Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Intermittent NPE in OutputStream.close with GzipHandler #12022

Closed
mperktold opened this issue Jul 9, 2024 · 1 comment · Fixed by #12025
Closed

Intermittent NPE in OutputStream.close with GzipHandler #12022

mperktold opened this issue Jul 9, 2024 · 1 comment · Fixed by #12025
Labels
Bug For general bugs on Jetty side Outstanding Bug Report! The bug report was outstanding!

Comments

@mperktold
Copy link

Jetty version(s)
Jetty 12.0.10

Jetty Environment
core

Java version/vendor (use: java -version)
openjdk version "21.0.3" 2024-04-16 LTS
OpenJDK Runtime Environment Temurin-21.0.3+9 (build 21.0.3+9-LTS)
OpenJDK 64-Bit Server VM Temurin-21.0.3+9 (build 21.0.3+9-LTS, mixed mode, sharing)

OS type/version
Windows 11

Description
We are seeing intermittent NPEs of the following kind:

java.lang.NullPointerException: Cannot invoke "org.eclipse.jetty.util.compression.CompressionPool$Entry.get()" because "this.this$0._deflaterEntry" is null
    java.io.IOException: java.lang.NullPointerException: Cannot invoke "org.eclipse.jetty.util.compression.CompressionPool$Entry.get()" because "this.this$0._deflaterEntry" is null
        at org.eclipse.jetty.io.content.ContentSinkOutputStream.handleException(ContentSinkOutputStream.java:99)
        at org.eclipse.jetty.io.content.ContentSinkOutputStream.close(ContentSinkOutputStream.java:87)
        ... (our code that closes the output stream)

It happens when closing an OutputStream obtained by Content.Sink.asOutputStream(response) after writing to it (via javax.xml.transform.Transformer, in case that matters). This means that the deflater of the GZIP response is released before close() is called.

I am not sure why this happens. It could be that writing fails for some reason (I'still waiting for confirmation whether something like that is in the logs), and then close() could fail because of that.

How to reproduce?

The following snippet starts a server that fails in a similar way:

Server server = new Server(8080);
server.setHandler(new Handler.Wrapper(new GzipHandler(new Handler.Abstract() {
    @Override
    public boolean handle(Request request, Response response, Callback callback) throws Exception {
        try (var out = Content.Sink.asOutputStream(response)) {
            out.write("Hello, Jetty".getBytes(StandardCharsets.UTF_8));
        }
        return true;
    }
})) {
    @Override
    public boolean handle(Request request, Response response, Callback callback) throws Exception {
        return super.handle(request, new Response.Wrapper(request, response) {
            @Override
            public void write(boolean last, ByteBuffer byteBuffer, Callback callback) {
                throw new IllegalStateException("Test");
            }
        }, callback);
    }
});
server.start();
server.join();

It simply tries to respond with "Hello, Jetty" gzipped, but throws an exception whenever content is written to the response. When called, it fails with the following stack trace:

WARNUNG: writeError: status=500, message=java.lang.IllegalStateException: Test, response=ErrorResponse@53f4969b{500,GET@45b64e16 http://localhost:8080/ HTTP/1.1}
java.lang.IllegalStateException: Test
	at it.prodata.util.JettyTest$2$1.write(JettyTest.java:61)
	at org.eclipse.jetty.server.Response$Wrapper.write(Response.java:751)
	at org.eclipse.jetty.server.handler.gzip.GzipResponseAndCallback.access$001(GzipResponseAndCallback.java:40)
	at org.eclipse.jetty.server.handler.gzip.GzipResponseAndCallback$GzipBufferCB.write(GzipResponseAndCallback.java:490)
	at org.eclipse.jetty.server.handler.gzip.GzipResponseAndCallback$GzipBufferCB.compressing(GzipResponseAndCallback.java:433)
	at org.eclipse.jetty.server.handler.gzip.GzipResponseAndCallback$GzipBufferCB.process(GzipResponseAndCallback.java:374)
	at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:262)
	at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:243)
	at org.eclipse.jetty.server.handler.gzip.GzipResponseAndCallback.gzip(GzipResponseAndCallback.java:157)
	at org.eclipse.jetty.server.handler.gzip.GzipResponseAndCallback.commit(GzipResponseAndCallback.java:268)
	at org.eclipse.jetty.server.handler.gzip.GzipResponseAndCallback.write(GzipResponseAndCallback.java:132)
	at org.eclipse.jetty.io.content.ContentSinkOutputStream.write(ContentSinkOutputStream.java:54)
	at java.base/java.io.OutputStream.write(OutputStream.java:124)
	at it.prodata.util.JettyTest$1.handle(JettyTest.java:51)
	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:597)
	at org.eclipse.jetty.server.Handler$Wrapper.handle(Handler.java:740)
	at it.prodata.util.JettyTest$2.handle(JettyTest.java:58)
	at org.eclipse.jetty.server.Server.handle(Server.java:181)
	at org.eclipse.jetty.server.internal.HttpChannelState$HandlerInvoker.run(HttpChannelState.java:648)
	at org.eclipse.jetty.server.internal.HttpConnection.onFillable(HttpConnection.java:403)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:322)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:99)
	at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:979)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1209)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1164)
	at java.base/java.lang.Thread.run(Thread.java:1583)
	Suppressed: java.io.IOException: java.lang.NullPointerException: Cannot invoke "org.eclipse.jetty.util.compression.CompressionPool$Entry.get()" because "this.this$0._deflaterEntry" is null
		at org.eclipse.jetty.io.content.ContentSinkOutputStream.handleException(ContentSinkOutputStream.java:99)
		at org.eclipse.jetty.io.content.ContentSinkOutputStream.close(ContentSinkOutputStream.java:87)
		at it.prodata.util.JettyTest$1.handle(JettyTest.java:50)

So the same NPE is thrown, but here it is caught and added as suppressed to the original exception. This is better than what we see in production and not exactly the same behavior. But still, it shows one way to get the same NPE.

@mperktold mperktold added the Bug For general bugs on Jetty side label Jul 9, 2024
lorban added a commit that referenced this issue Jul 10, 2024
… by the wrapping's Response.write()

Signed-off-by: Ludovic Orban <lorban@bitronix.be>
@lorban lorban added the Outstanding Bug Report! The bug report was outstanding! label Jul 10, 2024
@lorban
Copy link
Contributor

lorban commented Jul 10, 2024

Good catch!

Thanks for the report, and the exceptionally useful reproducer!

lorban added a commit that referenced this issue Jul 16, 2024
… by the wrapping's Response.write()

Signed-off-by: Ludovic Orban <lorban@bitronix.be>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Bug For general bugs on Jetty side Outstanding Bug Report! The bug report was outstanding!
Projects
None yet
2 participants