11 Replies Latest reply on Apr 23, 2015 1:00 PM by draganb

    NPE on Hibernate second-level cache invalidation

    draganb

      Hello,

       

      We are experiencing a strange behavior that is preventing us from using Hibernate L2 cache with Infinispan - occasionally we start getting NPEs during invalidation of the second-level cache entries and we have to restart the cluster in order to bring things back to normal.

       

      We are running a cluster of two instances of JBOSS EAP 6.2.0.GA on two separate physical machines.

       

      We are using default configuration for Hibernate L2 cache defined in Infinispan subsystem in standalone-full-ha.xml (displayed in config.xml attachment).

       

      In attachments are also persistence.xml and stack trace of the exception that occured on the node that initiated transaction (the node that sent invalidation commands to other nodes).

       

      The problematic entity (CampaignConfig) has a composite primary key (SessionFactory name is explicitly set as can be seen in persistence.xml, and everything works fine most of the time).

       

       

      On the node that is invalidated, the following stack trace is printed (and causes the entire XA transaction to rollback):

       

      09:50:14,655 WARN  [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] (OOB-20,shared=udp) Problems invoking command SingleRpcCommand{cacheName='CampaignConfig', command=InvalidateCommand{keys=[CampaignConfig#CampaignConfigId@2e6c, CampaignConfig#CampaignConfigId@2e8b]}}: java.lang.NullPointerException

          at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:119)

          at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:86)

          at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommandFromLocalCluster(CommandAwareRpcDispatcher.java:247)

          at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:220)

          at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:484)

          at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:391)

          at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:249)

          at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:600)

          at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130)

          at org.jgroups.JChannel.up(JChannel.java:707)

          at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1025)

          at org.jgroups.protocols.RSVP.up(RSVP.java:188)

          at org.jgroups.protocols.FRAG2.up(FRAG2.java:181)

          at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)

          at org.jgroups.protocols.FlowControl.up(FlowControl.java:400)

          at org.jgroups.protocols.pbcast.GMS.up(GMS.java:896)

          at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:245)

          at org.jgroups.protocols.UNICAST2.handleDataReceived(UNICAST2.java:765)

          at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:420)

          at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:645)

          at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:147)

          at org.jgroups.protocols.FD.up(FD.java:253)

          at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288)

          at org.jgroups.protocols.MERGE3.up(MERGE3.java:290)

          at org.jgroups.protocols.Discovery.up(Discovery.java:359)

          at org.jgroups.protocols.TP$ProtocolAdapter.up(TP.java:2607)

          at org.jgroups.protocols.TP.passMessageUp(TP.java:1260)

          at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1822)

          at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1795)

          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) [rt.jar:1.7.0_09]

          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) [rt.jar:1.7.0_09]

          at java.lang.Thread.run(Thread.java:722) [rt.jar:1.7.0_09]

       

       

       

      I suspect we have misconfigured something and I appreciate any help around this.

       

      Thanks and regards,

      Dragan

        • 1. Re: NPE on Hibernate second-level cache invalidation
          dan.berindei

          Hi Dragan

           

          The only way I can imagine this happening is if the cache is in invalidation mode on one node (the one running the transaction) and in local mode on the other node (the one throwing the NPE). You can check the cache mode for the entity caches being created in the JMX, as the cache MBean's name includes the clustering mode.

           

          But that would mean the invalidation starts failing immediately after the second node starts, not just occasionally. I have no idea how the NPE could start appearing after they are both running and you get one successful invalidation.

          • 2. Re: NPE on Hibernate second-level cache invalidation
            draganb

            Hi Dan,

             

            Thank you for the answer, you seem to be pointing us to the right direction.

             

            Your assumptions are correct:

            1) After reproducing the issue and inspecting the JMX we observed that the node throwing the NPE switches sometimes automatically from invalidation to local mode after the app has been redeployed.

            2) We have automatic redeployment of the application at regular intervals on the environment where this occurs and at first we did not notice that this actually occurs after redeployment.

             

            Afterwards, the caches on the problematic node remain in local mode until the entire JBoss instance is restarted (redeployment doesn't help).

             

            We also observed that Cache Manager MBean contains both members in it's clusterMembers attribute value, but the entity caches are in local mode.

             

            Now the question is, why do entity caches switch to local mode in this case (or more correctly said, why do they not switch back to invalidation mode once the other member rejoins the cluster)?

             

            Many thanks,

            Best regards,

            Dragan

            • 3. Re: NPE on Hibernate second-level cache invalidation
              galder.zamarreno

              Hmmm, there's something odd going there. If the cache manager shows two members, the underlying applications should also find them.

               

              Can you reproduce the issue again? If so, can you enable TRACE logging on packages org.infinispan and org.hibernate on both nodes in the cluster and make them available to us?

               

              Cheers,

              Galder

              • 4. Re: NPE on Hibernate second-level cache invalidation
                galder.zamarreno

                We've looked at your config and I think the issues you're having are due to using standalone configuration when running inside EAP.

                 

                You should remove:

                 

                <property name="hibernate.transaction.manager_lookup_class" value="org.hibernate.transaction.JBossTransactionManagerLookup" />

                <property name="hibernate.cache.region.factory_class" value="org.jboss.as.jpa.hibernate4.infinispan.InfinispanRegionFactory"/>

                <property name="hibernate.cache.infinispan.cachemanager" value="java:jboss/infinispan/container/hibernate"/>

                 

                All you need to do is enable second level cache as shown here and EAP would take care of the rest.

                • 5. Re: NPE on Hibernate second-level cache invalidation
                  draganb

                  Hi Galder,

                   

                  Thanks for the help and sorry for not providing the logs yet, we will do it as soon as possible.

                   

                  We already tried your suggestion some time ago when we introduced L2 cache to our application, however we get (full stack trace in the attachment):

                   

                  Caused by: org.hibernate.cache.NoCacheRegionFactoryAvailableException: Second-level cache is used in the application, but property hibernate.cache.region.factory_class is not given, please either disable second level cache or set correct region factory class name to property hibernate.cache.region.factory_class (and make sure the second level cache provider, hibernate-infinispan, for example, is available in the classpath).

                      at org.hibernate.cache.internal.NoCachingRegionFactory.buildEntityRegion(NoCachingRegionFactory.java:69) [hibernate-core-4.2.7.SP1-redhat-3.jar:4.2.7.SP1-redhat-3]

                      at org.hibernate.internal.SessionFactoryImpl.<init>(SessionFactoryImpl.java:349) [hibernate-core-4.2.7.SP1-redhat-3.jar:4.2.7.SP1-redhat-3]

                      at org.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1794) [hibernate-core-4.2.7.SP1-redhat-3.jar:4.2.7.SP1-redhat-3]

                      at org.hibernate.ejb.EntityManagerFactoryImpl.<init>(EntityManagerFactoryImpl.java:96) [hibernate-entitymanager-4.2.7.SP1-redhat-3.jar:4.2.7.SP1-redhat-3]

                      at org.hibernate.ejb.Ejb3Configuration.buildEntityManagerFactory(Ejb3Configuration.java:914) [hibernate-entitymanager-4.2.7.SP1-redhat-3.jar:4.2.7.SP1-redhat-3]

                   

                  It seems that one has to explicitly provide region factory in non-managed jpa (we use Spring).

                   

                  Thanks and regards,

                  Dragan

                  • 6. Re: NPE on Hibernate second-level cache invalidation
                    galder.zamarreno

                    Well, if it's non-managed, you should not pass `hibernate.cache.infinispan.cachemanager` since that forces the cache manager to be managed. If you want non-managed, everything must be non-managed, from Hibernate/JPA to Infinispan Cache Manager.

                     

                    For a non-managed set up, you need:

                     

                    <property name="hibernate.cache.region.factory_class" value="org.hibernate.cache.infinispan.InfinispanRegionFactory"/>

                     

                    And for the transactions part (needed if you have any entities as transactional):

                     

                    <property name="hibernate.transaction.jta.platform" value="org.hibernate.service.jta.platform.internal.JBossStandAloneJtaPlatform"/>

                     

                    Optionally, you can add this with a link to the XML for the Infinispan configuration, but this is optional and even if you use your own config, you should base it in the default one:

                     

                    <property name="hibernate.cache.infinispan.cfg" value="..."/>

                    • 7. Re: NPE on Hibernate second-level cache invalidation
                      draganb

                      Hi Galder,

                       

                      Now we get this

                       

                      Caused by: org.hibernate.cache.CacheException: Unable to start region factory

                          at org.hibernate.cache.infinispan.InfinispanRegionFactory.start(InfinispanRegionFactory.java:323) [hibernate-infinispan-4.2.7.SP1-redhat-3.jar:4.2.7.SP1-redhat-3]

                          at org.hibernate.internal.CacheImpl.<init>(CacheImpl.java:70) [hibernate-core-4.2.7.SP1-redhat-3.jar:4.2.7.SP1-redhat-3]

                          at org.hibernate.engine.spi.CacheInitiator.initiateService(CacheInitiator.java:40) [hibernate-core-4.2.7.SP1-redhat-3.jar:4.2.7.SP1-redhat-3]

                          at org.hibernate.engine.spi.CacheInitiator.initiateService(CacheInitiator.java:35) [hibernate-core-4.2.7.SP1-redhat-3.jar:4.2.7.SP1-redhat-3]

                          at org.hibernate.service.internal.SessionFactoryServiceRegistryImpl.initiateService(SessionFactoryServiceRegistryImpl.java:91) [hibernate-core-4.2.7.SP1-redhat-3.jar:4.2.7.SP1-redhat-3]

                          at org.hibernate.service.internal.AbstractServiceRegistryImpl.createService(AbstractServiceRegistryImpl.java:177) [hibernate-core-4.2.7.SP1-redhat-3.jar:4.2.7.SP1-redhat-3]

                          ... 57 more

                      Caused by: org.infinispan.config.ConfigurationException: javax.xml.stream.XMLStreamException: ParseError at [row,col]:[2,1]

                      Message: Unexpected element '{urn:infinispan:config:5.1}infinispan'

                          at org.infinispan.configuration.parsing.ParserRegistry.parse(ParserRegistry.java:87)

                          at org.infinispan.manager.DefaultCacheManager.<init>(DefaultCacheManager.java:353)

                          at org.infinispan.manager.DefaultCacheManager.<init>(DefaultCacheManager.java:326)

                          at org.hibernate.cache.infinispan.InfinispanRegionFactory.createCacheManager(InfinispanRegionFactory.java:387) [hibernate-infinispan-4.2.7.SP1-redhat-3.jar:4.2.7.SP1-redhat-3]

                          at org.hibernate.cache.infinispan.InfinispanRegionFactory.start(InfinispanRegionFactory.java:308) [hibernate-infinispan-4.2.7.SP1-redhat-3.jar:4.2.7.SP1-redhat-3]

                          ... 62 more

                      Caused by: javax.xml.stream.XMLStreamException: ParseError at [row,col]:[2,1]

                      Message: Unexpected element '{urn:infinispan:config:5.1}infinispan'

                          at org.jboss.staxmapper.XMLMapperImpl.processNested(XMLMapperImpl.java:108)

                          at org.jboss.staxmapper.XMLMapperImpl.parseDocument(XMLMapperImpl.java:69)

                          at org.infinispan.configuration.parsing.ParserRegistry.parse(ParserRegistry.java:77)

                          ... 66 more

                       

                      Also, what is the purpose of

                      <property name="hibernate.transaction.jta.platform" value="org.hibernate.service.jta.platform.internal.JBossStandAloneJtaPlatform"/> ?

                       

                      Is it safe to combine it with

                      <property name="hibernate.transaction.manager_lookup_class" value="org.hibernate.transaction.JBossTransactionManagerLookup" />

                      or I should get rid of the latter?

                       

                      Many thanks and kind regards,

                      Dragan

                      • 8. Re: NPE on Hibernate second-level cache invalidation
                        galder.zamarreno

                        That error refers to a misconfiguration of some sort in the infinispan.xml that you have passed in, if any...

                         

                        It could be also that the version of the XML, 5.1, is newer than what's supported by the Infinispan library that is trying to read it, which likely is the one that's shipped by your base EAP installation.

                         

                        `hibernate.transaction.jta.platform` was an improvement on previous transaction management in Hibernate, making it easier to use a JTA transaction manager standalone. Before that was in place, it was quite complicated to get it right, and indeed, you should get rid of `hibernate.transaction.manager_lookup_class`

                        • 9. Re: NPE on Hibernate second-level cache invalidation
                          draganb

                          Hi Galder,

                           

                          1) Actually, the default configuration is older than the version of the Infinispan library shipped in EAP (Infinispan version used in JBOSS EAP 6.2.0.GA is 5.2.7, and config relates to 5.1 version). I resolved that issue by adding the following entry in jboss-deployment-structure.xml:

                           

                          <module name="org.infinispan" services="export" export="true"/>

                           

                          The service which parses xml is not started if services="export" is not specified in the infinispan module dependency, hence that parsing error.

                           

                          2) Then I had to add a file named org.infinispan.commands.module.ModuleCommandExtensions containing the line org.hibernate.cache.infinispan.util.CacheCommandExtensions to META-INF/services folder of my application (got some exceptions without it).

                           

                          3) As you suggested, I added the following property in persistence.xml:

                           

                          <property name="hibernate.cache.region.factory_class" value="org.hibernate.cache.infinispan.InfinispanRegionFactory"/>

                           

                          4) I also added the property in persistence.xml:

                           

                          <property name="hibernate.transaction.jta.platform" value="org.hibernate.service.jta.platform.internal.JBossAppServerJtaPlatform"/>

                           

                          You suggested JBossStandAloneJtaPlatform, however it did not work with our setup (JBoss complained about some missing classes), and I think that JBossAppServerJtaPlatform will work better for us because we use other transactional resources that participate in the same XA transaction (Spring's JtaTransactionManager which expects standard JNDI bindings such as java:comp/UserTransaction etc., and JMS with HornetQ as provider).

                           

                          5) I copied the example (default) configuration files infinispan-configs.xml and jgroups-udp.xml from corresponding EAP modules and added them to my application's resources (and adjusted hibernate.cache.infinispan.cfg appropriately).

                           

                          In infinispan-configs.xml I changed:

                          a) Global transport property for jgroups to use jgroups-udp.xml configuration.

                          b) Renamed stateRetrieval config occurences to stateTransfer (in version 5.2 this config seems to be renamed and I got some warnings about it).

                           

                          I assume, in jgroups-udp.xml I should just set mcast_addr/mcast_port to the desired values to isolate my cluster from other clusters/machines in the same network (as I would do by adjusting jgroups-mping and jgroups-udp socket bindings in EAP's standalone.xml).

                           

                          After this, clustered cache started to work and we were not able to reproduce the original issue again. We will observe it closely because it was pretty hard to reproduce anyway, and I'm back here if it happens again .

                           

                          I am new to JBoss clustering and I came to most of the above configs by trial and error (although by definition it seems to be "a fundamental method of solving problems" ). What do you think, do you see any issues in this config?

                          Also, provided that we set up addresses/ports correctly, will this jgroups config be in some kind of clash with jgroups that is used by HornetQ and configured by EAP (in standalone.xml)?

                           

                          Many thanks and regards,

                          Dragan

                          • 10. Re: NPE on Hibernate second-level cache invalidation
                            galder.zamarreno

                            In general, I'd try to upgrade to a more recent EAP version, e.g. 6.4.0, and where possible, I'd let the 2LC be managed by the application server. That can be done simply by enabling 2LC and doing nothing else by setting hibernate.cache.use_second_level_cache to true. Even if you use Spring, it should still work unless I'm missing something         

                            • 11. Re: NPE on Hibernate second-level cache invalidation
                              draganb

                              Hi Galder,

                               

                              I confirm that this is working now, the issue did not appear after we configured Hibernate to use InfinispanRegionFactory.

                               

                              Many thanks to you and Dan for the help around this.

                               

                              Regards,

                              Dragan