constant timeout exception

[aaskey]

Hi there,

I set the put timeout value to be 10 seconds, however, it always throws out an exception in 10 seconds no matter the write succeeded or not.

Below is the log, at 11.926 the write returns successfully, but still at 21.912 an exception happens. Can this exception be avoided? If it is a real exception, can it be thrown to application instead of printing trace underneath? Printing tracing can be very expensive.

Dec 31 2014 12:18:11.926 [main] [Etcd.java:272] DEBUG c.s.c.e.Etcd - Etcd putValue - key GroupId, value 123456, return 123456
Dec 31 2014 12:18:21.912 [nioEventLoopGroup-2-2] [Slf4JLogger.java:151] WARN i.n.c.DefaultChannelPipeline - An exception was thrown by a user handler's exceptionCaught() method:
java.lang.IllegalStateException: complete already: DefaultPromise@282e593e(incomplete)
at io.netty.util.concurrent.DefaultPromise.setFailure(DefaultPromise.java:418) ~[netty-common-4.1.0.Beta3.jar:4.1.0.Beta3]
at mousio.etcd4j.transport.EtcdNettyClient$5.exceptionCaught(EtcdNettyClient.java:233) ~[etcd4j-2.0.0.jar:na]
at io.netty.channel.ChannelHandlerInvokerUtil.invokeExceptionCaughtNow(ChannelHandlerInvokerUtil.java:64) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.DefaultChannelHandlerInvoker.invokeExceptionCaught(DefaultChannelHandlerInvoker.java:110) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.AbstractChannelHandlerContext.fireExceptionCaught(AbstractChannelHandlerContext.java:167) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.ChannelInboundHandlerAdapter.exceptionCaught(ChannelInboundHandlerAdapter.java:131) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.ChannelHandlerInvokerUtil.invokeExceptionCaughtNow(ChannelHandlerInvokerUtil.java:64) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.DefaultChannelHandlerInvoker.invokeExceptionCaught(DefaultChannelHandlerInvoker.java:110) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.AbstractChannelHandlerContext.fireExceptionCaught(AbstractChannelHandlerContext.java:167) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.ChannelInboundHandlerAdapter.exceptionCaught(ChannelInboundHandlerAdapter.java:131) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.ChannelHandlerInvokerUtil.invokeExceptionCaughtNow(ChannelHandlerInvokerUtil.java:64) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.DefaultChannelHandlerInvoker.invokeExceptionCaught(DefaultChannelHandlerInvoker.java:110) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.AbstractChannelHandlerContext.fireExceptionCaught(AbstractChannelHandlerContext.java:167) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.ChannelHandlerAdapter.exceptionCaught(ChannelHandlerAdapter.java:79) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.ChannelHandlerInvokerUtil.invokeExceptionCaughtNow(ChannelHandlerInvokerUtil.java:64) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.DefaultChannelHandlerInvoker.invokeExceptionCaught(DefaultChannelHandlerInvoker.java:110) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.AbstractChannelHandlerContext.fireExceptionCaught(AbstractChannelHandlerContext.java:167) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.ChannelInboundHandlerAdapter.exceptionCaught(ChannelInboundHandlerAdapter.java:131) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.ChannelHandlerInvokerUtil.invokeExceptionCaughtNow(ChannelHandlerInvokerUtil.java:64) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.DefaultChannelHandlerInvoker.invokeExceptionCaught(DefaultChannelHandlerInvoker.java:110) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.AbstractChannelHandlerContext.fireExceptionCaught(AbstractChannelHandlerContext.java:167) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.handler.timeout.ReadTimeoutHandler.readTimedOut(ReadTimeoutHandler.java:186) [netty-handler-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.handler.timeout.ReadTimeoutHandler$ReadTimeoutTask.run(ReadTimeoutHandler.java:212) [netty-handler-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.util.concurrent.PromiseTask$RunnableAdapter.call(PromiseTask.java:38) [netty-common-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:123) [netty-common-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:343) [netty-common-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:356) [netty-transport-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:834) [netty-common-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:137) [netty-common-4.1.0.Beta3.jar:4.1.0.Beta3]
at java.lang.Thread.run(Thread.java:745) [na:1.8.0_20]
Caused by: io.netty.handler.timeout.ReadTimeoutException: null
Dec 31 2014 12:18:21.913 [nioEventLoopGroup-2-2] [Slf4JLogger.java:151] WARN i.n.c.DefaultChannelPipeline - .. and the cause of the exceptionCaught() was:
io.netty.handler.timeout.ReadTimeoutException: null

Thanks,

Ken

[jurmous]

I cannot reproduce your issue.. Can you share the code which is doing the put?

[aaskey]

This is with 3-node cluster. The local node is not etcd leader.

    String returnVal = null;

    EtcdResponsePromise<EtcdKeysResponse> putPromise = etcdClient.put(etcdKey, etcdValue)
            .timeout(10, TimeUnit.SECONDS).send();
    try {
        EtcdKeysResponse response = putPromise.get();
        returnVal = response.node.value;
        log.debug("Etcd putValue - key {}, value {}, return {}", etcdKey, etcdValue, returnVal);
    } catch (TimeoutException e) {
        // Handle timeout
        log.warn("Etcd putValue timeout exception {}, key {}, value {}", e.getMessage(), etcdKey, etcdValue);
        throw e;
    } catch (Exception e) {
        log.warn("Etcd putValue exception {}, key {}, value {}", e.getMessage(), etcdKey, etcdValue);
        throw e;
    }

[jurmous]

Thanks for reporting this issue! It is fixed in 2.0.1.

It was caused by a connection which was not closed on redirect. And the redirect happened because the client was not talking to the master node which is necessary for a put. And with the timeout the connection to the node would timeout while the new connection already did its job.