camellia: [Camellia-redis-proxy] Error Redis start fail/timeout occasionally

Module: [camellia-redis-proxy] Version: [v1.1.11] Content: [Error Redis start fail occasionally]

Issue

  • After upgrading the camellia version to v1.1.11, although fixed the ERR max number of clients + cluster connections reached sometimes, I still got the start fail/ping timeout
  • I checked the networking at that time still good
  • logs:

Time	message

Jan 12, 2023 @ 12:47:22.330	2023-01-12 12:47:22,330 INFO  camellia-redis-client-initialize-8-5  c.n.n.c.r.p.u.c.RedisClient:119 - RedisClient[@xxx.xx.xx.201:6379][id=779] try connect...

Jan 12, 2023 @ 12:47:22.330	2023-01-12 12:47:22,330 INFO  camellia-redis-client-initialize-8-5  c.n.n.c.r.p.u.c.RedisClient:124 - RedisClient[@xxx.xx.xx.201:6379][id=779] connect success

Jan 12, 2023 @ 12:47:22.329	2023-01-12 12:47:22,329 INFO  camellia-redis-client-initialize-8-4  c.n.n.c.r.p.u.c.RedisClient:124 - RedisClient[@xxx.xx.xx.245:6379][id=847] connect success

Jan 12, 2023 @ 12:47:22.328	2023-01-12 12:47:22,328 WARN  camellia-redis-client-9-4  c.n.n.c.r.p.u.c.RedisClient:150 - RedisClient[@xxx.xx.xxx.62:6379][id=688] connect close, will stop

Jan 12, 2023 @ 12:47:22.328	2023-01-12 12:47:22,328 INFO  camellia-redis-client-initialize-8-6  c.n.n.c.r.p.u.c.RedisClient:124 - RedisClient[@xxx.xx.xx.245:6379][id=778] connect success

Jan 12, 2023 @ 12:47:22.328	2023-01-12 12:47:22,328 INFO  camellia-redis-client-initialize-8-4  c.n.n.c.r.p.u.c.RedisClient:119 - RedisClient[@xxx.xx.xx.245:6379][id=847] try connect...

Jan 12, 2023 @ 12:47:22.328	2023-01-12 12:47:22,328 WARN  camellia-redis-client-9-2  c.n.n.c.r.p.u.c.RedisClient:150 - RedisClient[@xxx.xx.xx.25:6379][id=686] connect close, will stop

Jan 12, 2023 @ 12:47:22.328	2023-01-12 12:47:22,328 INFO  camellia-redis-client-initialize-8-5  c.n.n.c.r.p.u.c.RedisClient:119 - RedisClient[@xxx.xx.xx.245:6379][id=776] try connect...

Jan 12, 2023 @ 12:47:22.328	2023-01-12 12:47:22,328 INFO  camellia-redis-client-initialize-8-1  c.n.n.c.r.p.u.c.RedisClient:124 - RedisClient[@xxx.xx.xx.245:6379][id=779] connect success

Jan 12, 2023 @ 12:47:22.328	2023-01-12 12:47:22,328 INFO  camellia-redis-client-initialize-8-7  c.n.n.c.r.p.u.c.RedisClient:124 - RedisClient[@xxx.xx.xx.245:6379][id=777] connect success

Jan 12, 2023 @ 12:47:22.328	2023-01-12 12:47:22,328 INFO  camellia-redis-client-initialize-8-5  c.n.n.c.r.p.u.c.RedisClient:124 - RedisClient[@xxx.xx.xx.245:6379][id=785] connect success

Jan 12, 2023 @ 12:47:22.328	2023-01-12 12:47:22,328 INFO  camellia-redis-client-initialize-8-3  c.n.n.c.r.p.u.c.RedisClient:124 - RedisClient[@xxx.xx.xx.245:6379][id=784] connect success

Jan 12, 2023 @ 12:47:22.328	2023-01-12 12:47:22,328 WARN  camellia-redis-client-9-3  c.n.n.c.r.p.u.c.RedisClient:150 - RedisClient[@xxx.xx.xxx.186:6379][id=687] connect close, will stop

Jan 12, 2023 @ 12:47:22.328	2023-01-12 12:47:22,328 INFO  camellia-redis-client-initialize-8-5  c.n.n.c.r.p.u.c.RedisClient:124 - RedisClient[@xxx.xx.xx.245:6379][id=776] connect success

Jan 12, 2023 @ 12:47:22.328	2023-01-12 12:47:22,327 INFO  camellia-redis-client-initialize-8-3  c.n.n.c.r.p.u.c.RedisClient:119 - RedisClient[@xxx.xx.xx.245:6379][id=846] try connect...

Jan 12, 2023 @ 12:47:22.328	2023-01-12 12:47:22,328 INFO  camellia-redis-client-initialize-8-3  c.n.n.c.r.p.u.c.RedisClient:124 - RedisClient[@xxx.xx.xx.245:6379][id=846] connect success

Jan 12, 2023 @ 12:47:22.318	com.netease.nim.camellia.redis.exception.CamelliaRedisException: ping fail

Jan 12, 2023 @ 12:47:22.318		at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)

Jan 12, 2023 @ 12:47:22.318		at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)

Jan 12, 2023 @ 12:47:22.318		at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

Jan 12, 2023 @ 12:47:22.318		at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

Jan 12, 2023 @ 12:47:22.318		at java.util.concurrent.FutureTask.run(FutureTask.java:266)

Jan 12, 2023 @ 12:47:22.318		at com.netease.nim.camellia.redis.proxy.upstream.client.RedisClientHub.lambda$tryGetRedisClient$7(RedisClientHub.java:283)

Jan 12, 2023 @ 12:47:22.318		at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)

Jan 12, 2023 @ 12:47:22.318		at com.netease.nim.camellia.redis.proxy.upstream.client.RedisClient.ping(RedisClient.java:257)

Jan 12, 2023 @ 12:47:22.318		at java.lang.Thread.run(Thread.java:748)

Jan 12, 2023 @ 12:47:22.318	2023-01-12 12:47:22,318 WARN  camellia-work-group-3-3  c.n.n.c.r.p.u.c.RedisClient:150 - RedisClient[@xxx.xx.xx.245:6379][id=845] connect close, will stop

Jan 12, 2023 @ 12:47:22.318		at com.netease.nim.camellia.redis.proxy.upstream.client.RedisClient.start(RedisClient.java:154)

Jan 12, 2023 @ 12:47:22.318		at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

Jan 12, 2023 @ 12:47:22.318	2023-01-12 12:47:22,318 ERROR camellia-redis-client-initialize-8-8  c.n.n.c.r.p.u.c.RedisClient:174 - RedisClient[@xxx.xx.xx.245:6379][id=845] start fail

Jan 12, 2023 @ 12:47:22.318		at com.netease.nim.camellia.redis.proxy.upstream.client.RedisClientHub.lambda$tryGetRedisClient$7(RedisClientHub.java:283)

Jan 12, 2023 @ 12:47:22.318		at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

Jan 12, 2023 @ 12:47:22.318		at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)

Jan 12, 2023 @ 12:47:22.318		at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)

Jan 12, 2023 @ 12:47:22.318	java.util.concurrent.TimeoutException: null

Jan 12, 2023 @ 12:47:22.318	2023-01-12 12:47:22,317 ERROR camellia-redis-client-initialize-8-8  c.n.n.c.r.p.u.c.RedisClient:277 - RedisClient[@xxx.xx.xx.245:6379][id=845] ping timeout, timeoutMillis = 10000

Jan 12, 2023 @ 12:47:22.318		at com.netease.nim.camellia.redis.proxy.upstream.client.RedisClient.start(RedisClient.java:155)

Jan 12, 2023 @ 12:47:22.318		at com.netease.nim.camellia.redis.proxy.upstream.client.RedisClientHub.tryInitRedisClient(RedisClientHub.java:327)

Jan 12, 2023 @ 12:47:22.318		at com.netease.nim.camellia.redis.proxy.upstream.client.RedisClientHub.tryInitRedisClient(RedisClientHub.java:327)

Jan 12, 2023 @ 12:47:22.318		at java.lang.Thread.run(Thread.java:748)

Jan 12, 2023 @ 12:47:22.318		at java.util.concurrent.FutureTask.run(FutureTask.java:266)

Jan 12, 2023 @ 12:47:22.318		at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1771)

Jan 12, 2023 @ 12:47:22.217	2023-01-12 12:47:22,217 INFO  camellia-redis-client-initialize-8-7  c.n.n.c.r.p.u.c.RedisClient:119 - RedisClient[@xxx.xx.xx.245:6379][id=823] try connect...

Jan 12, 2023 @ 12:47:22.217	2023-01-12 12:47:22,217 INFO  camellia-redis-client-initialize-8-7  c.n.n.c.r.p.u.c.RedisClient:124 - RedisClient[@xxx.xx.xx.245:6379][id=823] connect success

Jan 12, 2023 @ 12:47:22.212	2023-01-12 12:47:22,212 INFO  camellia-redis-client-initialize-8-3  c.n.n.c.r.p.u.c.RedisClient:124 - RedisClient[@xxx.xx.xx.245:6379][id=778] connect success

Jan 12, 2023 @ 12:47:22.211	2023-01-12 12:47:22,211 INFO  camellia-redis-client-initialize-8-3  c.n.n.c.r.p.u.c.RedisClient:119 - RedisClient[@xxx.xx.xx.245:6379][id=778] try connect...

Jan 12, 2023 @ 12:47:22.162	2023-01-12 12:47:22,162 INFO  camellia-redis-client-initialize-8-4  c.n.n.c.r.p.u.c.RedisClient:119 - RedisClient[@xxx.xx.xx.201:6379][id=822] try connect...

Jan 12, 2023 @ 12:47:22.162	2023-01-12 12:47:22,162 INFO  camellia-redis-client-initialize-8-4  c.n.n.c.r.p.u.c.RedisClient:124 - RedisClient[@xxx.xx.xx.201:6379][id=822] connect success

Jan 12, 2023 @ 12:47:22.152		at java.util.concurrent.FutureTask.run(FutureTask.java:266)

Jan 12, 2023 @ 12:47:22.152		at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)

Jan 12, 2023 @ 12:47:22.152		at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

Jan 12, 2023 @ 12:47:22.152	com.netease.nim.camellia.redis.exception.CamelliaRedisException: ping fail

Jan 12, 2023 @ 12:47:22.152		at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

Jan 12, 2023 @ 12:47:22.152		at com.netease.nim.camellia.redis.proxy.upstream.client.RedisClientHub.lambda$tryGetRedisClient$7(RedisClientHub.java:283)

Jan 12, 2023 @ 12:47:22.152	2023-01-12 12:47:22,151 ERROR camellia-redis-client-initialize-8-1  c.n.n.c.r.p.u.c.RedisClient:174 - RedisClient[@xxx.xx.xx.245:6379][id=843] start fail

Jan 12, 2023 @ 12:47:22.152		at java.lang.Thread.run(Thread.java:748)

Jan 12, 2023 @ 12:47:22.152		at com.netease.nim.camellia.redis.proxy.upstream.client.RedisClientHub.tryInitRedisClient(RedisClientHub.java:327)

Jan 12, 2023 @ 12:47:22.152		at com.netease.nim.camellia.redis.proxy.upstream.client.RedisClient.start(RedisClient.java:155)

Jan 12, 2023 @ 12:47:22.152	2023-01-12 12:47:22,151 WARN  camellia-work-group-3-8  c.n.n.c.r.p.u.c.RedisClient:150 - RedisClient[@xxx.xx.xx.245:6379][id=843] connect close, will stop

Jan 12, 2023 @ 12:47:22.152		at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)

Jan 12, 2023 @ 12:47:22.149	2023-01-12 12:47:22,149 ERROR camellia-redis-client-initialize-8-1  c.n.n.c.r.p.u.c.RedisClient:277 - RedisClient[@xxx.xx.xx.245:6379][id=843] ping timeout, timeoutMillis = 10000

Jan 12, 2023 @ 12:47:22.149		at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

Jan 12, 2023 @ 12:47:22.149		at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)

Jan 12, 2023 @ 12:47:22.149		at java.util.concurrent.FutureTask.run(FutureTask.java:266)

Jan 12, 2023 @ 12:47:22.149	java.util.concurrent.TimeoutException: null

Jan 12, 2023 @ 12:47:22.149		at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1771)

Jan 12, 2023 @ 12:47:22.149		at java.lang.Thread.run(Thread.java:748)

Jan 12, 2023 @ 12:47:22.149		at com.netease.nim.camellia.redis.proxy.upstream.client.RedisClient.start(RedisClient.java:154)

Jan 12, 2023 @ 12:47:22.149		at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

Jan 12, 2023 @ 12:47:22.149		at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)

Jan 12, 2023 @ 12:47:22.149		at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)

Jan 12, 2023 @ 12:47:22.149		at com.netease.nim.camellia.redis.proxy.upstream.client.RedisClientHub.lambda$tryGetRedisClient$7(RedisClientHub.java:283)

Jan 12, 2023 @ 12:47:22.149		at com.netease.nim.camellia.redis.proxy.upstream.client.RedisClientHub.tryInitRedisClient(RedisClientHub.java:327)

Jan 12, 2023 @ 12:47:22.149		at com.netease.nim.camellia.redis.proxy.upstream.client.RedisClient.ping(RedisClient.java:257)

Jan 12, 2023 @ 12:47:22.134	com.netease.nim.camellia.redis.exception.CamelliaRedisException: ping fail

Jan 12, 2023 @ 12:47:22.134		at java.util.concurrent.CompletableFuture.uniAccept(CompletableFuture.java:656)

Jan 12, 2023 @ 12:47:22.134		at com.netease.nim.camellia.redis.proxy.command.AsyncCommandInvoker.invoke(AsyncCommandInvoker.java:69)

Jan 12, 2023 @ 12:47:22.134		at java.util.concurrent.CompletableFuture.thenAccept(CompletableFuture.java:1997)

Jan 12, 2023 @ 12:47:22.134		at com.netease.nim.camellia.redis.proxy.upstream.AsyncCamelliaRedisTemplate.sendCommand(AsyncCamelliaRedisTemplate.java:160)

Jan 12, 2023 @ 12:47:22.134		at com.netease.nim.camellia.redis.proxy.command.CommandsTransponder.flush(CommandsTransponder.java:335)

About this issue

  • Original URL
  • State: closed
  • Created a year ago
  • Comments: 82 (38 by maintainers)

Most upvoted comments

is start fail/timeout occasionally issue still exists? @tasszz2k

Yesterday, I upgraded the Camellia to version 1.1.12. However, despite the upgrade, the issue of start fail/timeout occasionally still persists. 😞

+2
tasszz2k on Feb 1, 2023

I have no idea for this start fail/timeout occasionally issue.

+2
caojiajun on Jan 16, 2023

1.2.0 will release soon, in this version, I refactor the upstream redis connection initialize logic, it will init in async mode, and update the default connectionTimeoutMillis to 1000ms(old version is 500ms), maybe it is useful for this issue. @tasszz2k

+1
caojiajun on Feb 8, 2023

maybe you can disable close-idle-connection to avoid this issue? @tasszz2k

+1
caojiajun on Feb 6, 2023

why haven’t I seen the camellia version 1.1.13 release yet? https://repo1.maven.org/maven2/com/netease/nim/camellia-redis-proxy-core/1.1.13/

the maven central repository is not very stable yestday, I will try to release today.

+1
caojiajun on Jan 31, 2023

today, I am going to do it

+1
tasszz2k on Jan 31, 2023

which one is real, could you pls use netstat -apn | grep 'xxx' to check it

+1
caojiajun on Jan 17, 2023

Which environment do you deploy your Redis proxy in Kubernetes, virtual machine, etc.?

k8s with docker, but upstream redis-cluster is run in physical server

+1
caojiajun on Jan 17, 2023

in multi telant cases, upstream redis connection maybe a lot, so idle-check-and-recycle is effective by default.

+1
caojiajun on Jan 16, 2023

1.8.0_202

I use this docker image: openjdk:8-jre-alpine

execute java -version in the pod

+1
caojiajun on Jan 16, 2023

so it works after move the redis server to a physical server?

yes, it is fixed by moving the redis server to a physical server

+1
tasszz2k on Jan 16, 2023

@tasszz2k any follow-up messages?

+1
caojiajun on Jan 16, 2023
Read more comments on GitHub
← amoro: [Bug]: Optimize status hangs in pending and minor
camellia: [Camellia-redis-proxy] memory leak →