*TimeOutHandlers
Christian Migowski
chrismfwrd at gmail.com
Fri Feb 6 08:06:08 EST 2009
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!
More information about the netty-users
mailing list