Uploaded image for project: 'Infinispan'
  1. Infinispan
  2. ISPN-8721

Clustered 2nd level cache sometimes throws NullPointerException when new node starts up

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Major Major
    • 9.4.0.Final
    • 9.1.4.Final
    • Hibernate Cache
    • None

      There is a race condition in PutFromLoadValidator as it registers itself in the component registry before it is fully initialised. You can reproduce this by running the contained app against h2 server db. First start this app with default port. Then start the app on port '8080' and make a few requests to '/add' to create data. After that send continuous requests to '/update' in order change data and trigger the cache:
      for i in

      {1..1000}
      ; do sleep 0.01; curl http://localhost:8080/update -X POST; done
      

      Then start another instance of the app on port 8090:

      java -jar test-app-0.0.1-SNAPSHOT.jar --server.port=8090
      

      Most of the time one of the updates will fail and the logs will show the following:

      2018-01-23 15:36:46 [main] DEBUG o.h.c.i.access.PutFromLoadValidator - Interceptor chain was: [org.infinispan.interceptors.InvocationContextInterceptor@407a7f2a, org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor@4ea5b703, org.infinispan.interceptors.EntryWrappingInterceptor@2a7ed1f, org.infinispan.interceptors.InvalidationInterceptor@3fa247d1, org.infinispan.interceptors.CallInterceptor@2cb2fc20]
      2018-01-23 15:36:46 [main] DEBUG o.h.c.i.access.PutFromLoadValidator - New interceptor chain is: [org.infinispan.interceptors.InvocationContextInterceptor@407a7f2a, org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor@4ea5b703, org.hibernate.cache.infinispan.access.NonTxPutFromLoadInterceptor@495ee280, org.infinispan.interceptors.EntryWrappingInterceptor@2a7ed1f, org.hibernate.cache.infinispan.access.NonTxInvalidationInterceptor@4fa1c212, org.infinispan.interceptors.CallInterceptor@2cb2fc20]
      2018-01-23 15:36:46 [main] TRACE o.i.manager.DefaultCacheManager - About to wire and start cache test.app.data.User-pending-puts
      2018-01-23 15:36:46 [remote-thread--p2-t1] ERROR o.i.i.InvocationContextInterceptor - ISPN000136: Error executing command BeginInvalidationCommand, writing keys test.app.data.User#2
      java.lang.NullPointerException: null
      at org.hibernate.cache.infinispan.access.PutFromLoadValidator.beginInvalidatingWithPFER(PutFromLoadValidator.java:561)
      at org.hibernate.cache.infinispan.access.PutFromLoadValidator.beginInvalidatingKey(PutFromLoadValidator.java:555)
      at org.hibernate.cache.infinispan.access.NonTxPutFromLoadInterceptor.visitInvalidateCommand(NonTxPutFromLoadInterceptor.java:70)
      at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:114)
      at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
      at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitInvalidateCommand(AbstractLockingInterceptor.java:112)
      at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:114)
      at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
      at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:110)
      at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:79)
      at org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:127)
      at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:114)
      at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:335)
      at org.infinispan.commands.remote.BaseRpcInvokingCommand.processVisitableCommand(BaseRpcInvokingCommand.java:43)
      at org.infinispan.commands.remote.SingleRpcCommand.perform(SingleRpcCommand.java:51)
      at org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokePerform(BasePerCacheInboundInvocationHandler.java:92)
      at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.run(BaseBlockingRunnable.java:34)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      at java.lang.Thread.run(Thread.java:748)
      2018-01-23 15:36:47 [main] TRACE o.i.manager.DefaultCacheManager - Closing latch for cache test.app.data.User-pending-puts
      

            tom.dearman Tom Dearman (Inactive)
            tom.dearman Tom Dearman (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Created:
              Updated:
              Resolved: