eclipse-ee4j / jersey

Eclipse Jersey Project - Read our Wiki:
https://github.com/eclipse-ee4j/jersey/wiki
Other
689 stars 351 forks source link

jersey 2.40 + JAXB based XML -> HTTP Status 500 – Internal Server Error with no stacktrace #5361

Open minfrin opened 1 year ago

minfrin commented 1 year ago

When an existing application is upgraded[1] to jersey v2.40, and an attempt is made to hit a previously-working endpoint using an Accept header of application/json, we get a correct response back.

If we change the Accept header to application/xml, tomcat throws a 500 internal server error as follows:

<!doctype html><html lang="en"><head><title>HTTP Status 500 – Internal Server Error</title><style type="text/css">body {font-family:Tahoma,Arial,sans-serif;} h1, h2, h3, b {color:white;background-color:#525D76;} h1 {font-size:22px;} h2 {font-size:16px;} h3 {font-size:14px;} p {font-size:12px;} a {color:black;} .line {height:1px;background-color:#525D76;border:none;}</style></head><body><h1>HTTP Status 500 – Internal Server Error</h1><hr class="line" /><p><b>Type</b> Status Report</p><p><b>Message</b> Internal Server Error</p><p><b>Description</b> The server encountered an unexpected condition that prevented it from fulfilling the request.</p><hr class="line" /><h3>Apache Tomcat/9.0.65</h3></body></html>

The exception that triggered the 500 is not logged anywhere, and without the exception we're stuck.

The dependency tree looks like this:

[snip non jersey jars]
[INFO] |  +- org.glassfish.jersey.core:jersey-client:jar:2.40:compile
[INFO] |  +- org.glassfish.jersey.connectors:jersey-jetty-connector:jar:2.40:compile
[INFO] |  +- org.eclipse.jetty:jetty-client:jar:10.0.15:compile
[INFO] |  |  +- org.eclipse.jetty:jetty-http:jar:10.0.15:compile
[INFO] |  |  |  \- org.eclipse.jetty:jetty-util:jar:10.0.15:compile
[INFO] |  |  +- org.eclipse.jetty:jetty-io:jar:10.0.15:compile
[INFO] |  |  +- org.eclipse.jetty:jetty-alpn-client:jar:10.0.15:compile
[INFO] |  |  \- org.slf4j:slf4j-api:jar:2.0.5:compile
[INFO] |  +- com.kohlschutter.junixsocket:junixsocket-jetty:jar:2.6.2:compile
[INFO] |  |  \- com.kohlschutter.junixsocket:junixsocket-core:pom:2.6.2:compile
[INFO] |  |     +- com.kohlschutter.junixsocket:junixsocket-native-common:jar:2.6.2:compile
[INFO] |  |     \- com.kohlschutter.junixsocket:junixsocket-common:jar:2.6.2:compile
[INFO] |  +- org.bouncycastle:bcprov-jdk15on:jar:1.61:compile
[INFO] |  +- org.bouncycastle:bcmail-jdk15on:jar:1.61:compile
[INFO] |  |  \- org.bouncycastle:bcpkix-jdk15on:jar:1.61:compile
[INFO] |  +- javax.mail:mail:jar:1.4.7:compile
[INFO] |  |  \- javax.activation:activation:jar:1.1:compile
[INFO] |  \- javax.transaction:jta:jar:1.1:compile
[snip]
[INFO] |  +- javax.ws.rs:javax.ws.rs-api:jar:2.1.1:compile
[INFO] |  \- javax.xml.bind:jaxb-api:jar:2.3.1:compile
[INFO] |     \- javax.activation:javax.activation-api:jar:1.2.0:compile
[INFO] +- org.glassfish.jersey.containers:jersey-container-servlet:jar:2.40:compile
[INFO] |  +- org.glassfish.jersey.containers:jersey-container-servlet-core:jar:2.40:compile
[INFO] |  +- org.glassfish.jersey.core:jersey-common:jar:2.40:compile
[INFO] |  |  \- jakarta.annotation:jakarta.annotation-api:jar:1.3.5:compile
[INFO] |  +- org.glassfish.jersey.core:jersey-server:jar:2.40:compile
[INFO] |  |  \- jakarta.validation:jakarta.validation-api:jar:2.0.2:compile
[INFO] |  \- jakarta.ws.rs:jakarta.ws.rs-api:jar:2.1.6:compile
[INFO] +- org.glassfish.jersey.media:jersey-media-moxy:jar:2.40:compile
[INFO] |  +- org.glassfish.jersey.ext:jersey-entity-filtering:jar:2.40:compile
[INFO] |  +- jakarta.json:jakarta.json-api:jar:1.1.6:compile
[INFO] |  +- org.glassfish:jakarta.json:jar:1.1.6:compile
[INFO] |  +- org.eclipse.persistence:org.eclipse.persistence.moxy:jar:2.7.12:compile
[INFO] |  |  \- org.eclipse.persistence:org.eclipse.persistence.core:jar:2.7.12:compile
[INFO] |  |     \- org.eclipse.persistence:org.eclipse.persistence.asm:jar:9.4.0:compile
[INFO] |  \- jakarta.xml.bind:jakarta.xml.bind-api:jar:2.3.3:compile
[INFO] |     \- jakarta.activation:jakarta.activation-api:jar:1.2.2:compile
[INFO] +- org.glassfish.jersey.media:jersey-media-multipart:jar:2.40:compile
[INFO] |  \- org.jvnet.mimepull:mimepull:jar:1.9.15:compile
[INFO] +- org.glassfish.jersey.media:jersey-media-jaxb:jar:2.40:compile
[INFO] |  +- org.glassfish.hk2.external:jakarta.inject:jar:2.6.1:compile
[INFO] |  \- org.glassfish.hk2:osgi-resource-locator:jar:1.0.3:compile
[INFO] +- org.glassfish.jersey.inject:jersey-hk2:jar:2.40:compile
[INFO] |  +- org.glassfish.hk2:hk2-locator:jar:2.6.1:compile
[INFO] |  |  +- org.glassfish.hk2.external:aopalliance-repackaged:jar:2.6.1:compile
[INFO] |  |  +- org.glassfish.hk2:hk2-api:jar:2.6.1:compile
[INFO] |  |  \- org.glassfish.hk2:hk2-utils:jar:2.6.1:compile
[INFO] |  \- org.javassist:javassist:jar:3.29.2-GA:compile
[INFO] +- commons-configuration:commons-configuration:jar:1.10:compile
[INFO] |  +- commons-lang:commons-lang:jar:2.6:compile
[INFO] |  \- commons-logging:commons-logging:jar:1.1.1:compile
[INFO] +- javax.servlet:javax.servlet-api:jar:4.0.1:provided
[INFO] +- commons-codec:commons-codec:jar:1.16.0:compile
[INFO] \- junit:junit:jar:4.13.2:test
[INFO]    \- org.hamcrest:hamcrest-core:jar:1.3:test

I suspect we're providing the wrong jaxb implementation.

There seem to be two different jaxb interfaces, and it's not clear which is correct:

[INFO] | - javax.xml.bind:jaxb-api:jar:2.3.1:compile [INFO] | - jakarta.xml.bind:jakarta.xml.bind-api:jar:2.3.3:compile

If we had the exception, we could probably fix this.

[1] We're in dependency hell.

minfrin commented 1 year ago

Managed to catch this in a debugger.

While returning the JAXB response, we hit this line which NPEs because _me is null.

https://github.com/eclipse-ee4j/glassfish-hk2-extra/blob/master/osgi-resource-locator/src/main/java/org/glassfish/hk2/osgiresourcelocator/ServiceLoader.java#L108

Eventually this exception is silently swallowed by this code:

    static Object lookupUsingOSGiServiceLoader(String factoryId, Logger logger) {

        try {
            // Use reflection to avoid having any dependency on ServiceLoader class
            Class serviceClass = Class.forName(factoryId);
            Class target = Class.forName(OSGI_SERVICE_LOADER_CLASS_NAME);
            Method m = target.getMethod(OSGI_SERVICE_LOADER_METHOD_NAME, Class.class);
            Iterator iter = ((Iterable) m.invoke(null, serviceClass)).iterator();
            if (iter.hasNext()) {
                Object next = iter.next();
                logger.fine("Found implementation using OSGi facility; returning object [" +
                        next.getClass().getName() + "].");
                return next;
            } else {
                return null;
            }
        } catch (IllegalAccessException |
                InvocationTargetException |
                ClassNotFoundException |
                NoSuchMethodException ignored) {
[logged, but not visible in tomcat logging, so invisible]
            logger.log(Level.FINE, "Unable to find from OSGi: [" + factoryId + "]", ignored);
[exception dropped on the floor here]
            return null;
        }
    }

Now we end up here:

        Class ctxFactoryClass =
                (Class) ServiceLoaderUtil.lookupUsingOSGiServiceLoader("javax.xml.bind.JAXBContext", logger);

        if (ctxFactoryClass != null) {
            return newInstance(classes, properties, ctxFactoryClass);
        }

        // else no provider found
        logger.fine("Trying to create the platform default provider");
[we end up here, because everything is null]
        return newInstance(classes, properties, ModuleUtil.DEFAULT_FACTORY_CLASS);

Now we're in tomcat, here:

            if (clazz == null) {
                if (log.isDebugEnabled()) {
                    log.debug("    --> Returning ClassNotFoundException");
                }
[we complain that com.sun.xml.bind.v2.ContextFactory is not found]
                throw new ClassNotFoundException(name);
            }

Then we end up here in tomcat:

            try {
                clazz = findClass(name);
                if (clazz != null) {
                    if (log.isDebugEnabled()) {
                        log.debug("  Loading class from local repository");
                    }
                    if (resolve) {
                        resolveClass(clazz);
                    }
                    return clazz;
                }
            } catch (ClassNotFoundException e) {
[we're here, and the exception is ignored]
                // Ignore
            }

Now we're back in jersey-media-jaxb, and we reach here:

    @Override
    public final void writeTo(
            Object t,
            Class<?> type,
            Type genericType,
            Annotation[] annotations,
            MediaType mediaType,
            MultivaluedMap<String, Object> httpHeaders,
            OutputStream entityStream) throws IOException {
        try {
            final Marshaller m = getMarshaller(type, mediaType);
            final Charset c = getCharset(mediaType);
            if (c != UTF8) {
                m.setProperty(Marshaller.JAXB_ENCODING, c.name());
            }
            setHeader(m, annotations);
            writeTo(t, mediaType, c, m, entityStream);
        } catch (JAXBException ex) {
[we hit here]
            throw new InternalServerErrorException(ex);
        }
    }

The variable ex above is:

javax.xml.bind.JAXBException: Implementation of JAXB-API has not been found on module path or classpath.
 - with linked exception:
[java.lang.ClassNotFoundException: com.sun.xml.bind.v2.ContextFactory]

We eventually arrive here in jersey-server:

    @Override
    public void aroundWriteTo(final WriterInterceptorContext context) throws IOException, WebApplicationException {
        try {
            context.proceed();
        } catch (final WebApplicationException | MappableException e) {
[we're here]
            throw e;
        } catch (final MessageBodyProviderNotFoundException nfe) {
            throw new InternalServerErrorException(nfe);
        } catch (final Exception e) {
            throw new MappableException(e);
        }

    }

The contents of e above are:

javax.ws.rs.InternalServerErrorException: HTTP 500 Internal Server Error

At this point we're thrown away all the exceptions that brought us to this point, and we fail on 500 with no explanation and no logging.

minfrin commented 1 year ago

Found an explanation of the mess that JAXB is in at https://stackoverflow.com/questions/71095913/what-is-the-difference-between-jaxb-impl-and-jaxb-runtime