Strange messages after reloading hazelcat instance

[Joan Balagueró]

Hello,

Hazelcast 4.2.6, 2-node cluster.

Occasionally after reloading a hazelcast instance (shutdown and start) we see this message on our log:

2023-06-05 21:07:56     [10.1.0.5]:9975 [ventusproxyCluster] [4.2.6] Cannot send response: null to [10.1.0.4]:9975. com.hazelcast.executor.impl.operations.MemberCallableTaskOperation{serviceName='hz:impl:executorService', identityHash=849212571, partitionId=-1, replicaIndex=0, callId=1997, invocationTime=1685999264018 (2023-06-05 21:07:44.018), waitTimeout=-1, callTimeout=60000, tenantControl=com.hazelcast.spi.impl.tenantcontrol.NoopTenantControl@0, name=ventusproxyExecutorService}

And sometimes the message is this:

2023-06-05 20:07:46     [10.1.0.4]:9975 [ventusproxyCluster] [4.2.6] Future.complete(Object) on completed future. Request: Invocation{op=com.hazelcast.executor.impl.operations.MemberCallableTaskOperation{serviceName='hz:impl:executorService', identityHash=487720155, partitionId=-1, replicaIndex=0, callId=-239, invocationTime=1685995654598 (2023-06-05 20:07:34.598), waitTimeout=-1, callTimeout=60000, tenantControl=com.hazelcast.spi.impl.tenantcontrol.NoopTenantControl@0, name=ventusproxyExecutorService}, tryCount=250, tryPauseMillis=500, invokeCount=1, callTimeoutMillis=60000, firstInvocationTimeMs=1685995654598, firstInvocationTime='2023-06-05 20:07:34.598', lastHeartbeatMillis=0, lastHeartbeatTime='1970-01-01 00:00:00.000', target=[10.1.0.4]:9975, pendingResponse={VOID}, backupsAcksExpected=-1, backupsAcksReceived=0, connection=null}, current value: ExceptionalResult{cause=com.hazelcast.core.HazelcastInstanceNotActiveException: Hazelcast instance is not active!}, offered value: null
java.lang.Exception: null
        at com.hazelcast.spi.impl.AbstractInvocationFuture.warnIfSuspiciousDoubleCompletion(AbstractInvocationFuture.java:1253) ~[hazelcast-4.2.6.jar:4.2.6]
        at com.hazelcast.spi.impl.AbstractInvocationFuture.complete0(AbstractInvocationFuture.java:1230) ~[hazelcast-4.2.6.jar:4.2.6]
        at com.hazelcast.spi.impl.AbstractInvocationFuture.complete(AbstractInvocationFuture.java:1219) ~[hazelcast-4.2.6.jar:4.2.6]
        at com.hazelcast.spi.impl.operationservice.impl.Invocation.complete(Invocation.java:672) ~[hazelcast-4.2.6.jar:4.2.6]
        at com.hazelcast.spi.impl.operationservice.impl.Invocation.sendResponse(Invocation.java:235) ~[hazelcast-4.2.6.jar:4.2.6]
        at com.hazelcast.spi.impl.operationservice.Offload$OffloadedOperationResponseHandler.sendResponse(Offload.java:169) ~[hazelcast-4.2.6.jar:4.2.6]
        at com.hazelcast.spi.impl.operationservice.Operation.sendResponse(Operation.java:475) ~[hazelcast-4.2.6.jar:4.2.6]
        at com.hazelcast.executor.impl.DistributedExecutorService$Processor.sendResponse(DistributedExecutorService.java:305) ~[hazelcast-4.2.6.jar:4.2.6]
        at com.hazelcast.executor.impl.DistributedExecutorService$Processor.run(DistributedExecutorService.java:288) ~[hazelcast-4.2.6.jar:4.2.6]
        at com.hazelcast.internal.util.executor.CachedExecutorServiceDelegate$Worker.run(CachedExecutorServiceDelegate.java:217) ~[hazelcast-4.2.6.jar:4.2.6]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[?:?]
        at java.lang.Thread.run(Thread.java:887) ~[?:?]
        at com.hazelcast.internal.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:76) ~[hazelcast-4.2.6.jar:4.2.6]
        at com.hazelcast.internal.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:102) ~[hazelcast-4.2.6.jar:4.2.6]

Which is scary, but it's not really true because the hz instance is alive and working fine.

What we are doing is just a shutdown of the instance and recreating it by calling Hazelcast.newHazelcastInstance(cfg);  and performing a 'warmUp' after this (creating and IMap, asking for its size and asking what node is the owner of several keys). This warm-up was a recommendation of you to avoid having issues asking by the owner of a key immediately after creating the hz instance.

Even knowing that the hz instance is running well, could anybody please tell me what can be the reason for these messages?

Thanks,

Joan.

[ahmet mırçık]

Hello Joan,

This is an issue but seems not a critical one, since it doesn't break the expected functionality of the system as far as i see. Reason of exception is the reference to the future object, this future object is notified both on node shutdown and on completion of executor run hence we see the double completion exception.

Maybe you can create a github issue to handle the situation gracefully.

--
You received this message because you are subscribed to the Google Groups "Hazelcast" group.
To unsubscribe from this group and stop receiving emails from it, send an email to hazelcast+...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/hazelcast/07bc984a-875d-4a6c-8052-00b32368766an%40googlegroups.com.

--

Ahmet Mırçık