jersey icon indicating copy to clipboard operation
jersey copied to clipboard

ApacheConnector/PoolingHttpClientConnectionManager doesn't pool at all!

Open glassfishrobot opened this issue 9 years ago • 5 comments

Using the ApacheConnector results in no connection pooling at all!

TCP sockets are always forcedly closed and no keep-alive is possible.

Currently it's better to just use Sun's sun.net.www.protocol.http.HttpURLConnection in the JDK which actually keeps the connections alive and reuses sockets.

Stack trace is:

Thread [http-runner-3] (Suspended)	
	owns: CPoolProxy  (id=72)	
	LoggingManagedHttpClientConnection(BHttpConnectionBase).shutdown() line: 306	
	LoggingManagedHttpClientConnection(DefaultManagedHttpClientConnection).shutdown() line: 97	
	LoggingManagedHttpClientConnection.shutdown() line: 89	
	CPoolEntry.shutdownConnection() line: 74	
	CPoolProxy.shutdown() line: 96	
	ConnectionHolder.abortConnection() line: 127	
	HttpResponseProxy.close() line: 64	
	ApacheConnector$3.close() line: 643	
	ApacheConnector$HttpClientResponseInputStream(FilterInputStream).close() line: 181 [local variables unavailable]	
	ApacheConnector$HttpClientResponseInputStream.close() line: 621	
	InboundMessageContext$EntityContent(EntityInputStream).close() line: 158	
	InboundMessageContext$EntityContent.close(boolean) line: 156	
	ClientResponse(InboundMessageContext).close() line: 939	
	InboundJaxrsResponse.close() line: 167	
	ConnectionPoolingTest.lambda$0(CountDownLatch, int, WebTarget) line: 67	
	1934932165.run() line: not available	
	Thread.run() line: 745

as you can see in the call chain ApacheConnector$HttpClientResponseInputStream always forces a close of the connection!

I think this bug was introduced by #3124: ApacheConnector: ClientResponse does not close ClosableHttpResponse

which was introduced shortly after 2.22 git describe 0d1326dee69d9c693014184bea3e4a44b323daee 2.22-37-g0d1326d

Switching back to 2.22 fixes the problem for me, and the ApacheConnector nicely lets the connections keep alive and actually reuses the underlying socket!

jersey-apache-connector 2.22.2:

netstat -n -p tcp
  TCP    127.0.0.1:51578        127.0.0.1:8080         HERGESTELLT
  TCP    127.0.0.1:51579        127.0.0.1:8080         HERGESTELLT
  TCP    127.0.0.1:51580        127.0.0.1:8080         HERGESTELLT
  TCP    127.0.0.1:51581        127.0.0.1:8080         HERGESTELLT
  TCP    127.0.0.1:51582        127.0.0.1:8080         HERGESTELLT
netstat -n -p tcp
  TCP    127.0.0.1:51591        127.0.0.1:8080         HERGESTELLT
  TCP    127.0.0.1:51592        127.0.0.1:8080         HERGESTELLT
  TCP    127.0.0.1:51593        127.0.0.1:8080         HERGESTELLT
  TCP    127.0.0.1:51594        127.0.0.1:8080         HERGESTELLT
  TCP    127.0.0.1:51595        127.0.0.1:8080         HERGESTELLT

you see the source port increasing in a test client loop with 5 concurrent connections -> no connection reuse, no keep alive!

jersey-apache-connector 2.22:

netstat -n -p tcp
  TCP    127.0.0.1:51774        127.0.0.1:8080         HERGESTELLT
  TCP    127.0.0.1:51775        127.0.0.1:8080         HERGESTELLT
  TCP    127.0.0.1:51776        127.0.0.1:8080         HERGESTELLT
  TCP    127.0.0.1:51777        127.0.0.1:8080         HERGESTELLT
  TCP    127.0.0.1:51778        127.0.0.1:8080         HERGESTELLT
netstat -n -p tcp
  TCP    127.0.0.1:51774        127.0.0.1:8080         HERGESTELLT
  TCP    127.0.0.1:51775        127.0.0.1:8080         HERGESTELLT
  TCP    127.0.0.1:51776        127.0.0.1:8080         HERGESTELLT
  TCP    127.0.0.1:51777        127.0.0.1:8080         HERGESTELLT
  TCP    127.0.0.1:51778        127.0.0.1:8080         HERGESTELLT

-> as it should be: reuse a connection

enabling JDK Logger logging with a logging.properties file like this:

handlers = java.util.logging.ConsoleHandler
java.util.logging.ConsoleHandler.level = FINEST
org.apache.http.impl.conn.PoolingHttpClientConnectionManager.level = FINEST

will show in 2.22 values greater than 0 for "kept alive":

Mär 29, 2016 5:27:38 PM org.apache.http.impl.conn.PoolingHttpClientConnectionManager releaseConnection
FEIN: Connection released: [id: 51][route: {}->http://localhost:8080][total kept alive: 1; route allocated: 5 of 50; total allocated: 5 of 50]

Affected Versions

[2.22.2]

glassfishrobot avatar Mar 29 '16 15:03 glassfishrobot

Reported by thomasmey

glassfishrobot avatar Mar 29 '16 15:03 glassfishrobot

@pavelbucek said: Also, see the offending commit: https://github.com/jersey/jersey/commit/0d1326dee69d9c693014184bea3e4a44b323daee

There is a useful comment, which should help with the correct resolution.

glassfishrobot avatar Nov 02 '16 08:11 glassfishrobot

This issue was imported from java.net JIRA JERSEY-3086

glassfishrobot avatar Apr 25 '17 05:04 glassfishrobot

It sounds like the response.close(); is the problem:

https://github.com/jersey/jersey/commit/0d1326dee69d9c693014184bea3e4a44b323daee

+        return new FilterInputStream(inputStream) {
+            @Override
+            public void close() throws IOException {
+                response.close();
+                super.close();
+            }

However, that was introduced to fix "JERSEY-2852: ApacheConnector: ClientResponse does not close ClosableHttpResponse".

"There is a useful comment, which should help with the correct resolution."

Any reason to believe swapping the order of the two lines would allow for connection pooling?

+ super.close();
+ response.close();

To me, it sounds like that would only fix https://github.com/jersey/jersey/issues/3629

There's also this comment on https://github.com/jersey/jersey/issues/3124 :

aaronjwhiteside said: This PR causes connection pooling to break, when response.close()(0d1326d#diff-> 91ece5335d0cdc9321a099df1caec54fR643) is called this causes Apache HttpClient to not release the connection back to the pool but close it instead.

HttpClientResponseInputStream.close() -> CloseableHttpResponse.close() -> HttpResponseProxy.close() -> ConnectionHolder.close() -> ConnectionHolder.releaseConnection(false)….

releaseConnection(false) causes the underlying connection to be closed and not released back to the pool for reuse.

But it doesn't give any suggestion on what else we should do.

mricken avatar Apr 05 '18 17:04 mricken

http://hc.apache.org/httpcomponents-client-4.4.x/tutorial/html/fundamentals.html#d5e145

“In order to ensure proper release of system resources one must close either the content stream associated with the entity or the response itself … The difference between closing the content stream and closing the response is that the former [(closing the content stream)] will attempt to keep the underlying connection alive by consuming the entity content while the latter [(closing the response itself)] immediately shuts down and discards the connection.” (emphasis mine)

It sounds like closing the connection is not necessar, which makes it seem like 0d1326dee69d9c693014184bea3e4a44b323daee should just be reverted.

mricken avatar Apr 05 '18 17:04 mricken