logback-access-spring-boot-starter icon indicating copy to clipboard operation
logback-access-spring-boot-starter copied to clipboard

Options for working around LOGBACK-1526 in 3.x version of this lib

Open grimsa opened this issue 3 years ago • 1 comments

Question

The original problem

logback-access has a feature that helps avoid polluting access logs with binary file content. This works OK for response bodies with image/* content type. However, this does not work for:

  • Request bodies (e.g. image, PDF, ZIP, etc.)
  • Response bodies of any non-image content type (e.g. PDF or ZIP)

This has been reported as https://jira.qos.ch/browse/LOGBACK-1526, but there has been no action for over a year.

The workaround

In our Java project that uses 2.7.1 version of this lib, we have implemented a workaround for this in a copy of TomcatLogbackAccessEvent. The changes were minimal - you can see them in this comment.

The current problem

As the 3.x version of this lib was rewritten to Kotlin, our classloading hack naturally no longer works.

On one hand, the original problem is a Logback issue that has nothing to do with this lib, but on the other, it seems LogbackAccessTomcatEventSource.kt does not extend ch.qos.logback.access.spi.AccessEvent, so even if they fixed the issue, changes would have to be made in this lib? (I'm not fluent in Kotlin - might be misreading the code)

What options do we have?

  1. Remain on 2.x version of this lib and hope LOGBACK-1526 gets resolved
  2. Attempt to fix it in this lib - would something similar to the workaround we had be accepted here?
  3. Any other options?

grimsa avatar Dec 19 '21 18:12 grimsa

Thank you for the report! I think LOGBACK-1526 is difficult to work around with version 3 in Java. I would like to provide an extension point to resolve the LOGBACK-1526 in a future version.

akkinoc avatar Dec 23 '21 08:12 akkinoc

@akkinoc We have kept using version 2 of this lib for now, but with upgrade to Spring Boot 3 and Jakarta EE APIs we're at the point where we either need to find a solution for this issue, or move away from logback-access entirely.

I think I see one low-effort hack that might save us.

(Assuming it is possible to add a Java class in a Kotlin project) Add a class like this in your library:

package dev.akkinoc.spring.boot.logback.access.tomcat;

import org.apache.catalina.connector.Request;
import org.apache.catalina.connector.Response;

/**
 * This is a hacky workaround for https://github.com/akkinoc/logback-access-spring-boot-starter/issues/98.
 * A user who wants to modify this logic should copy this class and modify it, and make sure the modified class has a higher classloader priority.
 */
class HackyLoggingOverrides {
    /**
     * Returning {@code null} means no override.
     * Returning non-null value will result in that value being logged instead of request body.
     */
    static String overriddenRequestBody(Request request) {
        // By default, no override is used
        return null;
    }

    /**
     * Returning {@code null} means no override.
     * Returning non-null value will result in that value being logged instead of response body.
     */
    static String overriddenResponseBody(Request request, Response response) {
        // By default, no override is used
        return null;
    }
}

and then in https://github.com/akkinoc/logback-access-spring-boot-starter/blob/main/src/main/kotlin/dev/akkinoc/spring/boot/logback/access/tomcat/LogbackAccessTomcatEventSource.kt#L130-L159 add logic like this (sorry for syntax, I don't use Kotlin):

    override val requestContent: String? by lazy(LazyThreadSafetyMode.NONE) {
        // ---- this is the new code enabling the override
        String requestBodyOverride = HackyLoggingOverrides.overriddenRequestBody(request);
        if (requestBodyOverride != null) return requestBodyOverride;
        //  ---- old code below
        val bytes = request.getAttribute(LB_INPUT_BUFFER) as ByteArray?
        if (bytes == null && isFormUrlEncoded(request)) {
            return@lazy requestParameterMap.asSequence()
                .flatMap { (key, values) -> values.asSequence().map { key to it } }
                .map { (key, value) -> encode(key, UTF_8.name()) to encode(value, UTF_8.name()) }
                .joinToString("&") { (key, value) -> "$key=$value" }
        }
        bytes?.let { String(it, UTF_8) }
    }

    // ...

    override val responseContent: String? by lazy(LazyThreadSafetyMode.NONE) {
        //  ---- this is the new code enabling the override
        String responseBodyOverride = HackyLoggingOverrides.overriddenResponseBody(request, response);
        if (responseBodyOverride != null) return responseBodyOverride;
        //  ---- old code below
        if (isImageResponse(response)) return@lazy "[IMAGE CONTENTS SUPPRESSED]"
        val bytes = request.getAttribute(LB_OUTPUT_BUFFER) as ByteArray?
        bytes?.let { String(it, UTF_8) }
    }

This way:

  1. Regular users would likely not abuse it, because HackyLoggingOverrides class is package-private (so not part of the "official" API)
  2. For us it would make it possible to customize the lib with little effort - we'd only need to copy-paste this HackyLoggingOverrides class into our microservice project (leaving package and class name exactly the same), implement the logic we need to suppress some responses, and then Spring would pick up our implementation instead of the one provided in this library, effectively allowing us to change the logic we need to change.
  3. The interim fix is simple to do and would not introduce a lot of technical debt

What do you think?

grimsa avatar Dec 14 '23 20:12 grimsa

@grimsa Thanks for your suggestion! Sorry for the delay. I've released #379 in v4.1.1, so please give it a try when you can!

akkinoc avatar Dec 27 '23 10:12 akkinoc

@akkinoc I tested 4.1.1 - it works 🎉 Thank you!

In our Java project I added the following class (sharing here so that others could use it as a template):

package dev.akkinoc.spring.boot.logback.access;

import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.springframework.http.HttpStatus;

/**
 * This is a classloading hack.
 * <p>
 * We are loading a modified version of {@code LogbackAccessHackyLoggingOverrides} as a workaround for missing logback-access feature to suppress
 * logging of some response bodies.
 * <p>
 * The class was copied from 4.1.1 version of {@code logback-access-spring-boot-starter} lib and then modified.
 *
 * @see <a href="https://github.com/akkinoc/logback-access-spring-boot-starter/issues/98">Issue which enabled this workaround</a>
 * @see <a href="https://jira.qos.ch/browse/LOGBACK-1526">LOGBACK-1526</a>
 */
@SuppressWarnings("unused")
public final class LogbackAccessHackyLoggingOverrides {
    private LogbackAccessHackyLoggingOverrides() {
    }

    public static String overriddenRequestBody(HttpServletRequest request) {
        return null;
    }

    public static String overriddenResponseBody(HttpServletRequest request, HttpServletResponse response) {
        boolean shouldSuppressResponseBodyLogging = "/endpoint-that-returns-a-binary-document".equals(request.getServletPath())
                && response.getStatus() == HttpStatus.OK.value();
        return shouldSuppressResponseBodyLogging
                ? "[CONTENTS SUPPRESSED]"
                : null;
    }
}

grimsa avatar Dec 27 '23 13:12 grimsa

Thanks for trying and sharing! 🎉

akkinoc avatar Dec 28 '23 01:12 akkinoc