ClosedChannelException (Was: Re: *TimeOutHandlers)

Trustin Lee (이희승) trustin at gmail.com
Sat Feb 7 12:41:37 EST 2009


Hi Dave,

Thanks for sharing your code first of all.  I will definitely look into it.

However, it would be great if you can send this kind of message with a
fresh message (i.e. not pressing the reply button) and with a
different (i.e. more relevant) subject.  I receive high volume of
messages so your small effort will help me a lot.  Also, please send
the description of the problem to the public mailing list and send the
attachment to me privately if necessary.  Other people might inspire
you with their experience. :-)

Anyway, ClosedChannelException in this case means you tried to write
something after a connection is closed.  It might be either a timing
issue or unexpected disconnection.  Under heavy load, I think
ClosedChannelException occurs pretty often even if the implementation
is just fine.  YMMV though.

HTH and Cheers,

— Trustin Lee, http://gleamynode.net/

On Sun, Feb 8, 2009 at 1:56 AM, Siracusa, Dave (YBUSA-KOP)
<Dave.Siracusa at yellowbook.com> wrote:
> Hi Trustin
>
>
>
> I've attached the source to my http proxy prototype.
>
> I also attached an updated httpserver (returns a larger response & listens
> on port 80).
>
>
>
> Under heavy stress I get unexpected errors.
>
>
>
> Steps to Reproduce:
>
> 1. Run the httpserver
>
> 2. I create a host entry called netty for 127.0.0.1
>
> 3. Launch jmeter w/ jmeter.bat -H localhost -P 8080
>
> a. Setup a Thread Group – Threads: 50, Loop count: 10
>
> b. Setup a nested Http Request specifying server name: netty
>
>
>
> Best,
>
> --Dave
>
>
>
> Here are the errors:
>
> WARNING: HttpRequestHandler.Unexpected exception from downstream.
>
> java.nio.channels.ClosedChannelException
>
>             at
> org.jboss.netty.channel.socket.nio.NioWorker.cleanUpWriteBuffer(NioWorker.java:530)
>
>             at
> org.jboss.netty.channel.socket.nio.NioWorker.write(NioWorker.java:321)
>
>             at
> org.jboss.netty.channel.socket.nio.NioServerSocketPipelineSink.handleAcceptedSocket(NioServerSocketPipelineSink.java:138)
>
>             at
> org.jboss.netty.channel.socket.nio.NioServerSocketPipelineSink.eventSunk(NioServerSocketPipelineSink.java:78)
>
>             at org.jboss.netty.channel.Channels.write(Channels.java:890)
>
>             at
> org.jboss.netty.handler.codec.oneone.OneToOneEncoder.handleDownstream(OneToOneEncoder.java:71)
>
>             at org.jboss.netty.channel.Channels.write(Channels.java:870)
>
>             at org.jboss.netty.channel.Channels.write(Channels.java:818)
>
>             at
> org.jboss.netty.channel.AbstractChannel.write(AbstractChannel.java:207)
>
>             at
> org.jboss.netty.example.proxy.HttpResponseHandler.messageReceived(HttpResponseHandler.java:77)
>
>             at
> org.jboss.netty.example.proxy.HttpResponseHandler.handleUpstream(HttpResponseHandler.java:130)
>
>             at
> org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:379)
>
>             at
> org.jboss.netty.handler.codec.replay.ReplayingDecoder.callDecode(ReplayingDecoder.java:401)
>
>             at
> org.jboss.netty.handler.codec.replay.ReplayingDecoder.messageReceived(ReplayingDecoder.java:345)
>
>             at
> org.jboss.netty.handler.codec.replay.ReplayingDecoder.handleUpstream(ReplayingDecoder.java:308)
>
>             at
> org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:336)
>
>             at
> org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:323)
>
>             at
> org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:301)
>
>             at
> org.jboss.netty.channel.socket.nio.NioWorker.processSelectedKeys(NioWorker.java:253)
>
>             at
> org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:170)
>
>             at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
>
>             at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
>
>             at java.lang.Thread.run(Thread.java:619)
>
>
>
>
>
> ________________________________
>
> From: Trustin Lee-3 (via Nabble)
> [mailto:ml-user+162222-252043752 at n2.nabble.com]
> Sent: Saturday, February 07, 2009 8:21 AM
> To: Siracusa, Dave (YBUSA-KOP)
> Subject: Re: *TimeOutHandlers
>
>
>
> Thanks Dave for the detailed bug report.  I've just checked in the fix
> for this silly bug. :)
>
> Will take a look at Christian's code soon ..
>
> — Trustin Lee, http://gleamynode.net/
>
>
>
> On Sat, Feb 7, 2009 at 8:34 AM, Dave Siracusa
> <dave.siracusa at ...> wrote:
>
>>
>> A bug in: ReadTimeOutHandler.channelClosed, it shouldn't call
>> super.channelOpen
>>  @Override
>>    public void channelClosed(ChannelHandlerContext ctx, ChannelStateEvent
>> e)
>>            throws Exception {
>>        destroy();
>>        super.channelOpen(ctx, e);
>>    }
>> - Dave
>>
>>
>> christian wrote:
>>>
>>> Hi,
>>>
>>> I was playing around with the new TimeoutHandlers (which are a great
>>> addition to Netty!) and found out that they are quite inaccurate. I
>>> setup a small sample which one server and just one client which are
>>> not sending regular messages, just in case of a timeout, and found out
>>> that the read timeout is of up to 4 seconds (in both directions) when
>>> wanting a 10 second timeout. Here is how I setup the server chain
>>> (client doesn't do timeout handling):
>>>
>>>       Timer timer = new HashedWheelTimer(10, TimeUnit.MILLISECONDS, 10);
>>>       pipeline.addLast("readTimeout", new ReadTimeoutHandler(timer, 10,
>>> TimeUnit.SECONDS));
>>>       pipeline.addLast("writeTimeout", new WriteTimeoutHandler(timer, 5,
>>> TimeUnit.SECONDS));
>>>
>>>       pipeline.addLast("handler", new TestHandler());
>>>
>>>
>>> and this is the exceptionCaught() of TestHandler method:
>>>     public void exceptionCaught(ChannelHandlerContext ctx, ExceptionEvent
>>> e) {
>>>       if (e.getCause() instanceof ChannelWriteTimeoutException) {
>>>           System.out.println(new
>>> SimpleDateFormat("HH:mm:ss.SSS").format(new Date())+" writetimeout");
>>>           writeTime(e.getChannel());
>>>       } else if (e.getCause() instanceof ChannelReadTimeoutException) {
>>>           System.out.println(new
>>> SimpleDateFormat("HH:mm:ss.SSS").format(new Date())+" readtimeout");
>>>           writeTime(e.getChannel());
>>>       } else {
>>>           e.getCause().printStackTrace();
>>>           Channel ch = e.getChannel();
>>>           ch.close().awaitUninterruptibly();
>>>           System.out.println("channel closed");
>>>       }
>>>     }
>>>
>>> it produces e.g. this output:
>>>
>>> 13:58:39.773 readtimeout
>>> 13:58:46.634 readtimeout
>>> 13:58:53.506 readtimeout
>>> 13:59:00.378 readtimeout
>>> 13:59:07.238 readtimeout
>>> 13:59:14.110 readtimeout
>>> 13:59:20.971 readtimeout
>>> 13:59:27.843 readtimeout
>>> 13:59:34.714 readtimeout
>>> 13:59:41.575 readtimeout
>>> 13:59:48.447 readtimeout
>>> 13:59:55.319 readtimeout
>>> 14:00:02.179 readtimeout
>>> 14:00:09.120 readtimeout
>>> 14:00:17.974 readtimeout
>>>
>>>
>>> as you can see it is never 10 seconds. Also, although the writetimeout
>>> is set lower, it is never fired, which seems like a bug to me.
>>> Also, because of that inaccurateness, sometimes exceptions in the
>>> timer occur (this is not always reproducable):
>>>
>>> 06.02.2009 12:37:00 org.jboss.netty.handler.timeout.HashedWheelTimer
>>> WARNUNG: An exception was thrown by TimerTask.
>>> java.lang.IllegalArgumentException: delay must be greater than
>>> 10000000 nanoseconds
>>>       at
>>>
>>> org.jboss.netty.handler.timeout.HashedWheelTimer.checkDelay(HashedWheelTimer.java:242)
>>>       at
>>>
>>> org.jboss.netty.handler.timeout.HashedWheelTimer.newTimeout(HashedWheelTimer.java:197)
>>>       at
>>>
>>> org.jboss.netty.handler.timeout.ReadTimeoutHandler$ReadTimeoutTask.run(ReadTimeoutHandler.java:145)
>>>       at
>>>
>>> org.jboss.netty.handler.timeout.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:399)
>>>       at
>>>
>>> org.jboss.netty.handler.timeout.HashedWheelTimer$Worker.notifyExpiredTimeouts(HashedWheelTimer.java:318)
>>>       at
>>>
>>> org.jboss.netty.handler.timeout.HashedWheelTimer$Worker.run(HashedWheelTimer.java:266)
>>>       at java.lang.Thread.run(Thread.java:595)
>>>
>>>
>>> Is this (the inaccurateness) expected because of the implementation of
>>> the HashedWheelTimer or did I just choose unlucky values? Or is it a
>>> bug in the timer implementation?
>>>
>>>
>>>
>>>
>>> greetings,
>>> christian!
>>> _______________________________________________
>>> netty-users mailing list
>>> netty-users at ...
>>> https://lists.jboss.org/mailman/listinfo/netty-users
>>>
>>>
>>
>> --
>> View this message in context:
>> http://n2.nabble.com/*TimeOutHandlers-tp2283992p2287118.html
>> Sent from the Netty User Group mailing list archive at Nabble.com.
>>
>> _______________________________________________
>> netty-users mailing list
>> netty-users at ...
>> https://lists.jboss.org/mailman/listinfo/netty-users
>>
>
> _______________________________________________
> netty-users mailing list
> netty-users at ...
> https://lists.jboss.org/mailman/listinfo/netty-users
>
> ________________________________
>
> This email is a reply to your post @
> http://n2.nabble.com/*TimeOutHandlers-tp2283992p2289107.html
> You can reply by email or by visting the link above.
>
>




More information about the netty-users mailing list