Apache HttpClient 4.4 Proxy Basic Auth: Multiple auth attemps

Question

I'm trying to send requests with HTTP Client 4.4 through a proxy with Basic Auth. If I enter the right credentials, then the connection is successful.

But if I enter the wrong credentials, all the following other connection attempts will fails even with the right credentials.

It seems like once we have supplied the (wrong) credentials for the first time, the new (correct or wrong) credentials are never sent.

You will see there are two calls:

1st call, wrong proxy credentials
2nd call, correct proxy credentials

The code:

package test;

import org.apache.commons.codec.binary.Base64;
import org.apache.http.HttpHost;
import org.apache.http.HttpResponse;
import org.apache.http.auth.AuthScope;
import org.apache.http.auth.UsernamePasswordCredentials;
import org.apache.http.client.HttpClient;
import org.apache.http.client.methods.HttpGet;
import org.apache.http.client.methods.HttpUriRequest;
import org.apache.http.client.protocol.HttpClientContext;
import org.apache.http.impl.client.HttpClientBuilder;
import org.apache.http.impl.client.HttpClients;

public class Main {

    private HttpClient client;
    private HttpClientContext context = HttpClientContext.create();

    public static void main(String[] args) throws Exception {
        System.setProperty("org.apache.commons.logging.Log", "org.apache.commons.logging.impl.SimpleLog");
        System.setProperty("org.apache.commons.logging.simplelog.showdatetime", "true");
        System.setProperty("org.apache.commons.logging.simplelog.log.org.apache.http", "DEBUG");
        System.setProperty("org.apache.commons.logging.simplelog.log.org.apache.http.wire", "ERROR");

        Main main = new Main();
        main.createHttpClient();
        main.send(true, "test", "wrong"); // 1st call, wrong credentials, if this call is removed, it works !
        main.send(true, "test", "correct"); // 2nd call, correct credentials
    }

    public void send(String username, String password) throws Exception {
        proxyAuthenticate(username, password);

        HttpUriRequest request = new HttpGet("https://the-backend.xyz");
        HttpResponse httpResponse = client.execute(request, context);
        int statusCode = httpResponse.getStatusLine().getStatusCode();
        System.out.println("######################### " + statusCode);
    }

    public void createHttpClient() throws Exception {
        HttpClientBuilder httpClientBuilder = HttpClients.custom();
        httpClientBuilder.setProxy(new HttpHost("proxy.the-proxy.xyz", 1234));
        client = httpClientBuilder.build();
    }

    private void proxyAuthenticate(String username, String password) {
        UsernamePasswordCredentials credentials = new UsernamePasswordCredentials(username, password);
        AuthScope scope = new AuthScope("proxy.the-proxy.xyz", 1234);

        CredentialsProvider provider = new BasicCredentialsProvider();
        provider.setCredentials(scope, credentials);

        context.setCredentialsProvider(provider);
    }

}

The logs for 1st attempt (connect with wrong proxy cred: two http requests one without the creds, one with the creds, both returns 407, looks logical):

2015/10/07 13:39:02:502 CEST [WARN] BasicAuthCache - Unexpected I/O error while serializing auth scheme java.io.NotSerializableException: test.Main at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1183) at java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1547) at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1508) at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1431) at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1177) at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:347) at org.apache.http.impl.client.BasicAuthCache.put(BasicAuthCache.java:107) at test.Main.proxyAuthenticate(Main.java:109) at test.Main.send(Main.java:56) at test.Main2.main(Main2.java:30)

2015/10/07 13:39:02:502 CEST [DEBUG] RequestAddCookies - CookieSpec selected: default 2015/10/07 13:39:02:502 CEST [DEBUG] PoolingHttpClientConnectionManager - Connection request: [route: {tls}->http://proxy.the-proxy.xyz:1234->https://the-backend.xyz:443][total kept alive: 0; route allocated: 0 of 3; total allocated: 0 of 3] 2015/10/07 13:39:02:502 CEST [DEBUG] PoolingHttpClientConnectionManager - Connection leased: [id: 1][route: {tls}->http://proxy.the-proxy.xyz:1234->https://the-backend.xyz:443][total kept alive: 0; route allocated: 1 of 3; total allocated: 1 of 3] 2015/10/07 13:39:02:502 CEST [DEBUG] MainClientExec - Opening connection {tls}->http://proxy.the-proxy.xyz:1234->https://the-backend.xyz:443 2015/10/07 13:39:02:502 CEST [DEBUG] DefaultHttpClientConnectionOperator - Connecting to proxy.the-proxy.xyz/123.45.67.890:1234 2015/10/07 13:39:07:530 CEST [DEBUG] DefaultHttpClientConnectionOperator - Connection established 321.54.76.098:58216<->123.45.67.890:1234 2015/10/07 13:39:07:530 CEST [DEBUG] headers - http-outgoing-1 >> CONNECT the-backend.xyz:443 HTTP/1.1 2015/10/07 13:39:07:530 CEST [DEBUG] headers - http-outgoing-1 >> Host: the-backend.xyz 2015/10/07 13:39:07:530 CEST [DEBUG] headers - http-outgoing-1 >> User-Agent: Apache-HttpClient/4.4.1 (Java/1.7.0_51) 2015/10/07 13:39:07:530 CEST [DEBUG] headers - http-outgoing-1 << HTTP/1.1 407 Proxy Authentication Required 2015/10/07 13:39:07:530 CEST [DEBUG] headers - http-outgoing-1 << Proxy-Authenticate: BASIC realm="InternetAccess" 2015/10/07 13:39:07:530 CEST [DEBUG] headers - http-outgoing-1 << Cache-Control: no-cache 2015/10/07 13:39:07:530 CEST [DEBUG] headers - http-outgoing-1 << Pragma: no-cache 2015/10/07 13:39:07:530 CEST [DEBUG] headers - http-outgoing-1 << Content-Type: text/html; charset=utf-8 2015/10/07 13:39:07:530 CEST [DEBUG] headers - http-outgoing-1 << Proxy-Connection: close 2015/10/07 13:39:07:530 CEST [DEBUG] headers - http-outgoing-1 << Connection: close 2015/10/07 13:39:07:530 CEST [DEBUG] headers - http-outgoing-1 << Content-Length: 2916 2015/10/07 13:39:07:530 CEST [DEBUG] HttpAuthenticator - Authentication required 2015/10/07 13:39:07:530 CEST [DEBUG] HttpAuthenticator - proxy.the-proxy.xyz:1234 requested authentication 2015/10/07 13:39:07:530 CEST [DEBUG] ProxyAuthenticationStrategy - Authentication schemes in the order of preference: [Negotiate, Kerberos, NTLM, Digest, Basic] 2015/10/07 13:39:07:530 CEST [DEBUG] ProxyAuthenticationStrategy - Challenge for Negotiate authentication scheme not available 2015/10/07 13:39:07:530 CEST [DEBUG] ProxyAuthenticationStrategy - Challenge for Kerberos authentication scheme not available 2015/10/07 13:39:07:530 CEST [DEBUG] ProxyAuthenticationStrategy - Challenge for NTLM authentication scheme not available 2015/10/07 13:39:07:530 CEST [DEBUG] ProxyAuthenticationStrategy - Challenge for Digest authentication scheme not available 2015/10/07 13:39:07:530 CEST [DEBUG] HttpAuthenticator - Selected authentication options: [BASIC [complete=true]] 2015/10/07 13:39:07:530 CEST [DEBUG] DefaultManagedHttpClientConnection - http-outgoing-1: Close connection 2015/10/07 13:39:07:530 CEST [DEBUG] DefaultHttpClientConnectionOperator - Connecting to proxy.the-proxy.xyz/123.45.67.890:1234 2015/10/07 13:39:12:560 CEST [DEBUG] DefaultHttpClientConnectionOperator - Connection established 321.54.76.098:58217<->123.45.67.890:1234 2015/10/07 13:39:12:560 CEST [DEBUG] HttpAuthenticator - Generating response to an authentication challenge using basic scheme 2015/10/07 13:39:12:560 CEST [DEBUG] headers - http-outgoing-1 >> CONNECT the-backend.xyz:443 HTTP/1.1 2015/10/07 13:39:12:560 CEST [DEBUG] headers - http-outgoing-1 >> Host: the-backend.xyz 2015/10/07 13:39:12:560 CEST [DEBUG] headers - http-outgoing-1 >> User-Agent: Apache-HttpClient/4.4.1 (Java/1.7.0_51) 2015/10/07 13:39:12:560 CEST [DEBUG] headers - http-outgoing-1 >> Proxy-Authorization: Basic xXXxxXxXXXXX 2015/10/07 13:39:12:561 CEST [DEBUG] headers - http-outgoing-1 << HTTP/1.1 407 Proxy Authentication Required 2015/10/07 13:39:12:561 CEST [DEBUG] headers - http-outgoing-1 << Proxy-Authenticate: BASIC realm="InternetAccess" 2015/10/07 13:39:12:561 CEST [DEBUG] headers - http-outgoing-1 << Cache-Control: no-cache 2015/10/07 13:39:12:561 CEST [DEBUG] headers - http-outgoing-1 << Pragma: no-cache 2015/10/07 13:39:12:561 CEST [DEBUG] headers - http-outgoing-1 << Content-Type: text/html; charset=utf-8 2015/10/07 13:39:12:561 CEST [DEBUG] headers - http-outgoing-1 << Proxy-Connection: close 2015/10/07 13:39:12:561 CEST [DEBUG] headers - http-outgoing-1 << Connection: close 2015/10/07 13:39:12:561 CEST [DEBUG] headers - http-outgoing-1 << Content-Length: 2966 2015/10/07 13:39:12:561 CEST [DEBUG] HttpAuthenticator - Authentication required 2015/10/07 13:39:12:561 CEST [DEBUG] HttpAuthenticator - proxy.the-proxy.xyz:1234 requested authentication 2015/10/07 13:39:12:561 CEST [DEBUG] HttpAuthenticator - Authorization challenge processed 2015/10/07 13:39:12:561 CEST [DEBUG] HttpAuthenticator - Authentication failed 2015/10/07 13:39:12:561 CEST [DEBUG] ProxyAuthenticationStrategy - Clearing cached auth scheme for http://proxy.the-proxy.xyz:1234 2015/10/07 13:39:12:561 CEST [DEBUG] DefaultManagedHttpClientConnection - http-outgoing-1: Close connection 2015/10/07 13:39:12:561 CEST [DEBUG] MainClientExec - CONNECT refused by proxy: HTTP/1.1 407 Proxy Authentication Required 2015/10/07 13:39:12:561 CEST [DEBUG] DefaultManagedHttpClientConnection - http-outgoing-1: Close connection 2015/10/07 13:39:12:561 CEST [DEBUG] MainClientExec - Connection discarded 2015/10/07 13:39:12:561 CEST [DEBUG] DefaultManagedHttpClientConnection - http-outgoing-1: Close connection 2015/10/07 13:39:12:561 CEST [DEBUG] PoolingHttpClientConnectionManager - Connection released: [id: 1][route: {tls}->http://proxy.the-proxy.xyz:1234->https://the-backend.xyz:443][total kept alive: 0; route allocated: 0 of 3; total allocated: 0 of 3]
################### 407

The logs for 2nd attempt (connect with correct proxy cred: only one http request, why isn't there a second request with the correct creds ???):

2015/10/07 13:39:17:585 CEST [WARN] BasicAuthCache - Unexpected I/O error while serializing auth scheme java.io.NotSerializableException: test.Main at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1183) at java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1547) at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1508) at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1431) at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1177) at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:347) at org.apache.http.impl.client.BasicAuthCache.put(BasicAuthCache.java:107) at test.Main.proxyAuthenticate(Main.java:109) at test.Main.send(Main.java:56) at test.Main2.main(Main2.java:32)

2015/10/07 13:39:17:585 CEST [DEBUG] RequestAddCookies - CookieSpec selected: default 2015/10/07 13:39:17:585 CEST [DEBUG] PoolingHttpClientConnectionManager - Connection request: [route: {tls}->http://proxy.the-proxy.xyz:1234->https://the-backend.xyz:443][total kept alive: 0; route allocated: 0 of 3; total allocated: 0 of 3] 2015/10/07 13:39:17:585 CEST [DEBUG] PoolingHttpClientConnectionManager - Connection leased: [id: 2][route: {tls}->http://proxy.the-proxy.xyz:1234->https://the-backend.xyz:443][total kept alive: 0; route allocated: 1 of 3; total allocated: 1 of 3] 2015/10/07 13:39:17:585 CEST [DEBUG] MainClientExec - Opening connection {tls}->http://proxy.the-proxy.xyz:1234->https://the-backend.xyz:443 2015/10/07 13:39:17:585 CEST [DEBUG] DefaultHttpClientConnectionOperator - Connecting to proxy.the-proxy.xyz/123.45.67.890:1234 2015/10/07 13:39:17:585 CEST [DEBUG] DefaultHttpClientConnectionOperator - Connection established 321.54.76.098:58218<->123.45.67.890:1234 2015/10/07 13:39:17:586 CEST [DEBUG] headers - http-outgoing-2 >> CONNECT the-backend.xyz:443 HTTP/1.1 2015/10/07 13:39:17:586 CEST [DEBUG] headers - http-outgoing-2 >> Host: the-backend.xyz 2015/10/07 13:39:17:586 CEST [DEBUG] headers - http-outgoing-2 >> User-Agent: Apache-HttpClient/4.4.1 (Java/1.7.0_51) 2015/10/07 13:39:17:586 CEST [DEBUG] headers - http-outgoing-2 << HTTP/1.1 407 Proxy Authentication Required 2015/10/07 13:39:17:586 CEST [DEBUG] headers - http-outgoing-2 << Proxy-Authenticate: BASIC realm="InternetAccess" 2015/10/07 13:39:17:586 CEST [DEBUG] headers - http-outgoing-2 << Cache-Control: no-cache 2015/10/07 13:39:17:586 CEST [DEBUG] headers - http-outgoing-2 << Pragma: no-cache 2015/10/07 13:39:17:586 CEST [DEBUG] headers - http-outgoing-2 << Content-Type: text/html; charset=utf-8 2015/10/07 13:39:17:586 CEST [DEBUG] headers - http-outgoing-2 << Proxy-Connection: close 2015/10/07 13:39:17:586 CEST [DEBUG] headers - http-outgoing-2 << Connection: close 2015/10/07 13:39:17:586 CEST [DEBUG] headers - http-outgoing-2 << Content-Length: 2916 2015/10/07 13:39:17:586 CEST [DEBUG] HttpAuthenticator - Authentication required 2015/10/07 13:39:17:586 CEST [DEBUG] HttpAuthenticator - proxy.the-proxy.xyz:1234 requested authentication 2015/10/07 13:39:17:586 CEST [DEBUG] DefaultManagedHttpClientConnection - http-outgoing-2: Close connection 2015/10/07 13:39:17:586 CEST [DEBUG] MainClientExec - CONNECT refused by proxy: HTTP/1.1 407 Proxy Authentication Required 2015/10/07 13:39:17:586 CEST [DEBUG] DefaultManagedHttpClientConnection - http-outgoing-2: Close connection 2015/10/07 13:39:17:586 CEST [DEBUG] MainClientExec - Connection discarded 2015/10/07 13:39:17:586 CEST [DEBUG] DefaultManagedHttpClientConnection - http-outgoing-2: Close connection 2015/10/07 13:39:17:586 CEST [DEBUG] PoolingHttpClientConnectionManager - Connection released: [id: 2][route: {tls}->http://proxy.the-proxy.xyz:1234->https://the-backend.xyz:443][total kept alive: 0; route allocated: 0 of 3; total allocated: 0 of 3]
################### 407

Any idea why on the 2nd attempt, it tries without the auth (normal), the server replies that Basic auth is required, then instead of trying with the correct credentials, it closes the connection.

Thanks !

UPDATE:

If I change the HttpClient (from 4.4) to DefaultHttpClient (from 4.3) and adapt these two methods, it works. Note that the getCredentialsProvider is called from the client in 4.3 and from context in 4.4 !!!

First time I receive a 407 status code but second time I receive 200 which is what I expect.

public void createHttpClient() throws Exception {
    client = new DefaultHttpClient();
    HttpHost proxy = new HttpHost("proxy.eurocontrol.be", 9513);
    ConnRouteParams.setDefaultProxy(client.getParams(), proxy);
}

private void proxyAuthenticate(String username, String password) {
    UsernamePasswordCredentials credentials = new UsernamePasswordCredentials(username, password);
    AuthScope scope = new AuthScope("proxy.eurocontrol.be", 9513);
    client.getCredentialsProvider().setCredentials(scope, credentials);
    // Called from client !!!!!!!!!!!!!!!!!
}

Ekansh Rastogi Ekansh Rastogi · Accepted Answer · 2015-10-07T13:18:47

The first lines of the codes clearly tells that both the requests were made.

First at  - 2015/10/07 13:39:02:502

Second at - 2015/10/07 13:39:17:585

What you are printing is the status code of the server response, see this and Http Status 407

Even your logs clearly say

Unexpected I/O error while serializing auth scheme java.io.NotSerializableException

There can be an exception due to serialization also.

Apache HttpClient 4.4 Proxy Basic Auth: Multiple auth attemps

1 Answers