{"action":"created","issue":{"url":"https://api.github.com/repos/mp911de/lettuce/issues/42","labels_url":"https://api.github.com/repos/mp911de/lettuce/issues/42/labels{/name}","comments_url":"https://api.github.com/repos/mp911de/lettuce/issues/42/comments","events_url":"https://api.github.com/repos/mp911de/lettuce/issues/42/events","html_url":"https://github.com/mp911de/lettuce/issues/42","id":59153818,"number":42,"title":"RedisClusterConnection stops operation after .RedisCommandTimeoutException","user":{"login":"taer","id":458866,"avatar_url":"https://avatars.githubusercontent.com/u/458866?v=3","gravatar_id":"","url":"https://api.github.com/users/taer","html_url":"https://github.com/taer","followers_url":"https://api.github.com/users/taer/followers","following_url":"https://api.github.com/users/taer/following{/other_user}","gists_url":"https://api.github.com/users/taer/gists{/gist_id}","starred_url":"https://api.github.com/users/taer/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/taer/subscriptions","organizations_url":"https://api.github.com/users/taer/orgs","repos_url":"https://api.github.com/users/taer/repos","events_url":"https://api.github.com/users/taer/events{/privacy}","received_events_url":"https://api.github.com/users/taer/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"milestone":null,"comments":2,"created_at":"2015-02-26T22:20:07Z","updated_at":"2015-02-26T23:33:31Z","closed_at":null,"body":"Setup: current master checkout of 3.1-SNAPSHOT: One thread, which has a single RedisClusterConnection<String,String>\r\n\r\nThe thread does a hgetall in a loop. You want to force a timeout on this thread. Do so by placing a VM breakpoint(pause all threads) in Utf8StringCodec.decode(). Let this hang for a bit(60 seconds I believe is the default timeout)\r\n\r\nNow, once you're sure you've expired the timeout, remove the breakpoint and resume the JVM. The command you paused will throw from \r\n**FutureSyncInvocationHandler:59                return LettuceFutures.await(command, timeout, unit);**\r\n\r\nIt doesn't seem to occur on a normal RedisConnection.\r\n\r\nThis is as far as I have made it. What happens next is the original caller gets an exception, which is perfectly fine. However, future calls to hgetall on the same connection will now simply timeout. \r\n\r\n```\r\n! com.lambdaworks.redis.RedisCommandTimeoutException: Command timed out\r\n! at com.lambdaworks.redis.LettuceFutures.await(LettuceFutures.java:68) ~[tanknew1.jar:na]\r\n! at com.lambdaworks.redis.FutureSyncInvocationHandler.handleInvocation(FutureSyncInvocationHandler.java:59) ~[tanknew1.jar:na]\r\n! at com.lambdaworks.com.google.common.reflect.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:87) ~[tanknew1.jar:na]\r\n! at com.sun.proxy.$Proxy95.hgetall(Unknown Source) ~[na:na]\r\n```\r\n\r\n\r\nAdditional info: The pause all threads didn't seem to matter. I updated to just pause the single thread in the decode, and it broke the same way.\r\n\r\n\r\nThat was how to reproduce the error. Here is all I've managed to dig up so far.\r\n\r\nDid a Thread dump. I have numerous requests blocked waiting for  lock on \r\ncom.lambdaworks.redis.RedisAsyncConnectionImpl.dispatch()\r\n\r\nThe guy who has that monitor is blocked on \r\n        at com.lambdaworks.redis.protocol.Command.get(Command.java:109)\r\nwhich is a CountDownLatch.await()\r\n\r\n"},"comment":{"url":"https://api.github.com/repos/mp911de/lettuce/issues/comments/76299011","html_url":"https://github.com/mp911de/lettuce/issues/42#issuecomment-76299011","issue_url":"https://api.github.com/repos/mp911de/lettuce/issues/42","id":76299011,"user":{"login":"taer","id":458866,"avatar_url":"https://avatars.githubusercontent.com/u/458866?v=3","gravatar_id":"","url":"https://api.github.com/users/taer","html_url":"https://github.com/taer","followers_url":"https://api.github.com/users/taer/followers","following_url":"https://api.github.com/users/taer/following{/other_user}","gists_url":"https://api.github.com/users/taer/gists{/gist_id}","starred_url":"https://api.github.com/users/taer/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/taer/subscriptions","organizations_url":"https://api.github.com/users/taer/orgs","repos_url":"https://api.github.com/users/taer/repos","events_url":"https://api.github.com/users/taer/events{/privacy}","received_events_url":"https://api.github.com/users/taer/received_events","type":"User","site_admin":false},"created_at":"2015-02-26T23:33:31Z","updated_at":"2015-02-26T23:33:31Z","body":"Ok, I see the problem now, but not sure how this happens. In CommandHandler:118\r\n\r\n```\r\n        while (!queue.isEmpty() && rsm.decode(buffer, queue.peek(), queue.peek().getOutput())) {\r\n```\r\nThe queue is NOT empty. On the next time through after I break the connection via the UTF8Decoder pause, it has 2 things in it.\r\nHead of the queue is my original clustercommand\r\n   Command [type=HGETALL, output=null]\r\nNext in queue is the one I just retried\r\n   Command [type=HGETALL, output=MapOutput [output={}, error='null']]\r\n\r\nrsm.decode is getting a null output, but returning false, which is exiting the while loop, abandoning my command that I just sent in.\r\n\r\nInverting the return at RedisStateMachine:81 to\r\n```\r\n        if (output == null) {\r\n            return !stack.isEmpty();\r\n        }\r\n```\r\nSort of solves this problem(future commands work to that key). The old command is taken from the queue, completed, and loops over again, sending the result to my real command. But I haven't dug through RSM too much. I think the queue in CommandHandler should be removing the timed out Commands when they time out. Is that the intention of the above stack.isEmpty?\r\n\r\nAlso, with that small hack above, isMoved() in ClusterCommand NPEs due to otput being null. That could probably be checked for."}}