Deadlock in Apache HTTP client for basic non-preemptive authentication

[jerseyrobot]

I wanna share my experience about an issue that I encountered. The scenario is the following:

1. jersey client 2. http client connection manager 3. apache connection provider 4. basic non-preemptive authentication

the problem was that in some cases the connection was not released like expected, like the log below shows

2015-02-25 19:26:06.488 DEBUG 13230 --- [nio-8181-exec-9] h.i.c.PoolingHttpClientConnectionManager : Connection released: [id: 0][route: {}->http://localhost:8080][total kept alive: 1; route allocated: 1 of 10; total allocated: 1 of 10]

• Example that works in both cases, successful http code or not

rootTarget.queryParam("sort", sort + "," + dir)
    .queryParam("size" + Integer.MAX_VALUE)
    .request(MediaType.APPLICATION_JSON_TYPE).get(String.class);

• Example that works only if the request is unsuccessful

return rootTarget
    .request(MediaType.WILDCARD_TYPE)
    .post(Entity.entity(myobject, MediaType.APPLICATION_JSON_TYPE),
            MyCustomClass.class);

• Example that doesn't work at all

Response r = null;
try {
    r = idTarget.request(MediaType.WILDCARD_TYPE)
            .put(Entity.entity(myobject, MediaType.APPLICATION_JSON_TYPE));
    if (r.getStatusInfo().getStatusCode() != Status.NO_CONTENT
            .getStatusCode()) {
        throw new InternalServerErrorException(r.getStatusInfo()
                .getReasonPhrase());
    }
} finally {
    if (r != null) {
        try {
            r.close();
        } catch (Exception e) {
            e.printStackTrace();
        }
    }
}

This last example works only if I consume the response body like string. Response.close() doesn't work.

Instead If I change the authentication to preemptive mode everything works fine.

Best regards Mario Casola

Environment

Linux ubuntu 13.10, tomcat 7.0.57, jdk 1.7.0_71 64 bit

Affected Versions

[2.16]

[jerseyrobot]

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

[jerseyrobot]

@glassfishrobot Commented Reported by mario.casola

[jerseyrobot]

@glassfishrobot Commented @AdamLindenthal said: Hi Mario,

could you please share the code where you configure the client? Or, ideally provide a minimal reproducer testcase, e.g. buildable and runnable by maven?

Thanks a lot, Adam

[jerseyrobot]

@glassfishrobot Commented mario.casola said: Hi Adam,

at the following link you can download a maven project to test the issue

https://www.dropbox.com/s/dhgr4t5tt0j4g6q/jersey-non-preemptive-auth.zip?dl=0

Max connection per route 5

[WORKING]

$ mvn -DnonPreemptive=false -DconsumeString=true -Dexception=true test $ mvn -DnonPreemptive=false -DconsumeString=false -Dexception=true test

2015-03-12 00:02:06.890 DEBUG 8504 --- [           main] h.i.c.PoolingHttpClientConnectionManager : Connection released: [id: 5][route: {}->http://localhost:8080][total kept alive: 0; route allocated: 0 of 5; total allocated: 0 of 10]

$ mvn -DnonPreemptive=false -DconsumeString=false -Dexception=false test $ mvn -DnonPreemptive=false -DconsumeString=true -Dexception=false test

2015-03-12 00:03:05.015 DEBUG 8582 --- [           main] o.a.http.impl.execchain.MainClientExec   : Connection can be kept alive indefinitely
2015-03-12 00:03:05.016 DEBUG 8582 --- [           main] h.i.c.PoolingHttpClientConnectionManager : Connection [id: 0][route: {}->http://localhost:8080] can be kept alive indefinitely 2015-03-12 00:03:05.017 DEBUG 8582 --- [           main] h.i.c.PoolingHttpClientConnectionManager : Connection released: [id: 0][route: {}->http://localhost:8080][total kept alive: 1; route allocated: 1 of 5; total allocated: 1 of 10]

[NOT WORKING]

$ mvn -DnonPreemptive=true -DconsumeString=true -Dexception=true test $ mvn -DnonPreemptive=true -DconsumeString=false -Dexception=true test $ mvn -DnonPreemptive=true -DconsumeString=true -Dexception=false test $ mvn -DnonPreemptive=true -DconsumeString=false -Dexception=false test

blocked

2015-03-11 23:42:39.717 DEBUG 7710 --- [           main] h.i.c.PoolingHttpClientConnectionManager : Connection request: [route: {}->http://localhost:8080][total kept alive: 0; route allocated: 5 of 5; total allocated: 5 of 10]

At the end doesn't seems to be a question between consuming String or a custom Object. Another aspect is if you remove the response body on http return code that is not SUCCESSFUL. In that case even with non preemptive authentication it works.

I hope this helps

regards Mario

[jerseyrobot]

@glassfishrobot Commented @AdamLindenthal said: Thanks, Mario. I've attached your example to the issue. We will look at it and decide if someone knows what's wrong or if we plan some work on for future sprints.

Adam

[jerseyrobot]

@glassfishrobot Commented @japod said: There does not seem to be an issue with client.close(). Try to place the following to the beginning of your test method:

Executors.newFixedThreadPool(1).submit(new Runnable(){

@Override
public void run() {
    try {
        Thread.sleep(10000);
    } catch (InterruptedException e) {
        e.printStackTrace();
    }
    restClient.close();
}
            })

In the original test case, the restClient.close() was never invoked!

[jerseyrobot]

@glassfishrobot Commented @japod said:

at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at org.apache.http.pool.PoolEntryFuture.await(PoolEntryFuture.java:133)
    at org.apache.http.pool.AbstractConnPool.getPoolEntryBlocking(AbstractConnPool.java:282)
    at org.apache.http.pool.AbstractConnPool.access$000(AbstractConnPool.java:64)
    at org.apache.http.pool.AbstractConnPool$2.getPoolEntry(AbstractConnPool.java:177)
    at org.apache.http.pool.AbstractConnPool$2.getPoolEntry(AbstractConnPool.java:170)
    at org.apache.http.pool.PoolEntryFuture.get(PoolEntryFuture.java:102)
    at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.leaseConnection(PoolingHttpClientConnectionManager.java:244)
    at org.apache.http.impl.conn.PoolingHttpClientConnectionManager$1.get(PoolingHttpClientConnectionManager.java:231)
    at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:173)
    at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:195)
    at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:86)
    at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:108)
    at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
    at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:72)
    at org.glassfish.jersey.apache.connector.ApacheConnector.apply(ApacheConnector.java:455)
    at org.glassfish.jersey.client.ClientRuntime.invoke(ClientRuntime.java:246)
    at org.glassfish.jersey.client.JerseyInvocation$1.call(JerseyInvocation.java:667)
    at org.glassfish.jersey.client.JerseyInvocation$1.call(JerseyInvocation.java:664)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:315)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:297)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:228)
    at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:444)
    at org.glassfish.jersey.client.JerseyInvocation.invoke(JerseyInvocation.java:664)
    at org.glassfish.jersey.client.authentication.HttpAuthenticationFilter.repeatRequest(HttpAuthenticationFilter.java:334)
    at org.glassfish.jersey.client.authentication.BasicAuthenticator.filterResponseAndAuthenticate(BasicAuthenticator.java:125)
    at org.glassfish.jersey.client.authentication.HttpAuthenticationFilter.filter(HttpAuthenticationFilter.java:250)
    at org.glassfish.jersey.client.ClientFilteringStages$ResponseFilterStage.apply(ClientFilteringStages.java:134)
    at org.glassfish.jersey.client.ClientFilteringStages$ResponseFilterStage.apply(ClientFilteringStages.java:123)
    at org.glassfish.jersey.process.internal.Stages.process(Stages.java:171)
    at org.glassfish.jersey.client.ClientRuntime.invoke(ClientRuntime.java:251)
    at org.glassfish.jersey.client.JerseyInvocation$2.call(JerseyInvocation.java:683)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:315)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:297)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:228)
    at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:444)
    at org.glassfish.jersey.client.JerseyInvocation.invoke(JerseyInvocation.java:679)
    at org.glassfish.jersey.client.JerseyInvocation$Builder.method(JerseyInvocation.java:408)
    at org.glassfish.jersey.client.JerseyInvocation$Builder.get(JerseyInvocation.java:308)
    at jersey.test.JerseyClientTest.test(JerseyClientTest.java:96)

[jerseyrobot]

@glassfishrobot Commented @japod said: Updated bug title to describe the real issue. Added stack trace that captures where the deadlock happens.

Moved to backlog.

[jerseyrobot]

@glassfishrobot Commented mario.casola said: Hi Jakub,

good to know that you found the real issue. I didn't call the close method on restClient (javax.ws.rs.client.Client) object because in a real webapp I never call that method. On webapp shutdown spring call the close() method for me. The method consumeTarget.request(MediaType.APPLICATION_JSON_TYPE).get(cls) should read the entity and call the method close on Response object.

thanks Mario

[jerseyrobot]

@glassfishrobot Commented @japod said: Understood, it was not the client but the response which you wanted to close. Anyway, the deadlock prevents any close attempt, even if it is placed in a finally block. We need to address the deadlock first.

[jerseyrobot]

@glassfishrobot Commented File: jersey-non-preemptive-auth.zip Attached By: @AdamLindenthal

[jerseyrobot]

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

[jerseyrobot]

@atdi Commented The problem is appearing when the Response object is having an entity and you don't close the entity resource. I've manage to fix it in my code by calling response.close() when I'm not reading the resource.