Skip to content

It seems to be an issue with the connection pool #3244

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
yuantangtai opened this issue Apr 7, 2025 · 8 comments
Open

It seems to be an issue with the connection pool #3244

yuantangtai opened this issue Apr 7, 2025 · 8 comments
Labels
status: waiting-for-feedback We need additional information before we can continue

Comments

@yuantangtai
Copy link

yuantangtai commented Apr 7, 2025

Bug Report

Current Behavior

After running the microservice for a period of time, the value read by StringRestTemplate.opsForValue().get(key) becomes messy and not for this key.

By using the Redis command line to get the key, it was found that Redis is normal.

Restarting the microservice or Redis can restore normal operation.

It seems that there is a leak or contamination in the Redis connection pool of the letter client.

Stack trace

Input Code

Input Code
if (isSync) {
            for (int i = 1; i <= 200; i++) {
                String key = redis_KEY + i + ":";
                JSONObject productJson = new JSONObject();
                productJson.put("id", i);
                productJson.put("name", "product" + i);
                redisTemplate.opsForValue().set(key, productJson.toJSONString());
            }
        }

        for (int i = 1; i <= count; i++) {
            int finalI = i;
            commonServiceTestExecutor.execute(() -> {
                String key = redis_KEY + finalI + ":";
                String value = redisTemplate.opsForValue().get(key);
                log.info("线程 ===========" + Thread.currentThread().getName() + "key:" + key + " 获取到的值: " + value);
            });
        }

Expected behavior/code

Environment

spring-boot-starter-data-redis2.3.1.RELEASE,lettuce-core6.1.5.RELEASE

Possible Solution

Additional context

@yuantangtai
Copy link
Author

After upgrading lettuce-core to version 6.5.5, it has been a week and no abnormalities have been found. But we haven't figured out the exact cause of this accident, how should we investigate it

@yuantangtai
Copy link
Author

A Spring Cloud project running on the arrch64 architecture

@tishun
Copy link
Collaborator

tishun commented Apr 7, 2025

Hey @yuantangtai ,

could you provide a more complete example of your code?

The toJSONString() method is not part of the Lettuce code, so I assume you are using some other library?

Were there other exceptions thrown in the logs before the driver became out-of-sync (I assume this is the problem you are describing - the returned data was not matching the requested key)?

@tishun tishun added status: waiting-for-feedback We need additional information before we can continue and removed status: waiting-for-triage labels Apr 7, 2025
@yuantangtai
Copy link
Author

yuantangtai commented Apr 7, 2025

Hey @yuantangtai ,

could you provide a more complete example of your code?

The toJSONString() method is not part of the Lettuce code, so I assume you are using some other library?

Were there other exceptions thrown in the logs before the driver became out-of-sync (I assume this is the problem you are describing - the returned data was not matching the requested key)?

Hey @tishun
In order to verify whether it is a problem with dirty data set by other threads or the value obtained by the get method, a testing method (as shown above) was written. Manually set 200 keys to Redis, and when the problem occurred, get the values of these 200 keys. It was found that the value read was not the value of the previous set, but the value of other keys in Redis. At present, this issue has occurred on multiple arrch64 architecture projects. As the cause is unknown, it cannot be reproduced for further troubleshooting. The toJSONString method is only used in the demo to print values retrieved from Redis, so there should be no problem. What can be confirmed now is that after a problem occurs, the value extracted by a simple stringeditemplate. opsForValue(). get (key) does not belong to this key anymore,Or do you have any suggestions for further investigating the issue? I can try to see if it can be reproduced,Thanks!

@yuantangtai
Copy link
Author

yuantangtai commented Apr 8, 2025

@tishun
Abnormalities were discovered around 17:55:23 on March 31, 2025
Here are the error logs from around that time, I'm not sure if they're related

2025-03-31 17:56:22.727 [ERROR] [network-alarm-async-handler-3] [] [AsyncSendServiceImpl.java:57] - 
org.springframework.dao.QueryTimeoutException: Redis command timed out; nested exception is io.lettuce.core.RedisCommandTimeoutException: Command timed out after 1 minute(s)
	at org.springframework.data.redis.connection.lettuce.LettuceExceptionConverter.convert(LettuceExceptionConverter.java:70) ~[spring-data-redis-2.3.1.RELEASE.jar:2.3.1.RELEASE]
	at org.springframework.data.redis.connection.lettuce.LettuceExceptionConverter.convert(LettuceExceptionConverter.java:41) ~[spring-data-redis-2.3.1.RELEASE.jar:2.3.1.RELEASE]
	at org.springframework.data.redis.PassThroughExceptionTranslationStrategy.translate(PassThroughExceptionTranslationStrategy.java:44) ~[spring-data-redis-2.3.1.RELEASE.jar:2.3.1.RELEASE]
	at org.springframework.data.redis.FallbackExceptionTranslationStrategy.translate(FallbackExceptionTranslationStrategy.java:42) ~[spring-data-redis-2.3.1.RELEASE.jar:2.3.1.RELEASE]
	at org.springframework.data.redis.connection.lettuce.LettuceConnection.convertLettuceAccessException(LettuceConnection.java:273) ~[spring-data-redis-2.3.1.RELEASE.jar:2.3.1.RELEASE]
	at org.springframework.data.redis.connection.lettuce.LettuceHashCommands.convertLettuceAccessException(LettuceHashCommands.java:471) ~[spring-data-redis-2.3.1.RELEASE.jar:2.3.1.RELEASE]
	at org.springframework.data.redis.connection.lettuce.LettuceHashCommands.hGetAll(LettuceHashCommands.java:196) ~[spring-data-redis-2.3.1.RELEASE.jar:2.3.1.RELEASE]
	at org.springframework.data.redis.connection.DefaultedRedisConnection.hGetAll(DefaultedRedisConnection.java:1117) ~[spring-data-redis-2.3.1.RELEASE.jar:2.3.1.RELEASE]
	at org.springframework.data.redis.connection.DefaultStringRedisConnection.hGetAll(DefaultStringRedisConnection.java:512) ~[rule-common-1.3.0-STANDARD-ITERATION-SNAPSHOT.jar:2.3.1.RELEASE]
	at org.springframework.data.redis.core.DefaultHashOperations.lambda$entries$13(DefaultHashOperations.java:245) ~[spring-data-redis-2.3.1.RELEASE.jar:2.3.1.RELEASE]
	at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:228) ~[spring-data-redis-2.3.1.RELEASE.jar:2.3.1.RELEASE]
	at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:188) ~[spring-data-redis-2.3.1.RELEASE.jar:2.3.1.RELEASE]
	at org.springframework.data.redis.core.AbstractOperations.execute(AbstractOperations.java:96) ~[spring-data-redis-2.3.1.RELEASE.jar:2.3.1.RELEASE]
	at org.springframework.data.redis.core.DefaultHashOperations.entries(DefaultHashOperations.java:245) ~[spring-data-redis-2.3.1.RELEASE.jar:2.3.1.RELEASE]
	at cn.cuiot.dmp.common.utils.RedisUtils.hmget(RedisUtils.java:277) ~[rule-common-1.3.0-STANDARD-ITERATION-SNAPSHOT.jar:1.3.0-STANDARD-ITERATION-SNAPSHOT]
	at cn.cuiot.dmp.rawdataforward.service.impl.NetworkWarnServiceImpl.processNetworkWarn(NetworkWarnServiceImpl.java:129) ~[rule-engine-consumer-0.2-SNAPSHOT.jar:0.2-SNAPSHOT]
	at cn.cuiot.dmp.rawdataforward.async.impl.AsyncSendServiceImpl.processNetworkWarn(AsyncSendServiceImpl.java:55) ~[rule-engine-consumer-0.2-SNAPSHOT.jar:0.2-SNAPSHOT]
	at sun.reflect.GeneratedMethodAccessor204.invoke(Unknown Source) ~[?:?]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_202]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_202]
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) ~[spring-aop-5.2.7.RELEASE.jar:5.2.7.RELEASE]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) ~[spring-aop-5.2.7.RELEASE.jar:5.2.7.RELEASE]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.2.7.RELEASE.jar:5.2.7.RELEASE]
	at org.springframework.aop.interceptor.AsyncExecutionInterceptor.lambda$invoke$0(AsyncExecutionInterceptor.java:115) ~[spring-aop-5.2.7.RELEASE.jar:5.2.7.RELEASE]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_202]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_202]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_202]
	at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_202]
Caused by: io.lettuce.core.RedisCommandTimeoutException: Command timed out after 1 minute(s)
	at io.lettuce.core.internal.ExceptionFactory.createTimeoutException(ExceptionFactory.java:53) ~[lettuce-core-6.1.5.RELEASE.jar:6.1.5.RELEASE]
	at io.lettuce.core.internal.Futures.awaitOrCancel(Futures.java:246) ~[lettuce-core-6.1.5.RELEASE.jar:6.1.5.RELEASE]
	at io.lettuce.core.cluster.ClusterFutureSyncInvocationHandler.handleInvocation(ClusterFutureSyncInvocationHandler.java:130) ~[lettuce-core-6.1.5.RELEASE.jar:6.1.5.RELEASE]
	at io.lettuce.core.internal.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:80) ~[lettuce-core-6.1.5.RELEASE.jar:6.1.5.RELEASE]
	at com.sun.proxy.$Proxy168.hgetall(Unknown Source) ~[?:?]
	at org.springframework.data.redis.connection.lettuce.LettuceHashCommands.hGetAll(LettuceHashCommands.java:194) ~[spring-data-redis-2.3.1.RELEASE.jar:2.3.1.RELEASE]

@tishun
Copy link
Collaborator

tishun commented Apr 8, 2025

@tishun Abnormalities were discovered around 17:55:23 on March 31, 2025 Here are the error logs from around that time, I'm not sure if they're related

This shouldn't be an issue.

To make sure I understand the problem:

  1. you set 200 keys incrementally, with both the key and the value containing the index
  2. you get the same 200 keys and compare the index of the value with the index in the key

The result is:
The index of the key is different than the index of the value, but when read with some other client it is okay

Is that correct?

Or do you have any suggestions for further investigating the issue? I can try to see if it can be reproduced

You could open another connection with some other client, e.g. redis-cli, and issue the MONITOR command. It would help you see if the commands issues by the spring-data-redis are correct.

@yuantangtai
Copy link
Author

@tishun Abnormalities were discovered around 17:55:23 on March 31, 2025 Here are the error logs from around that time, I'm not sure if they're related

This shouldn't be an issue.

To make sure I understand the problem:

  1. you set 200 keys incrementally, with both the key and the value containing the index
  2. you get the same 200 keys and compare the index of the value with the index in the key

The result is: The index of the key is different than the index of the value, but when read with some other client it is okay

Is that correct?

Or do you have any suggestions for further investigating the issue? I can try to see if it can be reproduced

You could open another connection with some other client, e.g. redis-cli, and issue the MONITOR command. It would help you see if the commands issues by the spring-data-redis are correct.
@tishun Thanks again

Image

Based on your suggestion, the verification results are shown in the following figure. How should I further investigate the problem next

@tishun
Copy link
Collaborator

tishun commented Apr 15, 2025

I am not really sure how this happens.

Could you provide a minimum reproducible example that we can debug and see what is wrong?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
status: waiting-for-feedback We need additional information before we can continue
Projects
None yet
Development

No branches or pull requests

2 participants