29

I want to send log events to Loggly as JSON objects with parameterized string messages. Our project currently has a lot of code that looks like this:

String someParameter = "1234";
logger.log("This is a log message with a parameter {}", someParameter);

We're currently using Logback as our SLF4J backend, and Logback's JsonLayout to serialize our ILogEvent objects into JSON. Consequentially, by they time our log events are shipped to Loggly, they look like this:

{
    "message": "This is a log message with a parameter 1234",
    "level": INFO,
    ....
}

While this does work, it sends a different message string for every value of someParameter, which renders Loggly's automatic filters next to useless.

Instead, I'd like to have a Layout that creates JSON that looks like this:

{
    "message": "This is a log message with a parameter {}",
    "level": INFO,
    "parameters": [
        "1234"
    ]
}

This format would allow Loggly to group all log events with the message This is a log message with a parameter together, regardless of the value of someParameter.

It looks like Logstash's KV filter does something like this - is there any way to accomplish this task with Logback, short of writing my own layout that performs custom serialization of the ILogEvent object?

MartyIX
  • 27,828
  • 29
  • 136
  • 207
MusikPolice
  • 1,699
  • 4
  • 19
  • 38
  • The problem I see with your example is that you do not know where the parameter would be inserted in the message. – Leonard Brünings Mar 24 '14 at 16:43
  • @LeonardBrünings that shouldn't matter, because the parameters are passed to the `log.log(message, param1, param2);` function. As long as order is preserved in the array that's inserted into the JSON object, all is good. – MusikPolice Mar 24 '14 at 16:59
  • but your message in the json did not have any placeholders. If that intentional and not a mistake you would not know how to render the correct message. – Leonard Brünings Mar 24 '14 at 18:38
  • @LeonardBrünings added the placeholder to the sample output JSON – MusikPolice Mar 24 '14 at 19:07

5 Answers5

21

There is a JSON logstash encoder for Logback, logstash-logback-encoder

Mark Roper
  • 1,389
  • 1
  • 16
  • 27
12

So for me I was trying to log execution times, I created a pojo called ExecutionTime with name, method, class, duration.

I was then able to create it:

ExecutionTime time = new ExecutionTime("Controller Hit", methodName, className, sw.getTotalTimeMillis());

For logging I then used:

private final Logger logger = LoggerFactory.getLogger(this.getClass());
logger.info(append("metric", time), time.toString());

Make sure you have: 

import static net.logstash.logback.marker.Markers.append;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

This will log something like this:

{  
   "ts":"2017-02-16T07:41:36.680-08:00",
   "msg":"ExecutionTime [name=Controller Hit, method=setupSession, className=class com.xxx.services.controllers.SessionController, duration=3225]",
   "logger":"com.xxx.services.metrics.ExecutionTimeLogger",
   "level":"INFO",
   "metric":{  
      "name":"Controller Hit",
      "method":"setupSession",
      "className":"class com.xxx.services.controllers.SessionController",
      "duration":3225
   }
}

Might be a different set up as I was using logback-spring.xml to output my logs to json:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/base.xml"/>
    <property name="PROJECT_ID" value="my_service"/>
    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <File>app/logs/${PROJECT_ID}.json.log</File>
        <encoder class="net.logstash.logback.encoder.LogstashEncoder">
            <fieldNames>
                <timestamp>ts</timestamp>
                <message>msg</message>
                <thread>[ignore]</thread>
                <levelValue>[ignore]</levelValue>
                <logger>logger</logger>
                <version>[ignore]</version>
            </fieldNames>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
            <maxIndex>10</maxIndex>
            <FileNamePattern>app/logs/${PROJECT_ID}.json.log.%i</FileNamePattern>
        </rollingPolicy>
        <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
            <MaxFileSize>20MB</MaxFileSize>
        </triggeringPolicy>
    </appender>
    <logger name="com.xxx" additivity="false" level="DEBUG">
        <appender-ref ref="FILE"/>
        <appender-ref ref="CONSOLE"/>
    </logger>
    <root level="WARN">
        <appender-ref ref="FILE"/>
    </root>
</configuration>
andrewps
  • 321
  • 3
  • 6
  • On applying the similar pattern - I see the "metrics" data log duplicated. It came as part of message and separate node as "metric" - same information printed ? Any suggestions please ? – techsavvy Oct 10 '19 at 15:34
  • I could resolve that duplicate issue as follows. logger.info("TROS Process Update ",append("trosdata",cleanerLogData),cleanerLogData); now message got value " TROS Proces Update" – techsavvy Oct 10 '19 at 16:31
  • Yeah the second param is the msg ie: logger.info(append("metric", metricObject), msgString); So you just need to change msgString to something else. – andrewps Jun 30 '21 at 15:12
5

You could use a Mapped Diagnostic Context to set a stamp for each of those type of log messages that you could then filter on once in loggly.

According to the source of JsonLayout the stamp is stored as a separate value in the JSON.

muttonUp
  • 6,351
  • 2
  • 42
  • 54
5

Here's a recently created project that provides a JSON-specific logging API and works with SLF4J:

https://github.com/savoirtech/slf4j-json-logger

ash
  • 4,867
  • 1
  • 23
  • 33
  • That's a nice little library. I doubt I'll switch existing projects over to it, as it would require a fair bit of work, but I'll definitely keep it in mind for future projects. – MusikPolice Aug 22 '16 at 15:02
  • Thank you @MusikPolice - we appreciate the feedback. – ash Aug 22 '16 at 22:30
  • I'm starting a new project now and will try this out. However, I'm not sure if I can configure default fields to include in log (I managed to do that with Logback, but I don't like relying on MDC to output any field, so I would prefer slf4j-json-logger with it's API). The idea is to have a field+value configured in config file, which would end up automatically added to all produced JSON log lines/objects. Is that possible in slf4j-json-logger? – mvmn Mar 06 '17 at 16:33
  • There is no feature for that now. Should be relatively easy to accomplish. Please either post this as an issue on github (here https://github.com/savoirtech/slf4j-json-logger/issues), or contribute a PR! – ash Mar 11 '17 at 05:40
  • The approach is nice and we tried it, but since the log messages of libraries are NOT formatted as JSON it was of no use for us. – Mark Schäfer Jul 12 '18 at 15:31
1

Like already answered you'll get a one-dimensional JSON tree with MDC and/or using a Marker with logstash-logback-encoder.

If you are also looking for the following:

  • codebooks for definition of logged datatype key and type,
  • configuration of log-aggregation tools (like elasticsearch)
  • generated Java helper-code for efficient and correct logging

then try a project I've created: json-log-domain. It defines a simple YAML-format definition from which the above can be generated.

An example helper-code statement would be

logger.info(host("localhost").port(8080), "Hello world");

while generated markdown would like something like this.

ThomasRS
  • 8,215
  • 5
  • 33
  • 48