Bug with Infinispan counter since 2.14

[ia3andy]

Describe the bug

When upgrading to 2.14.3.Final (from 2.13.2.Final), I've got this blocking exception:

2022-12-07 12:36:57,342 INFO  [org.inf.HOTROD] (main) ISPN004108: Native IOUring transport not available, using NIO instead: io.netty.incubator.channel.uring.IOUring
2022-12-07 12:36:57,555 INFO  [org.inf.HOTROD] (main) ISPN004021: Infinispan version: Infinispan 'Flying Saucer' 14.0.1.Final
2022-12-07 12:36:57,563 INFO  [org.inf.HOTROD] (HotRod-client-async-pool-1-1) ISPN004006: Server sent new topology view (id=1, age=0) containing 1 addresses: [10.128.4.239/<unresolved>:11222]
2022-12-07 12:36:57,566 INFO  [org.inf.HOTROD] (HotRod-client-async-pool-1-1) ISPN004014: New server added(10.128.4.239/<unresolved>:11222), adding to the pool.
2022-12-07 12:36:57,570 INFO  [org.inf.HOTROD] (HotRod-client-async-pool-1-1) ISPN004016: Server not in cluster anymore(infinispan/<unresolved>:11222), removing from the pool.
2022-12-07 12:36:57,790 WARN  [org.inf.HOTROD] (HotRod-client-async-pool-1-2) ISPN004098: Closing connection [id: 0x5664a123, L:/10.131.3.199:34488 - R:infinispan/172.30.239.172:11222] due to transport error: java.lang.NullPointerException: Cannot read field "opRespCode" because "params" is null
	at org.infinispan.client.hotrod.impl.protocol.Codec20.readHeader(Codec20.java:171)
	at org.infinispan.client.hotrod.impl.transport.netty.HeaderDecoder.decode(HeaderDecoder.java:122)
	at org.infinispan.client.hotrod.impl.transport.netty.HintedReplayingDecoder.callDecode(HintedReplayingDecoder.java:94)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:280)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
	at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:800)
	at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:499)
	at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:397)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:833)

2022-12-07 12:36:57,968 WARN  [org.inf.HOTROD] (HotRod-client-async-pool-1-1) ISPN004098: Closing connection [id: 0xa590e006, L:/10.131.3.199:34500 - R:infinispan/172.30.239.172:11222] due to transport error: java.lang.NullPointerException: Cannot read field "opRespCode" because "params" is null
	at org.infinispan.client.hotrod.impl.protocol.Codec20.readHeader(Codec20.java:171)
	at org.infinispan.client.hotrod.impl.transport.netty.HeaderDecoder.decode(HeaderDecoder.java:122)
	at org.infinispan.client.hotrod.impl.transport.netty.HintedReplayingDecoder.callDecode(HintedReplayingDecoder.java:94)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:280)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
	at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:800)
	at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:499)
	at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:397)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:833)

2022-12-07 12:36:58,016 ERROR [io.qua.run.Application] (main) Failed to start application (with profile openshift-cluster): org.infinispan.counter.exception.CounterException: ISPN029514: Invalid counter type. Expected=Strong but got Weak
	at org.infinispan.client.hotrod.counter.impl.RemoteCounterManager.assertStrongCounter(RemoteCounterManager.java:128)
	at org.infinispan.client.hotrod.counter.impl.RemoteCounterManager.createStrongCounter(RemoteCounterManager.java:122)
	at java.base/java.util.concurrent.ConcurrentHashMap.computeIfAbsent(ConcurrentHashMap.java:1708)
	at org.infinispan.client.hotrod.counter.impl.RemoteCounterManager.getOrCreateCounter(RemoteCounterManager.java:95)
	at org.infinispan.client.hotrod.counter.impl.RemoteCounterManager.getStrongCounter(RemoteCounterManager.java:48)
	at org.acme.GameResource.<init>(GameResource.java:59)
	at org.acme.GameResource_Subclass.<init>(Unknown Source)
	at org.acme.GameResource_Bean.create(Unknown Source)
	at org.acme.GameResource_Bean.create(Unknown Source)
	at io.quarkus.arc.impl.AbstractSharedContext.createInstanceHandle(AbstractSharedContext.java:113)
	at io.quarkus.arc.impl.AbstractSharedContext$1.get(AbstractSharedContext.java:37)
	at io.quarkus.arc.impl.AbstractSharedContext$1.get(AbstractSharedContext.java:34)
	at io.quarkus.arc.impl.LazyValue.get(LazyValue.java:26)
	at io.quarkus.arc.impl.ComputingCache.computeIfAbsent(ComputingCache.java:69)
	at io.quarkus.arc.impl.AbstractSharedContext.get(AbstractSharedContext.java:34)
	at io.quarkus.arc.impl.ClientProxies.getApplicationScopedDelegate(ClientProxies.java:21)
	at org.acme.GameResource_ClientProxy.arc$delegate(Unknown Source)
	at org.acme.GameResource_ClientProxy.arc_contextualInstance(Unknown Source)
	at org.acme.GameResource_Observer_Synthetic_7cf0717c670c27da30ed9286134533eadaf6a6a1.notify(Unknown Source)
	at io.quarkus.arc.impl.EventImpl$Notifier.notifyObservers(EventImpl.java:326)
	at io.quarkus.arc.impl.EventImpl$Notifier.notify(EventImpl.java:308)
	at io.quarkus.arc.impl.EventImpl.fire(EventImpl.java:76)
	at io.quarkus.arc.runtime.ArcRecorder.fireLifecycleEvent(ArcRecorder.java:131)
	at io.quarkus.arc.runtime.ArcRecorder.handleLifecycleEvents(ArcRecorder.java:100)
	at io.quarkus.deployment.steps.LifecycleEventsBuildStep$startupEvent1144526294.deploy_0(Unknown Source)
	at io.quarkus.deployment.steps.LifecycleEventsBuildStep$startupEvent1144526294.deploy(Unknown Source)
	at io.quarkus.runner.ApplicationImpl.doStart(Unknown Source)
	at io.quarkus.runtime.Application.start(Application.java:101)
	at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:110)
	at io.quarkus.runtime.Quarkus.run(Quarkus.java:70)
	at io.quarkus.runtime.Quarkus.run(Quarkus.java:43)
	at io.quarkus.runtime.Quarkus.run(Quarkus.java:123)
	at io.quarkus.runner.GeneratedMain.main(Unknown Source)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at io.quarkus.bootstrap.runner.QuarkusEntryPoint.doRun(QuarkusEntryPoint.java:61)
	at io.quarkus.bootstrap.runner.QuarkusEntryPoint.main(QuarkusEntryPoint.java:32)

Switching back to 2.13.2.Final fixed the problem.
This is on OpenShift and Infinispan deployed with the helm chart.

I can share the cluster credentials if needed.

[quarkus-bot]

/cc @geoand, @iocanel, @karesti, @wburns

[ia3andy]

and the code:

 counterManager.defineCounter("users",
            CounterConfiguration.builder(CounterType.UNBOUNDED_STRONG).storage(Storage.PERSISTENT).build());
       

[karesti]

@ia3andy checking on it

[karesti]

@ia3andy I have updated the IT tests to check counters type, and I can't reproduce. Could you be running the Infinispan 13 image (in the dev services or locally) instead of 14? I experienced this when I was upgrading to 14 a while ago

[ia3andy]

@karesti updating the Infinispan image to 14 is indeed fixing the problem.

Is there no way to detect this and add a log explaining the api is not compatible with the image?

[ia3andy]

FYI the default OpenShift Helm to install Infinispan uses the 13 image.

[wburns]

Clients if newer than the server, as of ISPN 10, should negotiate down to the older version. Are you explicitly setting the protocol version in your configuration?

[ia3andy]

@wburns no, it's default config (I am just setting the server and the credentials).

[wburns]

That is odd, for the time being you can override the protocol version in the configuration to workaround the issue
https://infinispan.org/docs/stable/titles/hotrod_java/hotrod_java.html#client-server-compatibility_hotrod-java-client
So in this case infinispan.client.hotrod.protocol_version=3.1

[wburns]

@karesti Can you make sure we get a bug logged against ISPN with the reproducer to fix this?

[karesti]

Yes, we will fix the compatibility issue in Infinispan @wburns @ia3andy https://issues.redhat.com/browse/ISPN-14090

[ia3andy]

@karesti should I re-open until this gets fixed?

[karesti]

@ia3andy no, since this is not a quarkus extension issue. the version here should be working with Infinispan 14. The bug that needs fixing is a compatibility issue of the server that we need to fix and needs to be backported to other versions too.