Quarkus Resteasy endpoint returning 500 to client after HEAD request because of Logbook NullPointerException

[fenix-hub]

I'm writing a webservice using Logbook to log requests and responses in a Quarkus application.
I'm using Resteasy implementation for the RESTful endpoints.
Exposing an @HEAD endpoint causes Logbook to throw a NullPointerException right after logging the response.
Even though the request is sucessfully handled, whatever the response code is (be it 200 or 404) the exception causes the client to not receive the webservice response, instead 500 is received.

Description

By my understanding, Logbook uses TeeStream to overcome the request/response stream to be emptied on requests and responses.
This is default behavior at least; however this should not be always done, because of some requests type not supporting (or not expecting) a response body to be returned by standard.
An HEAD request is one of these.

Expected Behavior

Logbook should just log request/response flow without trying to catch bodies in HEAD requests, eventually directly inspecting the body itself or just checking if the Content-Type header is present (it isn't for HEAD requests).

Actual Behavior

Logbook logs request/response correctly, but a NullPointerException is thrown and causes any client to receive 500 instead of the actual response.

Stacktrace

2022-12-07 10:53:01,001 TRACE [org.zal.log.Logbook] (executor-thread-0) {"origin":"local","type":"response","correlation":"c0f740b400ab062d","duration":566,"protocol":"HTTP/1.1","status":204}
2022-12-07 10:53:01,012 DEBUG [io.ver.ext.web.RoutingContext] (executor-thread-0) RoutingContext failure (500): java.lang.NullPointerException
        at org.zalando.logbook.jaxrs.TeeOutputStream.close(TeeOutputStream.java:39)
        at io.quarkus.resteasy.runtime.standalone.VertxHttpResponse.finish(VertxHttpResponse.java:145)
        at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:166)
        at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler$1.run(VertxRequestHandler.java:93)
        at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:576)
        at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2449)
        at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1478)
        at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
        at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        at java.base/java.lang.Thread.run(Thread.java:834)

Possible Fix

Don't look for a response body for HEAD requests.
Instead of directly targeting the request method, the body logging could be skipped because of missing the Content-Type header or if the response is just null.

Steps to Reproduce

1. Create a simple Quarkus project, including logbook and resteasy-reactive dependencies
2. Write a Resource implementing an HEAD endpoint

	@HEAD
	@Path("/handler/{handler}")
	public Response checkUserByHandler(@PathParam("handler") String handler) throws CustomException;

4. Make the endpoint implementation return any Response code
5. Make a request to that endpoint

Your Environment

Version used:

• logbook: 2.14.0
• quarkus: 2.14.1

[whiskeysierra]

I'm constantly surprised that developers use null instead of more obvious, better choices - like a constant, immutable, empty input stream in this case.

The proper fix, imho, would be to catch the null case in

logbook/logbook-jaxrs/src/main/java/org/zalando/logbook/jaxrs/LocalResponse.java

Line 59 in 9aaf58e

final TeeOutputStream stream = new TeeOutputStream(context.getEntityStream());

[fenix-hub]

From the specs

The HEAD method is identical to GET except that the server MUST NOT send content in the response.

Guess this is most of the time interpreted by a language-specific null instead of an empty response.
Thank you for contributing by the way.

[whiskeysierra]

Yeah, but implementation wise an empty stream bytes is a perfectly reasonable way to represent an empty response.

For reference: https://refactoring.guru/introduce-null-object

[fenix-hub]

Thank you for the resource.
Sadly even returning manually a non-empty response

return Response.ok(new Object()).build();

will anyway throw an excpection, so I guess it is something happening with Resteasy-Quarkus.

[fenix-hub]

Hello,
Is there any update on this?

[msdousti]

Hi @fenix-hub

I tried to reproduce the issue (using newer versions of Logbook and Quarkus).

Here's the project:
https://github.com/msdousti/quarkus-logbook

Please see the README.md file, where it showcases a HEAD request resulting in 200 OK, and Logbook logging the request.

As such, I'm closing the issue as not-reproducible.

Please feel free to re-open it with a link to a GitHub repository that reproduces the issue. (In doing so, please use the updated version of Logbook and Quarkus).

[fenix-hub]

@msdousti Thank you very much for your example project and for answering this issue,
although I would not really consider this closed and not-reproducible.

Though it works with newer verisons of Logbook and (especially) Quarkus,
Quarkus 2 is still used (which is the version that was used at the time the issue was opened), and since it is not unsupported officially, or considered non-compatible with Logbook version, the issue still is present and should be addressed in my opinion.
Updating to Quarkus 3 to resolve this kind of issue is not much of a resolution in this case.

Would this also work with Quarkus 2 (non reactive)?

[msdousti]

@fenix-hub

You're welcome!

I'm not super familiar with Quarkus; you can try creating a toy project with Quarkus 2.x (say Quarkus 2.16.2.Final, which is the latest 2.x at the moment) + latest version of Logbook (3.6.0). The setup can be reactive or classic.

If it fails with 500 error, please post the GitHub link here for me to investigate.

Please make sure the following is set up (I provided link to my toy project):

1. Dependency management and dependencies

2. Logbook filter

3. Logging level

[msdousti]

@fenix-hub

Here's a repo for exactly the same versions as you mentioned in the ticket:
https://github.com/msdousti/quarkus-logbook-2

[msdousti]

Addressed by #1909