1

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.

JoshDM
  • 4,939
  • 7
  • 43
  • 72
  • 1
    Its hard to diagnose a problem without a way to replicate the issue. Is it possible to produce a Minimal reproducible example? https://stackoverflow.com/help/minimal-reproducible-example Alternatively I might suggest debugging the server and trying to figure out why null is set. – Deadron Jul 23 '20 at 00:04
  • That is, indeed, the problem. From a functional standpoint, it's not possible for that method to return a null. This is something that I believe to be server and/or proprietary JVM specific. However, I am wondering if, by reviewing the code (all of which is from their respective third-party JARs) something might stand out as suspect. Or, perhaps, someone with experience in Liberty might recognize the issue. – JoshDM Jul 23 '20 at 00:20
  • @Deadron - since this now definitely appears to be JVM-specific, it's impossible to produce a MRE as requested. – JoshDM Jul 23 '20 at 14:30
  • Just run your example in the JVM in question? You can produce a minimal war file based test suite to execute on liberty. While its easy to blame the JVM this should really be the last thing you blame. So far its much more likely that either you have a classloader issue or there is some scenario in the http components that is non obvious. Nothing in the http components class looks like it guarantees a non null result from getURI. – Deadron Jul 23 '20 at 17:20
  • @Deadron - if the uri variable entering the class constructor is non-null (and logging verifies it is non-null), and no subsequent cast to `HttpRequestBase` and call to `setURI(null)` is made, then the `uri` variable stored should be non-null. – JoshDM Jul 24 '20 at 15:29
  • @Deaadron - Disabling shared class caching, disabling AOT compilation and disabling JIT compilation on Liberty seems to have resolved the issue. So it was definitely something with the Liberty configuration itself, if not the JVM directly. It's very easy to blame the code, too. – JoshDM Jul 24 '20 at 17:04
  • 1
    https://blog.codinghorror.com/the-first-rule-of-programming-its-always-your-fault/ – Deadron Jul 25 '20 at 20:46
  • @Deadron, certainly, however by the time I got to the point where I needed to post this question to SO, I knew the issue was either somewhere in the third party code that I just was not seeing (it wasn't) or with the application server (it was). – JoshDM Jul 27 '20 at 20:23
  • @Deadron - proof today. Turns out updating the IBM Java SDK used by Liberty to a newer IBM version solved it. IBM!!!! *shakes fist at cloud* – JoshDM Jul 30 '20 at 19:05

1 Answers1

0

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

JoshDM
  • 4,939
  • 7
  • 43
  • 72