CONNECT 4.3 - org.apache.commons.httpclient.SimpleHttpConnectionManager|_ThreadID=371;_ThreadName=Thread-2;|SimpleHttpConnectionManager being used incorrectly....

classic Classic list List threaded Threaded
2 messages Options
Reply | Threaded
Open this post in threaded view
|

CONNECT 4.3 - org.apache.commons.httpclient.SimpleHttpConnectionManager|_ThreadID=371;_ThreadName=Thread-2;|SimpleHttpConnectionManager being used incorrectly....

johnhd
We have a production instance of CONNECT 4.3 which is going down every few days. It just came to my desk so I haven't had much chance to determine if it's running out of memory, connections, or what... But I strongly suspect that it's running out of HTTP threads based on what I'm seeing here around the point of failure:

[#|2016-01-14T09:04:44.853-0700|WARNING|glassfish3.1.2|org.apache.commons.httpclient.SimpleHttpConnectionManager|_ThreadID=371;_ThreadName=Thread-2;|SimpleHttpConnectionManager being used incorrectly.  Be sure that HttpMethod.releaseConnection() is always called and that only one thread and/or method is using this connection manager at a time.|#]

Followed by a spam of:

[#|2016-01-14T09:04:41.119-0700|WARNING|glassfish3.1.2|org.apache.cxf.phase.PhaseInterceptorChain|_ThreadID=307;_ThreadName=Thread-2;|Interceptor for {urn:gov:hhs:fha:nhinc:adaptermpi}AdapterMpiSecuredService#{urn:gov:hhs:fha:nhinc:adaptermpi}FindCandidates has thrown exception, unwinding now
org.apache.cxf.interceptor.Fault: Could not send Message.
	at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:64)
	at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:271)
	at org.apache.cxf.interceptor.OutgoingChainInterceptor.handleMessage(OutgoingChainInterceptor.java:77)
	at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:271)
	at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121)
	at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:239)
	at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:218)
	at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:198)
	at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:137)
	at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:158)
	at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:243)
	at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPost(AbstractHTTPServlet.java:163)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)
	at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:219)
	at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1550)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:281)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
	at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:655)
	at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:595)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:161)
	at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:331)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:231)
	at com.sun.enterprise.v3.services.impl.ContainerMapper$AdapterCallable.call(ContainerMapper.java:317)
	at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:195)
	at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:860)
	at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:757)
	at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:1056)
	at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:229)
	at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:137)
	at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:104)
	at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:90)
	at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:79)
	at com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:54)
	at com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:59)
	at com.sun.grizzly.ContextTask.run(ContextTask.java:71)
	at com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:532)
	at com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:513)
	at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.catalina.connector.ClientAbortException: java.io.IOException: Broken pipe
	at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:384)
	at org.apache.catalina.connector.OutputBuffer.flush(OutputBuffer.java:353)
	at org.apache.catalina.connector.Response.flushBuffer(Response.java:643)
	at org.apache.catalina.connector.ResponseFacade.flushBuffer(ResponseFacade.java:328)
	at org.apache.cxf.transport.http.AbstractHTTPDestination$WrappedOutputStream.close(AbstractHTTPDestination.java:727)
	at org.apache.cxf.io.CacheAndWriteOutputStream.postClose(CacheAndWriteOutputStream.java:50)
	at org.apache.cxf.io.CachedOutputStream.close(CachedOutputStream.java:229)
	at org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56)
	at org.apache.cxf.transport.http.AbstractHTTPDestination$BackChannelConduit.close(AbstractHTTPDestination.java:656)
	at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:62)
	... 37 more
Caused by: java.io.IOException: Broken pipe
	at sun.nio.ch.FileDispatcherImpl.write0(Native Method)
	at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47)
	at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93)
	at sun.nio.ch.IOUtil.write(IOUtil.java:65)
	at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:487)
	at com.sun.grizzly.util.OutputWriter.flushChannel(OutputWriter.java:108)
	at com.sun.grizzly.util.OutputWriter.flushChannel(OutputWriter.java:76)
	at com.sun.grizzly.util.SSLOutputWriter.flushChannel(SSLOutputWriter.java:102)
	at com.sun.grizzly.ssl.SSLOutputBuffer.flushChannel(SSLOutputBuffer.java:138)
	at com.sun.grizzly.http.SocketChannelOutputBuffer.flushBuffer(SocketChannelOutputBuffer.java:498)
	at com.sun.grizzly.http.SocketChannelOutputBuffer.flush(SocketChannelOutputBuffer.java:476)
	at com.sun.grizzly.http.ProcessorTask.action(ProcessorTask.java:1287)
	at com.sun.grizzly.ssl.SSLProcessorTask.action(SSLProcessorTask.java:164)
	at com.sun.grizzly.tcp.Response.action(Response.java:268)
	at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:380)
	... 46 more

A restart of CONNECT reliably gets us running again.

Has anyone had experience with this particular error?

Early research seems to be some HTTP handling not being thread safe.

Semi-educated guess: I suspect one of this client's partners is requesting a ton of connections at the same time and causing some kind of race condition?

I haven't found mention of this issue on Google or in these forums yet.... I also wanted to point out that we haven't encountered in on CONNECT 4.4.1 which the bulk of our population is running, so maybe that helps narrow in on the issue... I may start sourcecode delving.
Reply | Threaded
Open this post in threaded view
|

Re: CONNECT 4.3 - org.apache.commons.httpclient.SimpleHttpConnectionManager|_ThreadID=371;_ThreadName=Thread-2;|SimpleHttpConnectionManager being used incorrectly....

christophermay07
Hey John,

    This is the first time I've seen this issue.  I haven't had a chance to dig through the source code, but I don't believe any changes were made regarding thread safety between 4.3.0 and 4.4.1.  The most immediate thing that jumps to my attention is, we removed several unnecessary (and possibly conflicting) transitive dependencies as part of 4.4.0.  Here is a list of jars that were removed from the CONNECT GF (w/o Direct) EAR (I've bolded the ones I consider most suspicious for this issue):

agent-1.5.3
apache-jsieve-0.4
apache-jsieve-mailet-0.4
apache-mailet-2.4
apache-mailet-base-1.1
apache-mime4j-0.6
axis-1.4
bcmail-jdk15-140
bcprov-jdk15-1.45
commons-discovery-0.4
commons-fileupload-1.2
concurrent-1.0
config-service-client-1.1
direct-common-1.1.1
DirectCore-4.3.0
DirectWebservices-4.0.6
dnsjava-2.0.8
dsn-1.4.3
enunciate-core-annotations-1.23
gateway-2.0.2
geronimo-javamail_1.4_spec-1.7.1
geronimo-jaxws_2.2_spec-1.1
geronimo-jms_1.1_spec-1.1.1
geronimo-servlet_3.0_spec-1.0

guice-2.0
jackson-core-asl-1.7.5
jackson-jaxrs-1.7.5
jackson-mapper-asl-1.7.5
jaxrpc-api-1.1
jcs-1.3
jdom-1.1
jsr250-api-1.0
jsr311-api-1.1.1

mail-1.4.4
saaj-api-1.3
servlet-api-2.5
xd-common-1.2-CONNECT

    Also, cglib-nodep-2.1_3 was upgraded to cglib-nodep-2.2 between releases.

    If you have any other information that could help us troubleshoot or reproduce this issue, let us know.

Regards,
Chris