[wildfly-dev] write-timeout and ClosedChannelException
Panos Konstantinidis
girionis at yahoo.com
Thu Dec 7 05:53:40 EST 2017
Hello,
apologies in advance if this is not the right place to ask questions, but I have some questions that require in-depth understanding of Wildfly and it seems that the users' forum is not the right place to ask them. We have a Wildfly instance installed (wildfly-10.1.0.Final) on standalone mode. We have added a write-timeout="45000" to http-listener & https-listener on production, but we noticed that we get a lot of ClosedChannelException errors: java.nio.channels.ClosedChannelException: nullat io.undertow.conduits.WriteTimeoutStreamSinkConduit.handleWriteTimeout(WriteTimeoutStreamSinkConduit.java:106)at io.undertow.conduits.WriteTimeoutStreamSinkConduit.write(WriteTimeoutStreamSinkConduit.java:122) I would have expected to only see WriteTimeoutException errors, as described here (WildFly 10.0 Model Reference ), which we do, but very occasionally. By looking at the undertow code (io.undertow.conduits.WriteTimeoutStreamSinkConduit) I noticed that the ClosedChannelException is thrown at the following piece of code: if (expireTimeVar != -1 && currentTime > expireTimeVar) { IoUtils.safeClose(connection); throw new ClosedChannelException(); } We managed to reproduce the problem on the UAT environment, with the following settings: <http-listener name="default" tcp-keep-alive="false" read-timeout="45000" write-timeout="10000" socket-binding="http" record-request-start-time="true" redirect-socket="https" enable-http2="true"/> <https-listener name="https" tcp-keep-alive="false" read-timeout="45000" write-timeout="10000" socket-binding="https" record-request-start-time="true" security-realm="ApplicationRealm" enable-http2="true"/>
and also with the following:
<http-listener name="default" tcp-keep-alive="true" read-timeout="45000" write-timeout="10000" socket-binding="http" record-request-start-time="true" redirect-socket="https" enable-http2="true"/> <https-listener name="https" tcp-keep-alive="true" read-timeout="45000" write-timeout="10000" socket-binding="https" record-request-start-time="true" security-realm="ApplicationRealm" enable-http2="true"/>
We cloned the undertow code and changed the WriteTimeoutStreamSinkConduit.java ourselves (we just added a few debug statements), rebuilt the undertow-core-1.4.0.Final.jar and replaced the one in the UAT environment with our custom version. I noticed the following in the logs [INFO ] 2017-12-05 12:48:57.240 [default task-6] [pt0_WuRKH4rsd6yPRrXen53Ee2OiPGlNed64iFrI] stdout [?:?] - Updating expire time to: currentTime: 1512470937239 + timeout: 10000[INFO ] 2017-12-05 12:49:11.452 [default task-4] [pt0_WuRKH4rsd6yPRrXen53Ee2OiPGlNed64iFrI] stdout [?:?] - Timeout is set to: 10000[INFO ] 2017-12-05 12:49:11.453 [default task-4] [pt0_WuRKH4rsd6yPRrXen53Ee2OiPGlNed64iFrI] stdout [?:?] - currentTime is: 1512470951453 and expireTime is: 1512470947239[INFO ] 2017-12-05 12:49:11.454 [default task-4] [pt0_WuRKH4rsd6yPRrXen53Ee2OiPGlNed64iFrI] stdout [?:?] - currentTime > expireTimeVar: true[ERROR] 2017-12-05 12:49:11.455 [default task-4] [pt0_WuRKH4rsd6yPRrXen53Ee2OiPGlNed64iFrI] g.c.RestExceptionHandler [RestExceptionHandler.java:24] - Exception Thrown: java.nio.channels.ClosedChannelException If you notice we are talking about two different requests (different thread name) under the same user (same session id) with 14'' delay. I *guess* this exception occurs because the same socket is reused for both requests (for both threads) and thus the expire time applies for all requests over the same socket. But in this case I would expect a WriteTimeoutException, as explained in the docs. So my questions are: a) How exactly does the write-timeout work? I would have thought that each new request resets the timer.b) Why don't I get a WriteTimeoutException instead? There are days that we see hundreds of ClosedChannelException but no WriteTimeoutException.c) Is there any way to avoid the ClosedChannelException? None of our users has complained yet, but the stack traces clog our log files. Regards Panos
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.jboss.org/pipermail/wildfly-dev/attachments/20171207/676970d4/attachment-0001.html
More information about the wildfly-dev
mailing list