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?

Use some form of aspects? – Dave Newton Jan 22 '16 at 22:03 — Dave Newton, Jan 22 '16 at 22:03

score 1 · Accepted Answer · answered Jan 25 '16 at 11:12

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));
    }
}

score 0 · Answer 2 · answered Jan 22 '16 at 22:35

0

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.

answered Jan 22 '16 at 22:35

Augusto

28,839
5
58
88

There are no problems in logging HTTP requests and responses. I don't even have to use application logging to this - this may be achieved by the means of the server. Interceptors may help to get rid of a peace of code I have provided, but they have some limitations like no direct way to get request and response bodies. I have not so much API methods in application, so it easier to wrap them like in code snippet. The real problem is to collect all the logs relevant to request during its execution without touching the code. Not sure how aspects can help either - need to think about this ) – alexey Jan 22 '16 at 22:53

Lazy man logging

2 Answers2