Skip to content
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

RedisCommandTimeoutException after two subsequent MULTI calls without executing the transaction #673

Closed
destitutus opened this issue Dec 25, 2017 · 7 comments
Labels
type: bug A general bug
Milestone

Comments

@destitutus
Copy link

jar: lettuce:4.4.2.Final

After ERR MULTI error all calls to redis are failed with RedisCommandTimeoutException. Is it known behaviour.
ERR MULTI probably from thread rice condition, but it is strange behaviour when after some error all other calls failed too

Caused by: com.lambdaworks.redis.RedisCommandExecutionException: ERR MULTI calls can not be nested
at com.lambdaworks.redis.protocol.AsyncCommand.completeResult(AsyncCommand.java:119)
at com.lambdaworks.redis.protocol.AsyncCommand.complete(AsyncCommand.java:110)
at com.lambdaworks.redis.protocol.CommandHandler.decode(CommandHandler.java:287)
at com.lambdaworks.redis.protocol.CommandHandler.channelRead(CommandHandler.java:259)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1359)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:935)
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:134)
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:645)
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:580)
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:497)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:459)
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
... 1 common frames omitted
com.lambdaworks.redis.RedisCommandTimeoutException: Command timed out
at com.lambdaworks.redis.LettuceFutures.await(LettuceFutures.java:118)
at com.lambdaworks.redis.LettuceFutures.awaitOrCancel(LettuceFutures.java:96)
at com.lambdaworks.redis.FutureSyncInvocationHandler.handleInvocation(FutureSyncInvocationHandler.java:61)
at com.lambdaworks.redis.internal.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:80)
@destitutus
Copy link
Author

destitutus commented Jan 23, 2018

main thread:

redisClient = RedisClient.create(RedisURI.create("redis://databases.test?timeout=1s"));
pool = ConnectionPoolSupport.createGenericObjectPool(redisClient::connect, new GenericObjectPoolConfig());

service thread(s)

try (StatefulRedisConnection<String, String> connection = pool.borrowObject()) {
      final RedisCommands<String, String> commands = connection.sync();
      commands.multi();
      commands.hset(redisConfig.getCollection(), key(key), value);
      if (ThreadLocalRandom.current().nextInt(0, 2) == 0) {
        throw new RuntimeException();
      }
      commands.hset(redisConfig.getCollection() + "-fs", key(key), value);
      commands.exec();
    } catch (Exception ex) {
      logger.warn("Redis error", ex);
    }

after first exception in service thread all commands are failed

[channel=0xc143f3b1, /10.11.12.14:36262 -> databases.test/10.11.12.13:6379, chid=0x2] write(ctx, TransactionalCommand [type=MULTI, output=StatusOutput [output=null, error='null'], commandType=com.lambdaworks.redis.protocol.AsyncCommand], promise)
[channel=0xc143f3b1, /10.11.12.14:36262 -> databases.test/10.11.12.13:6379] writing command TransactionalCommand [type=MULTI, output=StatusOutput [output=null, error='null'], commandType=com.lambdaworks.redis.protocol.AsyncCommand]
[channel=0xc143f3b1, /10.11.12.14:36262 -> databases.test/10.11.12.13:6379] Sent: *1
[channel=0xc143f3b1, /10.11.12.14:36262 -> databases.test/10.11.12.13:6379, chid=0x2] Received: 36 bytes, 1 commands in the stack
[channel=0xc143f3b1, /10.11.12.14:36262 -> databases.test/10.11.12.13:6379, chid=0x2] Buffer: -ERR MULTI calls can not be nested
[channel=0xc143f3b1, /10.11.12.14:36262 -> databases.test/10.11.12.13:6379, chid=0x2] Stack contains: 1 commands

@mp911de mp911de added the for: stackoverflow A question that is better suited to stackoverflow.com label Jan 23, 2018
@mp911de
Copy link
Collaborator

mp911de commented Jan 23, 2018

Lettuce connections require single-threaded/synchronized access when using transactions. If two or more threads call concurrently MULTI/EXEC methods this will destroy the connection state. I don't think there is anything we could do here.

In your code above, you're leaving the connection in MULTI state, the RuntimeException causes the code block to leave without resetting the transaction state (DISCARD/EXEC).

@destitutus
Copy link
Author

In your code above, you're leaving the connection in MULTI state, the RuntimeException causes the code block to leave without resetting the transaction state (DISCARD/EXEC).

But why it cause RedisCommandTimeoutException? It is really confusing.

@mp911de
Copy link
Collaborator

mp911de commented Jan 23, 2018

Thanks for pointing this detail out. The second MULTI is wrapped into another transactional command that completes upon EXEC. Because there is no EXEC, the command never completes.

We should be able to fix this so the error gets propagated without causing a timeout. Let me adjust the ticket description.

@mp911de mp911de added type: bug A general bug and removed for: stackoverflow A question that is better suited to stackoverflow.com labels Jan 23, 2018
@mp911de mp911de changed the title RedisCommandTimeoutException after ERR MULTI calls can not be nested RedisCommandTimeoutException after two subsequent MULTI calls without executing the transaction Jan 23, 2018
@destitutus
Copy link
Author

It would be great! Thanks!

@mp911de
Copy link
Collaborator

mp911de commented Jan 23, 2018

That's fixed now.

@mp911de mp911de closed this as completed Jan 23, 2018
@destitutus
Copy link
Author

Thank you! Also wold be great to add note about DISCARD to documentation about MULTI/EXEC probably, because it other case connection is not usable at all

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type: bug A general bug
Projects
None yet
Development

No branches or pull requests

2 participants