write-timeout and ClosedChannelException

classic Classic list List threaded Threaded
1 message Options
Reply | Threaded
Open this post in threaded view
|

write-timeout and ClosedChannelException

Panos Konstantinidis
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: null
at 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

_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev