Logging of Incoming Requests and Outgoing Responses in REST Server Applications

[lmartella1]

Hello,

For incident investigations, we would like to enable detailed logging of all incoming REST server requests and outgoing client REST requests. Specifically, we need to log request and response headers, status codes, and (optionally truncated) bodies.

We noticed that the quarkus-rest-client extension provides this functionality out of the box via the quarkus.rest-client.logging.scope=request-response property.

On the other end, we don't find an equivalent configuration for quarkus-rest (server-side) that allows us to achieve the same level of logging as what is available for the REST client. Has this feature already been implemented or considered as a built-in functionality in the quarkus-rest extension?

Thank you in advance.

[gsmet]

Yeah I agree it would be a nice feature.

I remember needing it once.

/cc @geoand maybe if we add some pointers in an issue, it could be a good-first-issue?

[geoand]

Yeah, it makes sense

[geoand]

I'll take care of it soon

[geoand]

@cescoffier @vietj I am interested in hearing what the typical solution in Vert.x looks like for this use case. I can imagine a custom Route, or even co-opting HttpServerMetrics :)

[geoand]

My preference would be to have a general solution for logging HTTP request info, not just something specific to Quarkus REST

[geoand]

I assume that we'll need something akin to LoggerHandler, but that only handles request logging.

Moreover, I think this request is a good opportunity for Vert.x to provide some general and customizable solution that both users of the tookit and integrations like Quarkus can leverage.

[phillip-kruger]

You can also add a log tab in dev-ui with this. Like the HTTP Access log. A REST Tab that just log this.

[geoand]

I don't think we'll be able to log bodies in any case, but the headers we can certainly do

[geoand]

Right. We would like only print the bodies (if possible) if we can determine that the Content is actually a text type.

[lmartella1]

Based on your initial recommendation, @geoand, and as a temporary solution until this feature is officially released with RHBQ, we developed a POC for a class that implements this functionality.

Disclaimer: Logging request and response bodies is a requirement for us. We are not concerned about sensitive data exposure, as we have measures in place to conceal logs and obfuscate sensitive information before they get persisted.

There you can see some snippets of code:

@Slf4j
public class ServerLogInterceptor {

  /**
   * Logs incoming HTTP requests before they are processed by JAX-RS resources.
   * <p>
   * Captures request method, URI, headers, and body content. For requests with bodies, the body is read asynchronously
   * to avoid blocking the request processing.
   *
   * @param request
   *          the incoming HTTP request
   * @param requestContext
   *          the JAX-RS request context
   */
  @ServerRequestFilter(preMatching = true)
  public void logRequest(HttpServerRequest request, ContainerRequestContext requestContext) {
    if (!isLoggingEnabled()) {
      return;
    }

    String baseInfo = buildRequestBaseInfo(request);
    if (requestContext.hasEntity()) {
      request.body()
          .onSuccess(buffer -> logWithBody(baseInfo, buffer != null ? buffer.toString() : ""))
          .onFailure(cause -> log.warn("{}, Body read failed: {}", baseInfo, cause.getMessage()));
    } else {
      logWithoutBody(baseInfo);
    }
  }

  /**
   * Logs outgoing HTTP responses after they are processed by JAX-RS resources.
   * <p>
   * Captures response status, headers, and body content.
   *
   * @param request
   *          the original HTTP request
   * @param responseContext
   *          the JAX-RS response context
   */
  @ServerResponseFilter
  public void logResponse(HttpServerRequest request, ContainerResponseContext responseContext) {
    if (!isLoggingEnabled()) {
      return;
    }

    String baseInfo = buildResponseBaseInfo(request, responseContext);
    if (responseContext.hasEntity()) {
      Object entity = responseContext.getEntity();
      String body = entity != null ? entity.toString() : "";
      logWithBody(baseInfo, body);
    } else {
      logWithoutBody(baseInfo);
    }
  }
  
  private String buildRequestBaseInfo(HttpServerRequest request) {
    return String.format("Request: %s %s Headers[%s]",
        request.method(),
        request.absoluteURI(),
        formatHeaders(request.headers()));
  }

  private String buildResponseBaseInfo(HttpServerRequest request, ContainerResponseContext responseContext) {
    return String.format("Response: %s %s, Status[%d %s], Headers[%s]",
        request.method(),
        request.absoluteURI(),
        responseContext.getStatus(),
        responseContext.getStatusInfo().getReasonPhrase(),
        formatHeaders(responseContext.getHeaders()));
  }

  private void logWithBody(String baseInfo, String body) {
    log.info("{}, Body:\n{}", baseInfo, truncateBody(body));
  }

  private void logWithoutBody(String baseInfo) {
    log.info("{}, Empty body", baseInfo);
  }

It does not address the concern raised by @cescoffier regarding the masking of the Authorization header value - so that's definitively a gap - and, as done by the quarkus-rest-client implementation we are not really paying attention on the content-type. Aside from this, do you see any other potential issues with this type of implementation?

[geoand]

You would have to at least check how it behaves in the following response situations:

• A bodyless response
• A response with a text body
• A response with a binary body
• A multipart response that contains both of the above
• A streaming response

Also cases you would to check how it behaves when Security is in play. Same for OpenTelemetry, metrics and access logging.

All that to say that there is a very good chance that your code fits perfectly into your current environment, but if we are going to do something in Quarkus, it has to be more general and robust (and IMHO should applied on the Vert.x level as I mentioned in my previous comments).

[cescoffier]

Also, the same cases exist for requests: with and without body, multi-part requests, streamed requests...

For the response, also check SSE - I doubt it's working as expected.

[geoand]

also check SSE - I doubt it's working as expected

Depends on what the expectation is :). In Quarkus REST we made the conscious decision to not execute ResponseFilter when streaming back results.