Hi,
I experienced problems in my production infrastructure with remote
calls. Tomcat seams to do some http connections pooling, and some of the
connections seams to not to receive the TCP FIN flag of the server.
Below is a more detailed explanation of the detected problem. I don't
know where the problem come from (maybe APR lib), but I start to post
here with hope to be redirected to the right place if needed.
I use tomcat6.0.18, with APR connector on debian 4.0 (etch) (libapr1
1.2.7-8.2), hessian protocol for the remote calls.
So I have a request from a browser which trigger a remote call.
According to the dumped traffic, the remote calls are pooled, so tomcat
(apr?HttpClient?java.net?) reuse previous opened connection.
But what is strange, seen in the tcpdump, is that at one point the
connection receive a TCP FIN flag from the server, but use again the
open connection, then receive a TCP RST flag, and then the connections
freeze until the timeout of the connector.
In attachment is provided the tcpdump of the last request, followed by a
[FIN,ACK] of the server, and a new request from the client 3 seconds
later, resulting in a [RST] from the server.
And a second file which have the two freezed thread dumps.
As I do not use advanced sendFile or cometPoll feature, the workaround
for this problem was to explicitly disable APR connector, returning to
org.apache.coyote.http11.Http11Protocol.
Has someone already such problem ? Is this problem already known ?
Thanks in advance for your help
The caller thread
"http-9000-6" daemon prio=10 tid=0x08749800 nid=0x6cba runnable
[0x27e5a000..0x27e5cfc0]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
at java.io.BufferedInputStream.read(BufferedInputStream.java:317)
- locked <0x53096b68> (a java.io.BufferedInputStream)
at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:687)
at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:632)
at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:766)
at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:632)
at
sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1000)
- locked <0x530da6c0> (a sun.net.www.protocol.http.HttpURLConnection)
at
java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:373)
at com.caucho.hessian.client.HessianProxy.invoke(HessianProxy.java:168)
at $Proxy553.getIndicatorValuesById(Unknown Source)
at sun.reflect.GeneratedMethodAccessor2825.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at
org.springframework.remoting.caucho.HessianClientInterceptor.invoke(HessianClientInterceptor.java:218)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at $Proxy554.getIndicatorValuesById(Unknown Source)
at sun.reflect.GeneratedMethodAccessor2825.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at
ch.elca.el4j.services.remoting.ClientContextInvocationHandler.invoke(ClientContextInvocationHandler.java:139)
at $Proxy555.getIndicatorValuesById(Unknown Source)
at sun.reflect.GeneratedMethodAccessor2824.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:301)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:198)
at $Proxy556.getIndicatorValuesById(Unknown Source)
at sun.reflect.GeneratedMethodAccessor2824.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:301)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:198)
at $Proxy556.getIndicatorValuesById(Unknown Source)
... lots of business stuff until remote hessian call ...
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
at
org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:568)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:286)
at
org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:856)
at
org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:565)
at
org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1509)
at java.lang.Thread.run(Thread.java:619)
the callee thread
"http-9000-3" daemon prio=10 tid=0x086f5400 nid=0x6cb7 runnable
[0x2855b000..0x2855d140]
java.lang.Thread.State: RUNNABLE
at org.apache.tomcat.jni.Socket.recvbb(Native Method)
at
org.apache.coyote.http11.InternalAprInputBuffer.fill(InternalAprInputBuffer.java:754)
at
org.apache.coyote.http11.InternalAprInputBuffer$SocketInputBuffer.doRead(InternalAprInputBuffer.java:792)
at
org.apache.coyote.http11.filters.ChunkedInputFilter.readBytes(ChunkedInputFilter.java:243)
at
org.apache.coyote.http11.filters.ChunkedInputFilter.parseChunkHeader(ChunkedInputFilter.java:273)
at
org.apache.coyote.http11.filters.ChunkedInputFilter.doRead(ChunkedInputFilter.java:132)
at
org.apache.coyote.http11.InternalAprInputBuffer.doRead(InternalAprInputBuffer.java:703)
at org.apache.coyote.Request.doRead(Request.java:428)
at
org.apache.catalina.connector.InputBuffer.realReadBytes(InputBuffer.java:298)
at org.apache.tomcat.util.buf.ByteChunk.substract(ByteChunk.java:405)
at org.apache.catalina.connector.InputBuffer.read(InputBuffer.java:313)
at
org.apache.catalina.connector.CoyoteInputStream.read(CoyoteInputStream.java:193)
at
com.caucho.hessian.io.Hessian2Input.readBuffer(Hessian2Input.java:2644)
at com.caucho.hessian.io.Hessian2Input.read(Hessian2Input.java:2624)
at
org.springframework.remoting.caucho.Hessian2SkeletonInvoker.invoke(Hessian2SkeletonInvoker.java:68)
at
org.springframework.remoting.caucho.HessianExporter.invoke(HessianExporter.java:142)
at
org.springframework.remoting.caucho.HessianServiceExporter.handleRequest(HessianServiceExporter.java:70)
at
org.springframework.web.servlet.mvc.HttpRequestHandlerAdapter.handle(HttpRequestHandlerAdapter.java:49)
at
org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:875)
at
org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:809)
at
org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:476)
at
org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:441)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at
org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:70)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
... business filters until hessian handling ...
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
at
org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:568)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:286)
at
org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:856)
at
org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:565)
at
org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1509)
at java.lang.Thread.run(Thread.java:619)
No. Time Source Destination Protocol Info
4552 3009.785479 127.0.0.1 127.0.0.1 TCP 39801
> 9000 [PSH, ACK] Seq=52838 Ack=51847 Win=49536 [TCP CHECKSUM INCORRECT]
Len=293 TSV=372932877 TSER=372932869
Frame 4552 (359 bytes on wire, 359 bytes captured)
Ethernet II, Src: 00:00:00:00:00:00 (00:00:00:00:00:00), Dst: 00:00:00:00:00:00
(00:00:00:00:00:00)
Internet Protocol, Src: 127.0.0.1 (127.0.0.1), Dst: 127.0.0.1 (127.0.0.1)
Transmission Control Protocol, Src Port: 39801 (39801), Dst Port: 9000 (9000),
Seq: 52838, Ack: 51847, Len: 293
Data (293 bytes)
0000 50 4f 53 54 20 2f 74 6e 63 6f 2f 63 6f 6d 2e 73 POST /tnco/com.s
<anonymize>
0050 54 54 50 2f 31 2e 31 0d 0a 43 6f 6e 74 65 6e 74 TTP/1.1..Content
0060 2d 54 79 70 65 3a 20 78 2d 61 70 70 6c 69 63 61 -Type: x-applica
0070 74 69 6f 6e 2f 68 65 73 73 69 61 6e 0d 0a 55 73 tion/hessian..Us
0080 65 72 2d 41 67 65 6e 74 3a 20 4a 61 76 61 2f 31 er-Agent: Java/1
0090 2e 36 2e 30 5f 30 37 0d 0a 48 6f 73 74 3a 20 69 .6.0_07..Host: i
<anonymize>
00e0 2e 32 2c 20 2a 2f 2a 3b 20 71 3d 2e 32 0d 0a 43 .2, */*; q=.2..C
00f0 6f 6e 6e 65 63 74 69 6f 6e 3a 20 6b 65 65 70 2d onnection: keep-
0100 61 6c 69 76 65 0d 0a 54 72 61 6e 73 66 65 72 2d alive..Transfer-
0110 45 6e 63 6f 64 69 6e 67 3a 20 63 68 75 6e 6b 65 Encoding: chunke
0120 64 0d 0a 0d 0a d....
No. Time Source Destination Protocol Info
4553 3009.785479 127.0.0.1 127.0.0.1 TCP 39801
> 9000 [PSH, ACK] Seq=53131 Ack=51847 Win=49536 [TCP CHECKSUM INCORRECT]
Len=322 TSV=372932877 TSER=372932869
Frame 4553 (388 bytes on wire, 388 bytes captured)
Ethernet II, Src: 00:00:00:00:00:00 (00:00:00:00:00:00), Dst: 00:00:00:00:00:00
(00:00:00:00:00:00)
Internet Protocol, Src: 127.0.0.1 (127.0.0.1), Dst: 127.0.0.1 (127.0.0.1)
Transmission Control Protocol, Src Port: 39801 (39801), Dst Port: 9000 (9000),
Seq: 53131, Ack: 51847, Len: 322
Data (322 bytes)
0000 31 33 62 0d 0a 63 01 00 6d 00 0e 67 65 74 43 6f 13b..c..m..getCo
<anonymize>
0130 61 6c 75 65 53 00 05 66 72 5f 46 52 7a 7a 7a 7a alueS..fr_FRzzzz
0140 0d 0a ..
No. Time Source Destination Protocol Info
4554 3009.785479 127.0.0.1 127.0.0.1 TCP 9000 >
39801 [ACK] Seq=51847 Ack=53453 Win=49536 Len=0 TSV=372932877 TSER=372932877
Frame 4554 (66 bytes on wire, 66 bytes captured)
Ethernet II, Src: 00:00:00:00:00:00 (00:00:00:00:00:00), Dst: 00:00:00:00:00:00
(00:00:00:00:00:00)
Internet Protocol, Src: 127.0.0.1 (127.0.0.1), Dst: 127.0.0.1 (127.0.0.1)
Transmission Control Protocol, Src Port: 9000 (9000), Dst Port: 39801 (39801),
Seq: 51847, Ack: 53453, Len: 0
No. Time Source Destination Protocol Info
4555 3009.785479 127.0.0.1 127.0.0.1 TCP 39801
> 9000 [PSH, ACK] Seq=53453 Ack=51847 Win=49536 [TCP CHECKSUM INCORRECT] Len=3
TSV=372932877 TSER=372932877
Frame 4555 (69 bytes on wire, 69 bytes captured)
Ethernet II, Src: 00:00:00:00:00:00 (00:00:00:00:00:00), Dst: 00:00:00:00:00:00
(00:00:00:00:00:00)
Internet Protocol, Src: 127.0.0.1 (127.0.0.1), Dst: 127.0.0.1 (127.0.0.1)
Transmission Control Protocol, Src Port: 39801 (39801), Dst Port: 9000 (9000),
Seq: 53453, Ack: 51847, Len: 3
Data (3 bytes)
0000 30 0d 0a 0..
No. Time Source Destination Protocol Info
4556 3009.785479 127.0.0.1 127.0.0.1 TCP 39801
> 9000 [PSH, ACK] Seq=53456 Ack=51847 Win=49536 [TCP CHECKSUM INCORRECT] Len=2
TSV=372932877 TSER=372932877
Frame 4556 (68 bytes on wire, 68 bytes captured)
Ethernet II, Src: 00:00:00:00:00:00 (00:00:00:00:00:00), Dst: 00:00:00:00:00:00
(00:00:00:00:00:00)
Internet Protocol, Src: 127.0.0.1 (127.0.0.1), Dst: 127.0.0.1 (127.0.0.1)
Transmission Control Protocol, Src Port: 39801 (39801), Dst Port: 9000 (9000),
Seq: 53456, Ack: 51847, Len: 2
Data (2 bytes)
0000 0d 0a ..
No. Time Source Destination Protocol Info
4557 3009.797485 127.0.0.1 127.0.0.1 TCP 9000 >
39801 [PSH, ACK] Seq=51847 Ack=53458 Win=49536 [TCP CHECKSUM INCORRECT] Len=892
TSV=372932880 TSER=372932877
Frame 4557 (958 bytes on wire, 958 bytes captured)
Ethernet II, Src: 00:00:00:00:00:00 (00:00:00:00:00:00), Dst: 00:00:00:00:00:00
(00:00:00:00:00:00)
Internet Protocol, Src: 127.0.0.1 (127.0.0.1), Dst: 127.0.0.1 (127.0.0.1)
Transmission Control Protocol, Src Port: 9000 (9000), Dst Port: 39801 (39801),
Seq: 51847, Ack: 53458, Len: 892
Data (892 bytes)
0000 48 54 54 50 2f 31 2e 31 20 32 30 30 20 4f 4b 0d HTTP/1.1 200 OK.
0010 0a 53 65 72 76 65 72 3a 20 41 70 61 63 68 65 2d .Server: Apache-
0020 43 6f 79 6f 74 65 2f 31 2e 31 0d 0a 43 6f 6e 74 Coyote/1.1..Cont
0030 65 6e 74 2d 4c 65 6e 67 74 68 3a 20 37 38 38 0d ent-Length: 788.
0040 0a 44 61 74 65 3a 20 54 68 75 2c 20 31 31 20 4a .Date: Thu, 11 J
0050 75 6e 20 32 30 30 39 20 31 34 3a 30 35 3a 35 37 un 2009 14:05:57
0060 20 47 4d 54 0d 0a 0d 0a 72 01 00 4d 74 00 32 63 GMT....r..Mt.2c
<anonymize>
0370 4e 44 49 56 49 44 55 41 4c 7a 7a 7a NDIVIDUALzzz
No. Time Source Destination Protocol Info
4558 3009.837207 127.0.0.1 127.0.0.1 TCP 39801
> 9000 [ACK] Seq=53458 Ack=52739 Win=49536 Len=0 TSV=372932890 TSER=372932880
Frame 4558 (66 bytes on wire, 66 bytes captured)
Ethernet II, Src: 00:00:00:00:00:00 (00:00:00:00:00:00), Dst: 00:00:00:00:00:00
(00:00:00:00:00:00)
Internet Protocol, Src: 127.0.0.1 (127.0.0.1), Dst: 127.0.0.1 (127.0.0.1)
Transmission Control Protocol, Src Port: 39801 (39801), Dst Port: 9000 (9000),
Seq: 53458, Ack: 52739, Len: 0
No. Time Source Destination Protocol Info
4559 3010.129548 127.0.0.1 127.0.0.1 TCP 9000 >
39801 [FIN, ACK] Seq=52739 Ack=53458 Win=49536 Len=0 TSV=372932963
TSER=372932890
Frame 4559 (66 bytes on wire, 66 bytes captured)
Ethernet II, Src: 00:00:00:00:00:00 (00:00:00:00:00:00), Dst: 00:00:00:00:00:00
(00:00:00:00:00:00)
Internet Protocol, Src: 127.0.0.1 (127.0.0.1), Dst: 127.0.0.1 (127.0.0.1)
Transmission Control Protocol, Src Port: 9000 (9000), Dst Port: 39801 (39801),
Seq: 52739, Ack: 53458, Len: 0
No. Time Source Destination Protocol Info
4560 3010.169203 127.0.0.1 127.0.0.1 TCP 39801
> 9000 [ACK] Seq=53458 Ack=52740 Win=49536 Len=0 TSV=372932973 TSER=372932963
Frame 4560 (66 bytes on wire, 66 bytes captured)
Ethernet II, Src: 00:00:00:00:00:00 (00:00:00:00:00:00), Dst: 00:00:00:00:00:00
(00:00:00:00:00:00)
Internet Protocol, Src: 127.0.0.1 (127.0.0.1), Dst: 127.0.0.1 (127.0.0.1)
Transmission Control Protocol, Src Port: 39801 (39801), Dst Port: 9000 (9000),
Seq: 53458, Ack: 52740, Len: 0
No. Time Source Destination Protocol Info
4561 3013.081197 127.0.0.1 127.0.0.1 TCP 39801
> 9000 [PSH, ACK] Seq=53458 Ack=52740 Win=49536 [TCP CHECKSUM INCORRECT]
Len=293 TSV=372933701 TSER=372932963
Frame 4561 (359 bytes on wire, 359 bytes captured)
Ethernet II, Src: 00:00:00:00:00:00 (00:00:00:00:00:00), Dst: 00:00:00:00:00:00
(00:00:00:00:00:00)
Internet Protocol, Src: 127.0.0.1 (127.0.0.1), Dst: 127.0.0.1 (127.0.0.1)
Transmission Control Protocol, Src Port: 39801 (39801), Dst Port: 9000 (9000),
Seq: 53458, Ack: 52740, Len: 293
Data (293 bytes)
0000 50 4f 53 54 20 2f 74 6e 63 6f 2f 63 6f 6d 2e 73 POST /tnco/com.s
<anonymize>
00e0 2e 32 2c 20 2a 2f 2a 3b 20 71 3d 2e 32 0d 0a 43 .2, */*; q=.2..C
00f0 6f 6e 6e 65 63 74 69 6f 6e 3a 20 6b 65 65 70 2d onnection: keep-
0100 61 6c 69 76 65 0d 0a 54 72 61 6e 73 66 65 72 2d alive..Transfer-
0110 45 6e 63 6f 64 69 6e 67 3a 20 63 68 75 6e 6b 65 Encoding: chunke
0120 64 0d 0a 0d 0a d....
No. Time Source Destination Protocol Info
4562 3013.084306 127.0.0.1 127.0.0.1 TCP 9000 >
39801 [RST] Seq=52740 Win=0 Len=0
Frame 4562 (54 bytes on wire, 54 bytes captured)
Ethernet II, Src: 00:00:00:00:00:00 (00:00:00:00:00:00), Dst: 00:00:00:00:00:00
(00:00:00:00:00:00)
Internet Protocol, Src: 127.0.0.1 (127.0.0.1), Dst: 127.0.0.1 (127.0.0.1)
Transmission Control Protocol, Src Port: 9000 (9000), Dst Port: 39801 (39801),
Seq: 52740, Len: 0
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org
