replicated cache with enabled statistics leads to NullPointer

[joachim.glink]

Hello.

We are using Infinispan inside Wildfly 15 (as module) for Hibernate 2nd LC.

The Infinispan configuration is done via the Wildfly configuration file (in our case the domain.xml).

If we run our application in Wildfly domain mode with multiple instances and configure Infinispan/Hibernate 2nd LC with a JGroups transport and enabled statistics, we get NullPointerExceptions in our log files (see below) if we call for example entityManager.find(..) for an entity class which is annotated with @Cache.

The caches are defined as replicated-cache with object memory store and expiration.

Oddly enough, the cache statistics seem to be updated nevertheless...

Of course, if we switch of the statistics for the caches the error doesn´t occur

The used versions:

Infinispan: 9.4.12.Final

Hibernate: Hibernate-5.4.1.Final

Wildfly: 15.0.1.Final

Java: OpenJDK 11

Infinispan configuration in Wildfly domain.xml:

<subsystem xmlns="urn:jboss:domain:infinispan:7.0">
  <cache-container name="hibernate" default-cache="local-query" module="org.infinispan.hibernate-cache">
    <transport channel="infinispan-jgroups" lock-timeout="60000"/>
    ...
      <replicated-cache name="user-cache" statistics-enabled="false">
        <object-memory size="10000"/>
        <expiration interval="10000" lifespan="2400000" max-idle="1200000"/>
      </replicated-cache>
    ...

The NullPointer in our server log file:

ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (httpWorkerThreads task-1) ISPN000136: Error executing command ReadWriteKeyCommand, writing keys [com.dematic.wms.appdemo.caching.entity.CachedEntity#5]: java.lang.NullPointerException
at [e-mail]//org.infinispan.interceptors.impl.CacheMgmtInterceptor.lambda$updateStatisticsReadWrite$11(CacheMgmtInterceptor.java:331)
at [e-mail]//org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(BaseAsyncInterceptor.java:81)
at [e-mail]//org.infinispan.interceptors.impl.CacheMgmtInterceptor.updateStatisticsReadWrite(CacheMgmtInterceptor.java:327)
at [e-mail]//org.infinispan.interceptors.impl.CacheMgmtInterceptor.visitReadWriteKeyCommand(CacheMgmtInterceptor.java:351)
at [e-mail]//org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(ReadWriteKeyCommand.java:113)
at [e-mail]//org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
at [e-mail]//org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
at [e-mail]//org.infinispan.interceptors.DDAsyncInterceptor.visitReadWriteKeyCommand(DDAsyncInterceptor.java:207)
at [e-mail]//org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(ReadWriteKeyCommand.java:113)
at [e-mail]//org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(BaseAsyncInterceptor.java:123)
at [e-mail]//org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContextInterceptor.java:90)
at [e-mail]//org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:56)
at [e-mail]//org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
at [e-mail]//org.infinispan.interceptors.DDAsyncInterceptor.visitReadWriteKeyCommand(DDAsyncInterceptor.java:207)
at [e-mail]//org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(ReadWriteKeyCommand.java:113)
at [e-mail]//org.infinispan.interceptors.DDAsyncInterceptor.visitCommand(DDAsyncInterceptor.java:50)
at [e-mail]//org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invokeAsync(AsyncInterceptorChainImpl.java:234)
at [e-mail]//org.infinispan.functional.impl.AbstractFunctionalMap.invokeAsync(AbstractFunctionalMap.java:127)
at [e-mail]//org.infinispan.functional.impl.ReadWriteMapImpl.eval(ReadWriteMapImpl.java:56)
at [e-mail]//org.infinispan.hibernate.cache.commons.access.TombstoneAccessDelegate.putFromLoad(TombstoneAccessDelegate.java:102)
at [e-mail]//org.infinispan.hibernate.cache.v53.impl.ReadOnlyEntityDataAccess.putFromLoad(ReadOnlyEntityDataAccess.java:30)
at org.hibernate//org.hibernate.engine.internal.TwoPhaseLoad.doInitializeEntity(TwoPhaseLoad.java:226)
at org.hibernate//org.hibernate.engine.internal.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:129)
at org.hibernate//org.hibernate.loader.plan.exec.process.internal.AbstractRowReader.performTwoPhaseLoad(AbstractRowReader.java:241)
at org.hibernate//org.hibernate.loader.plan.exec.process.internal.AbstractRowReader.finishUp(AbstractRowReader.java:209)
at org.hibernate//org.hibernate.loader.plan.exec.process.internal.ResultSetProcessorImpl.extractResults(ResultSetProcessorImpl.java:133)
at org.hibernate//org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:122)
at org.hibernate//org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:86)
at org.hibernate//org.hibernate.loader.entity.plan.AbstractLoadPlanBasedEntityLoader.load(AbstractLoadPlanBasedEntityLoader.java:197)
at org.hibernate//org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:4272)
at org.hibernate//org.hibernate.event.internal.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:482)
at org.hibernate//org.hibernate.event.internal.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:452)
at org.hibernate//org.hibernate.event.internal.DefaultLoadEventListener.load(DefaultLoadEventListener.java:203)
at org.hibernate//org.hibernate.event.internal.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:262)
at org.hibernate//org.hibernate.event.internal.DefaultLoadEventListener.doOnLoad(DefaultLoadEventListener.java:105)
at org.hibernate//org.hibernate.event.internal.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:73)
at org.hibernate//org.hibernate.internal.SessionImpl.fireLoad(SessionImpl.java:1287)
at org.hibernate//org.hibernate.internal.SessionImpl.access$2000(SessionImpl.java:211)
at org.hibernate//org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.doLoad(SessionImpl.java:2923)
at org.hibernate//org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.lambda$load$1(SessionImpl.java:2904)
at org.hibernate//org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.perform(SessionImpl.java:2860)
at org.hibernate//org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.load(SessionImpl.java:2904)
at org.hibernate//org.hibernate.internal.SessionImpl.find(SessionImpl.java:3545)
at org.hibernate//org.hibernate.internal.SessionImpl.find(SessionImpl.java:3512)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        ...

Is this a known issue or has someone a hint what could be causing the NullPointer?

Thanks

Joachim

[galder.zamarreno]

That looks indeed like a bug of some sort.

More than individual Infinispan statistics, for Hibernate 2LC, you're interested in Hibernate Cache statistics. These can be enabled like this. The code here shows how to query them.

[joachim.glink]

Thanks for your response.

I know that I can see also Hibernate 2LC statistics. But we want to have the Infinispan statistics also available to see the cache distribution across different nodes of a clustered cache.

[galder.zamarreno]

Fair enough. I've sent a couple of PRs to fix it in 9.4.x and 10.x

[joachim.glink]

Thanks.

Are there any (JIRA) tasks created for this issue? If yes, could you please link them.

[galder.zamarreno]

They're already linked, see right hand side of this forum post