Lazy man logging

Question

I have a spring application serving web requests. Each request method looks like this

@RequestMapping(value = someUri, method = RequestMethod.POST)
Response someUriProcessor (SomeRequestModelMethod request) throws Exception {

    try (JsonLogger logger = new JsonLogger(request, loggingTest1Uri)){
        // get actual result
        Response result = getSomeResultMethod(request);
        // feed result to special logging object
        logger.setResult (result);
        // return result to client
        return result;
    }
}

JsonLogger class generate JSON object in close method and log it via standard slf4j logging framework which is uploaded to log analyzer tool (Splunk), it logs request, response, response time and so on.

During execution of getSomeResultMethod which does a lot of work lots of useful logs are generated using standard slf4j with logback binding in production. I want these logs to be included in JsonLogger without touching all the underlying classes (there are LOTS of them), say using method JsonLogger.appendToResultLog(String txt). My first thought is create my own wrapping slf4j binding, unwind stacktrace on each call to logger.info, logger.error and so on methods using reflection up to rest controller method and append log string JsonLogger in it.

I have strong feeling that I'm inventing a bicycle. Are there any more-or-less standard way to achieve results required?

Answer 1

Ended up with no aspects and reflection - just custom logback appender.

public class JsonInnerLogsAppender extends AppenderBase<ILoggingEvent> {
    public JsonInnerLogsAppender () {
        this.setName("JSON_LOGGING_INTERNAL");
    }
    @Override
    protected void append(ILoggingEvent eventObject) {
        JsonLogger.putLogInfo(eventObject.getFormattedMessage());
    }
}

And JsonLogger like this

public class JsonLogger implements AutoCloseable {

    /**
     * Contains mapping between current thread id and corresponding JsonLogger object
     */
    private static transient ConcurrentHashMap<Long, JsonLogger> loggersMap = new ConcurrentHashMap<>();

    /**
     * Should be configured with special appender pattern, like
     * <encoder>
     *     <pattern>%date{ISO8601} [%-18thread] %-5level %msg %logger{70}%n</pattern>
     * </encoder>
     */
    private transient Logger logger = LoggerFactory.getLogger(getClass());
    private transient static Gson gson = new Gson();


    /**
     * Container that would be serialized to JSON after close and added to JSON log
     */
    private final JsonLogContainer logContainer;

    public JsonLogger (Object request, HttpServletRequest servletRequest) {
        this.logContainer = new JsonLogContainer(gson.toJson(request), servletRequest.getRequestURI());
        // request is started
        loggersMap.put(Thread.currentThread().getId(), this);
    }


    /**
     * @param logString formatted log string, called from custom appender
     */
    public static void putLogInfo (String logString) {
        // find appropriate JsonLogger instance (if any) and append log to it
        JsonLogger jsonLogger = loggersMap.get(Thread.currentThread().getId());
        if ( null != jsonLogger ) {
            jsonLogger.putLogToContainer(logString);
        }
    }

    private void putLogToContainer (String logString) {
        logContainer.putLog(logString);
    }

    @Override
    public void close() throws Exception {
        String log = this.logContainer.getLog(new Date());
        // request is completed
        loggersMap.remove(Thread.currentThread().getId());
        // put record to JSON log
        logger.info(log);
    }

    public void setResult(Object result) {
        logContainer.setResponse(gson.toJson(result));
    }
}

Answer 2

There are indeed a few simpler alternatives. I think the cleanest way with spring is to create a custom Interceptor (which is pretty much like a servlet filter, but with more refined functionality).

You can read a bit more about them in the Spring documentation.

I forgot to add that there might be a even simpler solution using Logback Access, which is a tiny libray from logback to log information about request and responses.