2023-04-10 21:09:48,132 [http-nio-8080-exec-6] DEBUG Http11NioProtocol - Found processor [null] for socket [org.apache.tomcat.util.net.NioChannel@75e0481f:java.nio.channels.SocketChannel[connected local=/**ipv4**:8080 remote=/**ipv4**:37867]]
2023-04-10 21:09:48,132 [http-nio-8080-exec-6] DEBUG Http11NioProtocol - Popped processor [org.apache.coyote.http11.Http11Processor@2e00e63d] from cache
2023-04-10 21:09:48,132 [http-nio-8080-exec-6] DEBUG Http11InputBuffer - Before fill(): parsingHeader: [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position(): [0], byteBuffer.limit(): [0], end: [83]
2023-04-10 21:09:48,132 [http-nio-8080-exec-6] DEBUG Http11InputBuffer - Received [******1448 bytes of request data is logged here*******]
2023-04-10 21:09:48,132 [http-nio-8080-exec-6] DEBUG Http11InputBuffer - Before fill(): parsingHeader: [true], parsingRequestLine: [false], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position(): [1448], byteBuffer.limit(): [1448], end: [118]
2023-04-10 21:09:48,132 [http-nio-8080-exec-6] DEBUG Http11InputBuffer - Received []
2023-04-10 21:09:48,132 [http-nio-8080-exec-6] DEBUG Http11Processor - Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@29f02bf2:org.apache.tomcat.util.net.NioChannel@75e0481f:java.nio.channels.SocketChannel[connected local=/**ipv4**:8080 remote=/**ipv4**:37867]], Status in: [OPEN_READ], State out: [LONG]

after waiting for second(21:09:48,132 to 21:09:49,132), same request is now transferred to different http executor thread.

2023-04-10 21:09:49,132 [http-nio-8080-exec-10] DEBUG Http11NioProtocol - Processing socket [org.apache.tomcat.util.net.NioChannel@75e0481f:java.nio.channels.SocketChannel[connected local=/**ipv4**:8080 remote=/**ipv4**:37867]] with status [OPEN_READ]
2023-04-10 21:09:49,132 [http-nio-8080-exec-10] DEBUG Http11NioProtocol - Found processor [org.apache.coyote.http11.Http11Processor@2e00e63d] for socket [org.apache.tomcat.util.net.NioChannel@75e0481f:java.nio.channels.SocketChannel[connected local=/**ipv4**:8080 remote=/**ipv4**:37867]]
2023-04-10 21:09:49,132 [http-nio-8080-exec-10] DEBUG Http11NioProtocol - Removed processor [org.apache.coyote.http11.Http11Processor@2e00e63d] from waiting processors
2023-04-10 21:09:49,132 [http-nio-8080-exec-10] DEBUG Http11InputBuffer - Before fill(): parsingHeader: [true], parsingRequestLine: [false], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position(): [1448], byteBuffer.limit(): [1448], end: [118]
2023-04-10 21:09:49,132 [http-nio-8080-exec-10] DEBUG Http11InputBuffer - Received [***** second part of  same request*****]
2023-04-10 21:09:49,142 [http-nio-8080-exec-10] DEBUG GzipOutputFilter - Flushing the compression stream!
2023-04-10 21:09:49,143 [http-nio-8080-exec-10] DEBUG GzipOutputFilter - Flushing the compression stream!
2023-04-10 21:09:49,143 [http-nio-8080-exec-10] DEBUG GzipOutputFilter - Flushing the compression stream!
2023-04-10 21:09:49,143 [http-nio-8080-exec-10] DEBUG Http11InputBuffer - Before fill(): parsingHeader: [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position(): [0], byteBuffer.limit(): [0], end: [1714]
2023-04-10 21:09:49,143 [http-nio-8080-exec-10] DEBUG Http11InputBuffer - Received []
2023-04-10 21:09:49,144 [http-nio-8080-exec-10] DEBUG Http11Processor - Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@29f02bf2:org.apache.tomcat.util.net.NioChannel@75e0481f:java.nio.channels.SocketChannel[connected local=/**ipv4**:8080 remote=/**ipv4**:37867]], Status in: [OPEN_READ], State out: [OPEN]
2023-04-10 21:09:49,144 [http-nio-8080-exec-10] DEBUG Http11NioProtocol - Pushed Processor [org.apache.coyote.http11.Http11Processor@2e00e63d]

We are seeing delay in processing http request by 1 sec on SpringBoot 2.6.14 embedded Tomcat 9.0.69 running on RHEL8/JDK11. Looks like execution of same request is transferred from thread http-nio-8080-exec-6 to http-nio-8080-exec-10 after reading 1448 bytes of data.

  • http-nio-8080-exec-6 reads partial data 1448
  • Request is now assigned to new thread http-nio-8080-exec-10 after 1 sec delay.
  • Read remaining bytes of data from socket of same request which was originally handled by http-nio-8080-exec-6
  • http-nio-8080-exec-10 completes processing request.

How can we configure or avoid execution transfer? Under what circumstances does tomcat schedule current request to different executor thread?

Thank you in advance!

0

There are 0 best solutions below