CompletableFutureWrapper change threadId when unlock by using redission

[SCHLLLLLL]

Describe the bug

CompletableFutureWrapper may cause to wrap CompletableFuture when unlocking by using redission, causing the callback thread to be different from the original thread holding the lock

Steps to reproduce

but it is occasionally
java.lang.IllegalMonitorStateException: attempt to unlock lock, not locked by current thread by node id: 6332b643-be65-4554-8aca-0fdb93f3b649 thread-id: 31042

there is my stack info

2025-05-09 10:54:47.618 at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) 2025-05-09 10:54:47.618 at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) 2025-05-09 10:54:47.618 at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) 2025-05-09 10:54:47.618 at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493) 2025-05-09 10:54:47.618 at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:581) 2025-05-09 10:54:47.618 at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:655) 2025-05-09 10:54:47.618 at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:719) 2025-05-09 10:54:47.618 at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166) 2025-05-09 10:54:47.618 at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) 2025-05-09 10:54:47.618 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) 2025-05-09 10:54:47.618 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) 2025-05-09 10:54:47.618 at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) 2025-05-09 10:54:47.618 at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) 2025-05-09 10:54:47.618 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) 2025-05-09 10:54:47.618 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) 2025-05-09 10:54:47.618 at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276) 2025-05-09 10:54:47.618 at io.netty.handler.codec.ReplayingDecoder.callDecode(ReplayingDecoder.java:366) 2025-05-09 10:54:47.618 at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:507) 2025-05-09 10:54:47.618 at org.redisson.client.handler.CommandDecoder.decode(CommandDecoder.java:113) 2025-05-09 10:54:47.618 at org.redisson.client.handler.CommandDecoder.decode(CommandDecoder.java:137) 2025-05-09 10:54:47.618 at org.redisson.client.handler.CommandDecoder.decodeCommand(CommandDecoder.java:210) 2025-05-09 10:54:47.618 at org.redisson.client.handler.CommandDecoder.decodeCommandBatch(CommandDecoder.java:318) 2025-05-09 10:54:47.618 at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1975) 2025-05-09 10:54:47.618 at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488) 2025-05-09 10:54:47.618 at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:750) 2025-05-09 10:54:47.618 at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:774) 2025-05-09 10:54:47.618 at io.opentelemetry.javaagent.instrumentation.redisson.CompletableFutureWrapper.lambda$new$0(CompletableFutureWrapper.java:28) 2025-05-09 10:54:47.618 at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1975) 2025-05-09 10:54:47.618 at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488) 2025-05-09 10:54:47.618 at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:750) 2025-05-09 10:54:47.618 at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:774) 2025-05-09 10:54:47.618 at org.redisson.command.RedisExecutor.lambda$execute$4(RedisExecutor.java:176) 2025-05-09 10:54:47.618 at org.redisson.command.RedisExecutor.checkAttemptPromise(RedisExecutor.java:524) 2025-05-09 10:54:47.618 at org.redisson.command.RedisCommonBatchExecutor.handleResult(RedisCommonBatchExecutor.java:163) 2025-05-09 10:54:47.618 at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1975) 2025-05-09 10:54:47.618 at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488) 2025-05-09 10:54:47.618 at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:750) 2025-05-09 10:54:47.618 at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:774) 2025-05-09 10:54:47.618 at org.redisson.command.CommandBatchService.lambda$executeAsync$7(CommandBatchService.java:322) 2025-05-09 10:54:47.618 at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1975) 2025-05-09 10:54:47.618 at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488) 2025-05-09 10:54:47.618 at java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:811) 2025-05-09 10:54:47.618 at java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:836) 2025-05-09 10:54:47.618 at org.redisson.RedissonBaseLock.lambda$unlockAsync$2(RedissonBaseLock.java:323) 2025-05-09 10:54:47.618 java.lang.IllegalMonitorStateException: attempt to unlock lock, not locked by current thread by node id: 6332b643-be65-4554-8aca-0fdb93f3b649 thread-id: 31042

there is the biz code
String lockKey = String.format(OrderPayKey.LOCK_BY_ORDER_ID, orderId); RLock lock = redisTools.getLock(lockKey); log.info("lock :{}", lockKey); if (lock.tryLock(1, 20, TimeUnit.SECONDS)) { try { // bizCode } catch (Exception e) { throw new CodeException(ResultCodeEnum.INTERNAL_SERVER.code(), e.getMessage(), e); } finally { // 释放锁 try { log.info("before unlock check: {}", lockKey); if (lock.isLocked() && lock.isHeldByCurrentThread()) { log.info("before unlock: {}", lockKey); lock.unlock(); log.info("after unlock: {}", lockKey); } } catch (Exception e) { log.error("unlock exception: {}", e.getMessage()); throw new CodeException(errorCodeProperties.getRetailErrorCode().getPAY_COMPLETE_ERROR(), "service busy"); } } }

I suspect it's due to CompletableFutureWrapper

Can someone help me figure out the problem?

Expected behavior

normal to unlock

Actual behavior

IllegalMonitorStateException occurs

io.opentelemetry.javaagent.instrumentation.redisson.CompletableFutureWrapper.lambda$new$0(CompletableFutureWrapper.java:28)

Javaagent or library instrumentation version

opentelemetry-javaagent-2.9.0.jar

Environment

JDK: 1.8
OS: linux
redission: 3.17.6

Additional context

No response

[laurit]

CompletableFutureWrapper may cause to wrap CompletableFuture when unlocking by using redission, causing the callback thread to be different from the original thread holding the lock

The way I see it the error has already happened by the time the callback is invoked.

Have a look at redisson/redisson#4871 seems to be the same issue as you are seeing.

[github-actions]

This has been automatically marked as stale because it has been marked as needing author feedback and has not had any activity for 7 days. It will be closed automatically if there is no response from the author within 7 additional days from this comment.