Mark Mindenhall created CAMEL-8193:
--------------------------------------
Summary: Frequent BlockingOperationExceptions under load
Key: CAMEL-8193
URL: https://issues.apache.org/jira/browse/CAMEL-8193
Project: Camel
Issue Type: Bug
Components: camel-netty, camel-netty4
Affects Versions: 2.14.1
Environment: Ubuntu 14.04, JDK 1.8.0_25
Reporter: Mark Mindenhall
I have a class that combines a netty4 consumer with a kafka producer, pulling
messages off of a TCP socket and sticking them into kafka for further
processing. While doing some load testing, I started seeing a lot of stack
traces like the following:
{noformat}
2014-12-29 19:55:57,517 - [WARN] - from io.netty.util.concurrent.DefaultPromise
in Camel Thread #23 - NettyServerTCPWorker
An exception was thrown by
org.apache.camel.component.netty4.handlers.ServerResponseFutureListener.operationComplete()
io.netty.util.concurrent.BlockingOperationException:
DefaultChannelPromise@4e2727d0(uncancellable)
at
io.netty.util.concurrent.DefaultPromise.checkDeadLock(DefaultPromise.java:390)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.DefaultChannelPromise.checkDeadLock(DefaultChannelPromise.java:157)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.util.concurrent.DefaultPromise.awaitUninterruptibly(DefaultPromise.java:283)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.DefaultChannelPromise.awaitUninterruptibly(DefaultChannelPromise.java:135)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.DefaultChannelPromise.awaitUninterruptibly(DefaultChannelPromise.java:28)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.util.concurrent.DefaultPromise.syncUninterruptibly(DefaultPromise.java:225)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.DefaultChannelPromise.syncUninterruptibly(DefaultChannelPromise.java:123)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.DefaultChannelPromise.syncUninterruptibly(DefaultChannelPromise.java:28)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
org.apache.camel.component.netty4.NettyHelper.close(NettyHelper.java:121)
~[camel-netty4-2.14.1.jar:2.14.1]
at
org.apache.camel.component.netty4.handlers.ServerResponseFutureListener.operationComplete(ServerResponseFutureListener.java:80)
~[camel-netty4-2.14.1.jar:2.14.1]
at
org.apache.camel.component.netty4.handlers.ServerResponseFutureListener.operationComplete(ServerResponseFutureListener.java:36)
~[camel-netty4-2.14.1.jar:2.14.1]
at
io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:680)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:567)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:406)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.DefaultChannelPromise.trySuccess(DefaultChannelPromise.java:82)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.ChannelOutboundBuffer.safeSuccess(ChannelOutboundBuffer.java:523)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.ChannelOutboundBuffer.remove(ChannelOutboundBuffer.java:247)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.ChannelOutboundBuffer.removeBytes(ChannelOutboundBuffer.java:322)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.socket.nio.NioSocketChannel.doWrite(NioSocketChannel.java:301)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:745)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.flush0(AbstractNioChannel.java:315)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.AbstractChannel$AbstractUnsafe.flush(AbstractChannel.java:713)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.DefaultChannelPipeline$HeadContext.flush(DefaultChannelPipeline.java:1159)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.ChannelHandlerInvokerUtil.invokeFlushNow(ChannelHandlerInvokerUtil.java:165)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.DefaultChannelHandlerInvoker.invokeFlush(DefaultChannelHandlerInvoker.java:355)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:297)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.ChannelOutboundHandlerAdapter.flush(ChannelOutboundHandlerAdapter.java:115)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.ChannelHandlerInvokerUtil.invokeFlushNow(ChannelHandlerInvokerUtil.java:165)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.channel.DefaultChannelHandlerInvoker$16.run(DefaultChannelHandlerInvoker.java:363)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:343)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:356)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at
io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:834)
[netty-all-4.1.0.Beta3.jar:4.1.0.Beta3]
at java.lang.Thread.run(Thread.java:745) [na:1.8.0_20]
{noformat}
The documentation for
[ChannelFuture|http://netty.io/4.1/api/io/netty/channel/ChannelFuture.html]
says "Do not call {{await()}} inside {{ChannelHandler}}", due to a possible
deadlock. Per the documentation, this results in an {{IllegalStateException}}
(netty3) or a {{BlockingOperationException}} (netty4+).
The javadoc for
{{[NettyHelper.close|http://camel.apache.org/maven/camel-2.14.0/camel-netty/apidocs/org/apache/camel/component/netty/NettyHelper.html#close%28org.jboss.netty.channel.Channel%29]}}
claims to close the channel asynchronously, but that method calls
{{channel.close().syncUninterruptibly()}}, which blocks waiting for the channel
to close and results in the exception under certain conditions.
The attached patch resolves this issue for both the camel-netty and
camel-netty4 components.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
