*TimeOutHandlers

[Trustin Lee]

Christian,

ReadTimeoutHandler seems to work just fine with JDK 1.6.0.12, Windows
Vista SP1.  Could you tell me your environment more in detail?

server started...
channel connected: NioAcceptedSocketChannel(id:
56024241-011f-1000-a20b-01e853f4ddac, /127.0.0.1:50050 =>
/127.0.0.1:12345)
22:10:14.354
22:10:24.393 readtimeout
22:10:34.479 readtimeout
22:10:44.465 readtimeout
22:10:54.438 readtimeout
22:11:04.414 readtimeout
22:11:14.370 readtimeout
22:11:24.314 readtimeout
22:11:34.252 readtimeout
22:11:44.179 readtimeout
22:11:54.143 readtimeout
22:12:04.067 readtimeout
22:12:14.008 readtimeout
22:12:23.955 readtimeout
22:12:33.929 readtimeout
22:12:43.890 readtimeout
22:12:53.814 readtimeout
22:13:03.761 readtimeout
22:13:13.714 readtimeout
22:13:23.661 readtimeout
...

Thanks,

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



On Sun, Feb 8, 2009 at 4:01 PM, Trustin Lee <trustin at gleamynode.net> wrote:
> Hi Christian,
>
> Thanks to your test code, I was able to fix the
> IllegalArgumentException.  It should never happen now.
>
> However, I was not able to reproduce the inaccurate delay issue in my
> environment.  I think your system might be returning an inaccurate
> value when HashedWheelTimer calls System.nanoTime().  What operating
> system are you using?  (I suspect it's Windows again :)  Anyway,
> HashedWheelTimer should work even if the precision of
> System.nanoTime() is not good enough.  Let me keep tracking down the
> problem.
>
> Cheers,
>
> — Trustin Lee, http://gleamynode.net/
>
>
>
> On Fri, Feb 6, 2009 at 10:06 PM, Christian Migowski
> <chrismfwrd at gmail.com> 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 lists.jboss.org
>> https://lists.jboss.org/mailman/listinfo/netty-users
>>
>