ApacheConnector/PoolingHttpClientConnectionManager doesn't pool at all!

[jerseyrobot]

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 0d1326d
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]

[jerseyrobot]

@glassfishrobot Commented
Reported by thomasmey

[jerseyrobot]

@glassfishrobot Commented
@pavelbucek said:
Also, see the offending commit: jersey/jersey@0d1326d

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

[jerseyrobot]

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

[jerseyrobot]

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

jersey/jersey@0d1326d

+        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.

[jerseyrobot]

@mricken Commented
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 0d1326d should just be reverted.

[jerseyrobot]

• Issue Imported From: https://github.com/jersey/jersey/issues/3358
• Original Issue Raised By:@glassfishrobot
• Original Issue Assigned To: @PetrJanouch

[jansupol]

Fixed by #3861