I have a Tomcat 8 websocket application and noticed a certain behavior when handling websocket client calls. Some details:
http-nio-8080-exec-3 - 18:50:56 <-- this takes 30 seconds
http-nio-8080-exec-3 - 18:50:56 <--+
http-nio-8080-exec-3 - 18:50:56 |
http-nio-8080-exec-3 - 18:50:56 |
http-nio-8080-exec-3 - 18:50:56 |
http-nio-8080-exec-3 - 18:50:56 |
http-nio-8080-exec-3 - 18:50:56 |
http-nio-8080-exec-3 - 18:50:56 |
http-nio-8080-exec-3 - 18:50:56 |
http-nio-8080-exec-3 - 18:50:56 |
http-nio-8080-exec-3 - 18:50:56 |- these take less than a
http-nio-8080-exec-3 - 18:50:56 | second but get queued
http-nio-8080-exec-3 - 18:50:56 | after the first one that
http-nio-8080-exec-3 - 18:50:56 | takes 30 seconds
http-nio-8080-exec-3 - 18:50:56 |
http-nio-8080-exec-3 - 18:50:56 |
http-nio-8080-exec-3 - 18:50:56 |
http-nio-8080-exec-3 - 18:50:56 |
http-nio-8080-exec-3 - 18:50:56 |
http-nio-8080-exec-3 - 18:50:56 |
http-nio-8080-exec-3 - 18:50:56 <--+
The above is showing the server logs for some client calls fired in close succession (the name of the thread in the pool and the time the response was sent to the client). The first call takes 30 seconds while the rest take less than a second. The problem is that the fast calls are queued behind the slow one and are being handled by the same thread in Tomcat's pool.
I would have expected something like this instead:
http-nio-8080-exec-3 - 18:50:56 <-- this takes 30 seconds
http-nio-8080-exec-7 - 18:50:26 <---+
http-nio-8080-exec-5 - 18:50:26 |
http-nio-8080-exec-2 - 18:50:26 |
http-nio-8080-exec-1 - 18:50:26 |
http-nio-8080-exec-8 - 18:50:26 |
http-nio-8080-exec-10 - 18:50:26 |
http-nio-8080-exec-11 - 18:50:26 |
http-nio-8080-exec-9 - 18:50:26 |
http-nio-8080-exec-20 - 18:50:26 |
http-nio-8080-exec-13 - 18:50:26 |- these take less than a
http-nio-8080-exec-15 - 18:50:26 | second, don't depend
http-nio-8080-exec-17 - 18:50:26 | on the first one, and
http-nio-8080-exec-22 - 18:50:26 | are handled by different
http-nio-8080-exec-5 - 18:50:26 | threads
http-nio-8080-exec-7 - 18:50:26 |
http-nio-8080-exec-12 - 18:50:26 |
http-nio-8080-exec-16 - 18:50:26 |
http-nio-8080-exec-11 - 18:50:26 |
http-nio-8080-exec-22 - 18:50:26 |
http-nio-8080-exec-13 - 18:50:26 <--+
But I get the first version, not the second one.
If I don't run all calls in quick succession but wait for the responses I do get what I expect:
http-nio-8080-exec-8 - 18:54:20
http-nio-8080-exec-6 - 18:55:21
http-nio-8080-exec-7 - 18:56:20
http-nio-8080-exec-9 - 18:57:20
http-nio-8080-exec-2 - 18:58:20
http-nio-8080-exec-1 - 18:59:21
.... etc ....
From what I've found (e.g. here: http://grokbase.com/t/tomcat/users/125zhqcz2s/non-blocking-websockets and here: Tomcat 8 JSR 356 WebSocket Threading) I understand this is the behavior as implemented.
Is it possible to have all calls execute in parallel, each call using another thread from the pool?