Why is HttpUriRequest.getURI() returning null when the uri variable is not null?

1k views Asked by At

SUMMARY

I am encountering a unique scenario where a call to an instance of httpcomponents HttpUriRequest method getURI() is returning null, when the variable in the instance is not null. It is impossible in this scenario for HttpUriRequest.getURI() to return a null, yet that is what is happening.

CODE WALKTHROUGH

This is the code walkthrough. It demonstrates how the HttpUriRequest.getURI() method cannot possibly return a null, yet it is returning null.

The relevant libraries used are

  • com.sun.jersey.contribs:jersey-apache-client4:jar:1.19.4
  • org.apache.httpcomponents:httpclient:jar:4.5.12

Our in-house application calls third-party code that uses jersey-apache-client4 to make RESTful calls to an external system via apache httpcomponents httpclient.

For the purposes of this question, requests begin at the call to ApacheHttpClient4Handler.handle(ClientRequest), source below.

  • Numbered in-line comments will guide the walk-through.

Relevant source for class ApacheHttpClient4Handler v1.19.4

    package com.sun.jersey.client.apache4;
    
    // ... irrelevant code removed

    public final class ApacheHttpClient4Handler extends TerminatingClientHandler {

        private final HttpClient client;
        private final boolean preemptiveBasicAuth;

        // ... irrelevant code removed

        public ClientResponse handle(final ClientRequest cr) throws ClientHandlerException {

            // {1} this is where the HttpUriRequest instance is created.  
            // See source walkthrough of getUriHttpRequest(ClientRequest) below.
            final HttpUriRequest request = getUriHttpRequest(cr);

            // {8} - calling request.getURI() here returns not null, and logging produces the expected "https://{serverpath}" on toString()

            writeOutBoundHeaders(cr.getHeaders(), request);

            // {11} - calling request.getURI() here returns not null, and logging produces the expected "https://{serverpath}" on toString()

            try {
                HttpResponse response;

                if(preemptiveBasicAuth) {

                    // this code block is never entered as preemptiveBasicAuth is always false for the scenario
                    // ... irrelevant code removed

                } else {

                    // {12} - calling request.getURI() here returns not null, and logging produces the expected "https://{serverpath}" on toString()

                    // the following line throws the unexpected NullPointerException originating from the call to getHost(request).
                    // See source walkthrough of getHost(HttpUriRequest) below.
                    response = getHttpClient().execute(getHost(request), request);
                }

                // from here to the catch is never reached due to the NPE two lines above.
                ClientResponse r = new ClientResponse(response.getStatusLine().getStatusCode(),
                        getInBoundHeaders(response),
                        new HttpClientResponseInputStream(response),
                        getMessageBodyWorkers());
                        
                if (!r.hasEntity()) {

                    r.bufferEntity();
                    r.close();
                }

                return r;

            } catch (Exception e) {

                // {15} - NPE is caught here and rethrown.
                throw new ClientHandlerException(e);
            }

        }

        // ... irrelevant code removed

        // this is the method where the unexpected NPE is thrown.
        private HttpHost getHost(final HttpUriRequest request) {

            // {13} - calling request.getURI() here returns null.  
            // It is not possible for this to be happening.

            // {14} - since getURI() returns null, a NPE will be thrown because .getHost() can't be called on a null return.
            // WHY IS getURI() returning null ???!!!???
            return new HttpHost(request.getURI().getHost(), request.getURI().getPort(), request.getURI().getScheme());
        }

        // {2} - this is called by handle(ClientRequest)
        private HttpUriRequest getUriHttpRequest(final ClientRequest cr) {

            final String strMethod = cr.getMethod();
            final URI uri = cr.getURI();

            // {3} - uri is not null, and logging produces the expected "https://{serverpath}" on toString()

            final Boolean bufferingEnabled = isBufferingEnabled(cr);
            final HttpEntity entity = getHttpEntity(cr, bufferingEnabled);
            final HttpUriRequest request;

            // {4} - uri is not null, and logging produces the expected "https://{serverpath}" on toString()

            // even odds for a HttpGet, HttpPost, HttpPut, HttpDelete; HttpHead and HttpOptions do not get referenced by this scenario.
            // it does not matter which class the request is, the uri will end up being null.
            if (strMethod.equals("GET")) {
                request = new HttpGet(uri);
            } else if (strMethod.equals("POST")) {
                request = new HttpPost(uri);
            } else if (strMethod.equals("PUT")) {
                request = new HttpPut(uri);
            } else if (strMethod.equals("DELETE")) {
                request = new HttpDelete(uri);
            } else if (strMethod.equals("HEAD")) {
                request = new HttpHead(uri);
            } else if (strMethod.equals("OPTIONS")) {
                request = new HttpOptions(uri);
            } else {

                // this block of code is never hit by the requests for this scenario.
                request = new HttpEntityEnclosingRequestBase() {
                    @Override
                    public String getMethod() {
                        return strMethod;
                    }

                    @Override
                    public URI getURI() {
                        return uri;
                    }
                };
            }

            // {5} - checking uri shows it is not null, and logging produces the expected "https://{serverpath}" on toString()
            // calling request.getURI() here returns not null, and logging produces the expected "https://{serverpath}" on toString()

            // {6} - sometimes this is called, sometimes it is not; regardless, the error scenario still happens
            if(entity != null && request instanceof HttpEntityEnclosingRequestBase) {
                ((HttpEntityEnclosingRequestBase) request).setEntity(entity);
            } else if (entity != null) {
                throw new ClientHandlerException("Adding entity to http method " + cr.getMethod() + " is not supported.");
            }

            // ... irrelevant code removed

            // {7} - calling request.getURI() here returns not null, and logging produces the expected "https://{serverpath}" on toString()

            return request;
        }

        // ... irrelevant code removed

        private void writeOutBoundHeaders(final MultivaluedMap<String, Object> headers, final HttpUriRequest request) {

            // {9} - none of this code is relevant; it does not change the value of the uri
            for (Map.Entry<String, List<Object>> e : headers.entrySet()) {
                List<Object> vs = e.getValue();
                if (vs.size() == 1) {
                    request.addHeader(e.getKey(), ClientRequest.getHeaderValue(vs.get(0)));
                } else {
                    StringBuilder b = new StringBuilder();
                    for (Object v : e.getValue()) {
                        if (b.length() > 0) {
                            b.append(',');
                        }
                        b.append(ClientRequest.getHeaderValue(v));
                    }
                    request.addHeader(e.getKey(), b.toString());
                }
            }

            // {10} - calling request.getURI() here returns not null, and logging produces the expected "https://{serverpath}" on toString()
        }

        // ... irrelevant code removed
    }

Relevant source for interface HttpUriRequest v4.5.12

    package org.apache.http.client.methods;

    import java.net.URI;

    import org.apache.http.HttpRequest;

    public interface HttpUriRequest extends HttpRequest {

        // ... irrelevant code removed

        URI getURI();

        // ... irrelevant code removed
    }

Relevant source for abstract class HttpRequestBase v4.5.12 (HttpGet, HttpPost, etc. extend this)

    package org.apache.http.client.methods;

    import java.net.URI;

        // ... irrelevant code removed

    public abstract class HttpRequestBase extends AbstractExecutionAwareRequest
        implements HttpUriRequest, Configurable {

        // ... irrelevant code removed

        private URI uri;

        // ... irrelevant code removed

        @Override
        public URI getURI() {
            return this.uri;
        }

        // ... irrelevant code removed

        public void setURI(final URI uri) {
            this.uri = uri;
        }
    }

Relevant source for class HttpGet v4.5.12 (HttpPost, etc. are implemented similarly)

    package org.apache.http.client.methods;

    import java.net.URI;

    public class HttpGet extends HttpRequestBase {

        public final static String METHOD_NAME = "GET";

        public HttpGet() {
            super();
        }

        public HttpGet(final URI uri) {
            super();
            setURI(uri);
        }

        /**
         * @throws IllegalArgumentException if the uri is invalid.
         */
        public HttpGet(final String uri) {
            super();
            setURI(URI.create(uri));
        }

        @Override
        public String getMethod() {
            return METHOD_NAME;
        }
    }

Given the source walkthrough and the supporting comments proving the viability of the state of the Object instance, how is it possible the call to request.getURI() is returning null?

ENVIRONMENT

  • This code runs under IBM Liberty on Linux servers (JVM 8.0-5.40).
  • This code also runs under Wildfly on Windows servers (JVM 1.7).
  • The code is identical on both system types.
  • The code never has the above stated problem on the Windows servers.
  • The code does not have the above stated problem on Liberty servers where the Liberty management administration console is installed.

OBSERVATIONS

  • The first 2-3 pass-throughs of ApacheHttpClient4Hander.handle(ClientRequest) succeed without request.getURI() returning null; it is only on the 4th and subsequent requests that it returns null.

INVESTIGATION

Here are some investigation steps I have taken so far:

1 - I created this case on SO for group-mind insight.

2 - I opened a case with IBM.

3 - Customize ApacheHttpClient4Handler

  • I add debug logging to all methods via SL4J.

RESULT

  • the log output proves the call to HttpUriRequest.getURI() only starts returning null after entering ApacheHttpClient4Handler.getHost(final HttpUriRequest request).
  • any call immediately before getHost(HttpUriRequest) shows getURI() to return not-null.
  • after adding the debug logging, instead of after the 2-3 and subsequent requests (per OBSERVATIONS), HttpUriRequest.getURI() now returns null after the 1-2 (and subsequent) requests. I suspect this is due to debug logging proactively calling HttpUriRequest.getURI(), but I cannot confirm this and do not know why the scenario is now shorter.

4 - Customize ApacheHttpClient4Handler further

  • change all references of HttpUriRequest to HttpRequestBase

RESULT

  • doing this did not solve the problem; getURI() still returns null.

5 - Customize HttpRequestBase

  • add debug logging to getURI() / setURI(...) methods

RESULT

  • Application started working as designed, except with lots of debug logging!!!
  • see section MAJOR UPDATE below.

6 - Customize HttpGet, HttpPut, etc.

  • add debug logging to constructors.

RESULT

  • see section MAJOR UPDATE below.

7 - Update IBM JVM from 8.0-5.40 to 8.0-6.11

  • List of NPE-related bugfixes from the IBM release notes
  • IJ17563 | NPE WHEN CALLING JAVA.LANG.STRING.INDEXOF API WITH A LARGE OFFSET
  • IJ19669 | NPE OCCURS WHEN READING AN EMPTY PKCS12 KEYSTORE USING JAVA 8
  • IJ20528 | NPE OR SEGFAULT FOR METHOD CALL TO OBJECT OF A PRIMITIVE WRAPPER TYPE
  • IJ23079 | UNEXPECTED NPE CAUSED BY AN INCORRECT JIT COMPILER OPTIMIZATION
  • TODO: results to be posted in update

CONCLUSION

What is going on here?

Is the IBM implementation of the JVM used by Liberty mistreating this code, or is there something else?

Based on the code, and the walkthrough, there is no way HttpUriRequest.getURI() should be returning null.

MAJOR UPDATE

Per Step 5 in INVESTIGATION, I customized httpclient with debug logging using source from the global distribution. After adding the JAR to my project, it started working. I rolled back my changes, rebuilt the JAR from unmodified source, added it to my project, and the application started working.

I redeployed again using the globally-distributed httpclient-4.5.12.jar My application failed.

Again, I did not make any changes to the code; I took the httpclient-4.5.12-sources.jar, compiled it in Eclipse and redeployed with my newly-named JAR, httpclient-4.5.12.joshdm.jar. And it works.

I decompiled both JARs using JAD to examine the code. There were minimal differences, only in labels, which means the compilers were different. I compared MANIFEST.MF for both JARs; the Build-Jdk entries were different. I compiled using Jdk 1.8.0_191. The global one was compiled using Jdk 1.8.0_181.

I have reported this strange discrepancy to IBM, provided both compiled JARs and the source JAR, and am waiting to hear back as to why mine works with their JVM and why the global one does not. I am now 99% certain this is an IBM JVM or server configuration issue, and has nothing to do with the deployed application.

UPDATE #2

Adding the following configuration and rolling back to the global JAR works (also works with the recompiled JAR).

-Xshareclasses:none - disables shared class caching and AOT compilation.

-Xnojit - disables JIT compilation

Disabling shared class caching, disabling AOT compilation and disabling JIT compilation on Liberty seems to have resolved the issue. I will write-up an actual answer once I hear back from IBM why the above settings were needed.

1

There are 1 answers

0
JoshDM On BEST ANSWER

IBM Liberty was running on version ibm-java-sdk-8.0-5.40

Updating it to ibm-java-sdk-8.0-6.11 solved it.

Bugfixes are found here

IBM responded, "several JIT issues {...} were fixed since Java 8 SR5 FP40 {...} {i}t is very likely that you did not hit the same code path in the working environment."

My guesses at the culprit: IJ20528, IJ23079