I have a Java Hazelcast client connecting to Hazelcast normally, however, I am trying to figure out the way this Java client handle the failure on the clusters.
I found the setting of clientConfig.getConnectionStrategyConfig().getConnectionRetryConfig().setInitialBackoffMillis(10000).setMaxBackoffMillis(10000); to set the wait time between retries to 10 secs.
It seems working fine, however, I am receiving countless log of retrying and fail to connect to the cluster between retries.
I am wondering if the client is trying to connect these many times (which I want to avoid), or where are these log coming from (since it should only try to connect every 10 secs).
My Client Setup:
public MyHazelcastClient() {
// Create hazelcast client config
ClientConfig clientConfig = new ClientConfig();
clientConfig.getNetworkConfig().addAddress("127.0.0.1:5701");
clientConfig.setInstanceName("hz-client-local");
clientConfig.setClusterName("dev");
// Set connection retry strategy
clientConfig.getConnectionStrategyConfig().getConnectionRetryConfig()
.setInitialBackoffMillis(10000)
.setMaxBackoffMillis(10000);
// Create hazelcast instance
HazelcastInstance hz = HazelcastClient.newHazelcastClient(clientConfig);
Properties properties = HazelcastCachingProvider.propertiesByInstanceName(hzInstanceName);
hz.getLifecycleService().addLifecycleListener(event -> {
if (event.getState() == LifecycleState.CLIENT_DISCONNECTED) {
isAlive = false;
logger.info("Hazelcast clusters disconnected.");
}
else {
isAlive = true;
logger.info("Hazelcast clusters reconnected");
}
});
}
Test log (shutdown hazelcast cluster in the middle):
Jun 07, 2022 4:32:57 PM com.hazelcast.client.impl.connection.tcp.TcpClientConnection
INFO: hz-client-local [dev] [5.0.2] ClientConnection{alive=false, connectionId=1, channel=NioChannel{/127.0.0.1:56789->/127.0.0.1:5701}, remoteAddress=[127.0.0.1]:5701, lastReadTime=2022-06-07 16:32:57.491, lastWriteTime=2022-06-07 16:32:57.491, closedTime=2022-06-07 16:32:57.947, connected server version=5.0.2} closed. Reason: Connection closed by the other side
Jun 07, 2022 4:32:57 PM com.hazelcast.client.impl.connection.ClientConnectionManager
INFO: hz-client-local [dev] [5.0.2] Removed connection to endpoint: [127.0.0.1]:5701:bab6c664-a458-4671-9d22-388bbf840dcf, connection: ClientConnection{alive=false, connectionId=1, channel=NioChannel{/127.0.0.1:56789->/127.0.0.1:5701}, remoteAddress=[127.0.0.1]:5701, lastReadTime=2022-06-07 16:32:57.491, lastWriteTime=2022-06-07 16:32:57.491, closedTime=2022-06-07 16:32:57.947, connected server version=5.0.2}
Jun 07, 2022 4:32:57 PM com.hazelcast.core.LifecycleService
INFO: hz-client-local [dev] [5.0.2] HazelcastClient 5.0.2 (20211221 - 18eec9f) is CLIENT_DISCONNECTED
Jun 07, 2022 4:32:57 PM com.xxx.xxx.xxx.client.MyHazelcastClient lambda$new$0
INFO: Hazelcast clusters disconnected.
Jun 07, 2022 4:32:57 PM com.hazelcast.client.impl.connection.ClientConnectionManager
INFO: hz-client-local [dev] [5.0.2] Trying to connect to cluster: dev
Jun 07, 2022 4:32:57 PM com.hazelcast.client.impl.connection.ClientConnectionManager
INFO: hz-client-local [dev] [5.0.2] Trying to connect to Member [127.0.0.1]:5701 - bab6c664-a458-4671-9d22-388bbf840dcf
Jun 07, 2022 4:32:57 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Exception during initial connection to Member [127.0.0.1]:5701 - bab6c664-a458-4671-9d22-388bbf840dcf: com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:32:57 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Unable to get live cluster connection, retry in 10000 ms, attempt: 1, cluster connect timeout: INFINITE, max backoff: 10000 ms
Jun 07, 2022 4:32:58 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:32:59 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:00 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:01 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:02 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:03 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:04 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:05 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:06 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:07 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:07 PM com.hazelcast.client.impl.connection.ClientConnectionManager
INFO: hz-client-local [dev] [5.0.2] Trying to connect to Member [127.0.0.1]:5701 - bab6c664-a458-4671-9d22-388bbf840dcf
Jun 07, 2022 4:33:07 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Exception during initial connection to Member [127.0.0.1]:5701 - bab6c664-a458-4671-9d22-388bbf840dcf: com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:07 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Unable to get live cluster connection, retry in 10000 ms, attempt: 2, cluster connect timeout: INFINITE, max backoff: 10000 ms
Jun 07, 2022 4:33:08 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:09 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:10 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:11 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:12 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:13 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:14 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:15 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:16 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:17 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:17 PM com.hazelcast.client.impl.connection.ClientConnectionManager
INFO: hz-client-local [dev] [5.0.2] Trying to connect to Member [127.0.0.1]:5701 - bab6c664-a458-4671-9d22-388bbf840dcf
Jun 07, 2022 4:33:17 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Exception during initial connection to Member [127.0.0.1]:5701 - bab6c664-a458-4671-9d22-388bbf840dcf: com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
Jun 07, 2022 4:33:17 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Unable to get live cluster connection, retry in 10000 ms, attempt: 3, cluster connect timeout: INFINITE, max backoff: 10000 ms
Jun 07, 2022 4:33:18 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
You can see between Unable to get live cluster connection, retry in 10000 ms, attempt: 1, cluster connect timeout: INFINITE, max backoff: 10000 ms and the attempt 2, there are lots of log of trying to connect, which is confusing me are these attempt count correct?
Is there a way I can make it actually only tries to connect every 10 secs? Or way to quiet down these log if they are not relevant? Thanks
This seems a bug in the Java client implementation.
The re-connection logic works in every 10 seconds with the configuration you did, there is no problem there. You can see that by checking the logs starting with the following lines, which are 10 seconds apart.
Jun 07, 2022 4:32:57 PM com.hazelcast.client.impl.connection.ClientConnectionManager
INFO: hz-client-local [dev] [5.0.2] Trying to connect to Member [127.0.0.1]:5701 - bab6c664-a458-4671-9d22-388bbf840dcf
The other logs you see are coming from an internal periodic task that is executed every second which tries to establish a connection to all cluster members if the smart routing is enabled (which is enabled by default).
Jun 07, 2022 4:32:59 PM com.hazelcast.client.impl.connection.ClientConnectionManager
WARNING: hz-client-local [dev] [5.0.2] Could not connect to member bab6c664-a458-4671-9d22-388bbf840dcf, reason com.hazelcast.core.HazelcastException: java.io.IOException: Connection refused to address /127.0.0.1:5701
The problem is the client should be smarter in the periodic task and should not try to connect cluster members if there is no connection to the cluster yet and leave the re-connection logic to its correct place.
I have created a GitHub issue to track fixing this. Unfortunately, there is no way to work around the logs that are printed every second, and you would have to wait for it to get fixed.