Logging for HTTP servlet requests

[sleberknight]

Here's some half-baked (maybe not even half) experimental code derived from some actual code I found in one of our production services that does some very minimal request logging. Since we really just don't interact with the raw servlet API much at all, I'm not sure it's worth anything more than just as experimental, throwaway code anyway.

But here is is for posterity, in case we ever care about it.

package org.kiwiproject.beta.servlet;

import static java.util.Objects.isNull;
import static java.util.stream.Collectors.toList;

import com.google.common.annotations.Beta;
import lombok.experimental.UtilityClass;
import lombok.extern.slf4j.Slf4j;
import org.kiwiproject.beta.slf4j.KiwiSlf4j;
import org.slf4j.Logger;
import org.slf4j.event.Level;

import javax.servlet.http.HttpServletRequest;
import java.util.Collections;
import java.util.Enumeration;
import java.util.List;
import java.util.Optional;
import java.util.regex.Pattern;

// Maybe a better way would be to have a builder that lets you specify all the various things
// that you want logged, e.g. method, request URL, query string, etc. but also have several
// factory methods to create some "standard" sets of things to be logged. Then the log methods
// can accept this "configuration"

@UtilityClass
@Slf4j
@Beta
public class KiwiHttpServletRequests {

    private static final String LINE_SEPARATOR = System.lineSeparator();

    // Refs:
    // * https://sonarcloud.io/organizations/kiwiproject/rules?open=javasecurity%3AS5145&rule_key=javasecurity%3AS5145
    // * https://rules.sonarsource.com/java/RSPEC-5145
    private static final Pattern SANITIZER_PATTERN = Pattern.compile("[\n\r\t]");

    public static void traceLogRequestInfo(Logger logger, HttpServletRequest request) {
        logRequestInfo(logger, Level.TRACE, request);
    }

    public static void debugLogRequestInfo(Logger logger, HttpServletRequest request) {
        logRequestInfo(logger, Level.DEBUG, request);
    }

    public static void logRequestInfo(Logger logger, Level level, HttpServletRequest request) {
        var template = "Request:{} ; method: {}{} ; requestURL: {}{} ; queryString: {}{} ; attributeNames: {}{} ; headerNames: {}";
        
        if (KiwiSlf4j.isEnabled(logger, level)) {
            var sanitizedRequestURL = sanitized(request.getRequestURL());
            var sanitizedQueryString = Optional.ofNullable(request.getQueryString())
                    .map(KiwiHttpServletRequests::sanitized)
                    .orElse("");

            KiwiSlf4j.log(logger, level, template,
                    LINE_SEPARATOR,
                    request.getMethod(),
                    LINE_SEPARATOR,
                    sanitizedRequestURL,
                    LINE_SEPARATOR,
                    sanitizedQueryString,
                    LINE_SEPARATOR,
                    nullSafeEnumerationToSanitizedList(request.getAttributeNames()),
                    LINE_SEPARATOR,
                    nullSafeEnumerationToSanitizedList(request.getHeaderNames())
            );
        }
    }

    private static List<String> nullSafeEnumerationToSanitizedList(Enumeration<String> enumeration) {
        if (isNull(enumeration)) {
            return List.of();
        }

        return Collections.list(enumeration)
                .stream()
                .map(KiwiHttpServletRequests::sanitized)
                .collect(toList());
    }

    private static String sanitized(CharSequence original) {
        return SANITIZER_PATTERN.matcher(original).replaceAll("_");
    }
}

[sleberknight]

The sanitized method is a candidate for putting in KiwiStrings or equivalent, maybe with a new name like sanitizedForLogging. But maybe instead of going into a generic String utility class it should go into a logging-specific utility class. This new utility class would start with only this one method, and I can't really think of much else to put in there that is completely generic like this. KiwiSl4fj provides logging utilities specific to SLF4J so it doesn't make sense to put it there. Alas, having to decide where to put simple methods like this is annoying.

Possible class:

package org.kiwiproject.logging;

// imports

@UtilityClass
public class KiwiLogging {

    // Refs:
    // * https://sonarcloud.io/organizations/kiwiproject/rules?open=javasecurity%3AS5145&rule_key=javasecurity%3AS5145
    // * https://rules.sonarsource.com/java/RSPEC-5145
    private static final Pattern SANITIZER_PATTERN = Pattern.compile("[\n\r\t]");

    public static String sanitizeForLogging(CharSequence msg) {
        return SANITIZER_PATTERN.matcher(original).replaceAll("_");
    }
}

Note that the method is named as a verb phrase, e.g. "sanitize the input for logging", not in the past tense (as with sanitized).

Of course, just writing the above made me think of a whole lot of possibilities for this class, since you basically want to apply this to the arguments that are injected into a log message template, e.g.

LOG.info("The request URL was {}, sanitizeForLogging(requestURL));

Because you also want to then lazily call this in case the log level is not active, e.g.

LOG.info("The request URL was {}, lazy(() -> sanitizeForLogging(requestURL)));

And if you need to sanitize multiple arguments this starts to get really messy. The better solution would be for the logging libraries to provide this sanitization, perhaps as an option to always replace \r\n. But that's not happening anytime soon.

So, you could add something like:

    public static Supplier<String> lazySanitizeForLogging(CharSequence msg) {
        return lazy(() -> SANITIZER_PATTERN.matcher(original).replaceAll("_"));
    }

Starting with these two methods might be fine.

[sleberknight]

Re-reviewing this, it's kind of funny because one the one hand, the above code sanitizes input by replacing newlines and carriage returns, but on the other it intentionally adds line separators to the log statements! Maybe the idea was that sanitizing user input, e.g., from query parameters, was needed, but in our own logging it is acceptable to add newlines. Regardless, it would probably be best to remove those newlines.