JSON Logging in Spring Boot Applications
Tags: microservices, java
Published: 2020-09-18 02:28:48

Application logs are like the black box. When troubleshooting issues first thing I look at is the application logs. It becomes essential to put thought into what we log in order to be able to identify issues based on logs.

Today we have a class of applications called log aggregation systems. Log aggregation is useful when we have lot of microservices and we want to trace logs across microservices.

I would like to demonstrate how to log application logs in a JSON format.

# Advantages of JSON Logging

A traditional java application log would look something like the following

```
2020-09-17 21:56:10.740  INFO [Orders:restartedMain::] o.s.b.w.embedded.tomcat.TomcatWebServer - Tomcat started on port(s): 8080 (http) with context path ''
```

If one were to search it in a unix box one would do a 
```
cat application.log | grep <your-search>
```

I recall days where logs like these were shipped by me to Sumo Logic (another log aggregation system) and I would use regular expression gymnastics to arrive at an optimal search.

Someone came up with this different approach of why not store the logs in a more searchable format when it is primarily used for searching. JSON happened to lend itself easily to being searched and hence json logging. Another way to refer to this is also structured logs, because the logs have a well defined structure which can later be used to search.

The same application log displayed above in a JSON format would look like

```
{
  "@timestamp": "2020-06-17T14:41:11.174-04:00",
  "@version": "1",
  "message": "Tomcat initialized with port(s): 8080 (http)",
  "logger_name": "org.springframework.boot.web.embedded.tomcat.TomcatWebServer",
  "thread_name": "restartedMain",
  "level": "INFO",
  "level_value": 20000
}
```
This now makes it easier to search the logs by say `time` or `level` or even `thread_name`.

# JSON Logging in Spring Boot Application

For logging logs in a JSON format one needs to include 2 dependencies. If you use maven for dependency management one would include the dependencies as follows

```
<dependency>
	<groupId>net.logstash.logback</groupId>
	<artifactId>logstash-logback-encoder</artifactId>
	<version>6.4</version>
</dependency>
<dependency>
	<groupId>ch.qos.logback</groupId>
	<artifactId>logback-classic</artifactId>
	<version>1.2.3</version>
</dependency>
```

Here we are using the library [logstash-logback-encoder](https://github.com/logstash/logstash-logback-encoder)

We can then configure the json encoder the logback with the following code snippet

```
<encoder class="net.logstash.logback.encoder.LogstashEncoder">
    <providers>
        <timestamp>
            <timeZone>EST</timeZone>
        </timestamp>
        <pattern>
            <pattern>
                {
                "level": "%level",
                "service": "orders",
                "traceId": "%X{X-B3-TraceId:-}",
                "spanId": "%X{X-B3-SpanId:-}",
                "thread": "%thread",
                "class": "%logger{40}",
                "message": "%message"
                }
            </pattern>
        </pattern>
        <stackTrace>
            <throwableConverter class="net.logstash.logback.stacktrace.ShortenedThrowableConverter">
                <maxDepthPerThrowable>30</maxDepthPerThrowable>
                <maxLength>2048</maxLength>
                <shortenedClassNameLength>20</shortenedClassNameLength>
                <rootCauseFirst>true</rootCauseFirst>
            </throwableConverter>
        </stackTrace>
    </providers>
</encoder>
```

So let us assume you want to log the data as traditional logs to the console and log them as json to a file we can configure the logback xml as follows

```
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/console.xml"/>
    <appender name="stdout" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %5p [Orders:%thread:%X{X-B3-TraceId}:%X{X-B3-SpanId}] %logger{40} - %msg%n
            </pattern>
        </encoder>
    </appender>
    <appender name="fileout"
              class="ch.qos.logback.core.rolling.RollingFileAppender">
        <File>./logs/orders.log</File>
        <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
            <maxIndex>8</maxIndex>
            <FileNamePattern>./logs/orders.log.%i
            </FileNamePattern>
        </rollingPolicy>
        <triggeringPolicy
                class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
            <MaxFileSize>128MB</MaxFileSize>
        </triggeringPolicy>

        <encoder class="net.logstash.logback.encoder.LogstashEncoder">
            <providers>
                <timestamp>
                    <timeZone>EST</timeZone>
                </timestamp>
                <pattern>
                    <pattern>
                        {
                        "level": "%level",
                        "service": "orders",
                        "traceId": "%X{X-B3-TraceId:-}",
                        "spanId": "%X{X-B3-SpanId:-}",
                        "thread": "%thread",
                        "class": "%logger{40}",
                        "message": "%message"
                        }
                    </pattern>
                </pattern>
                <stackTrace>
                    <throwableConverter class="net.logstash.logback.stacktrace.ShortenedThrowableConverter">
                        <maxDepthPerThrowable>30</maxDepthPerThrowable>
                        <maxLength>2048</maxLength>
                        <shortenedClassNameLength>20</shortenedClassNameLength>
                        <rootCauseFirst>true</rootCauseFirst>
                    </throwableConverter>
                </stackTrace>
            </providers>
        </encoder>
    </appender>
    <root level="info">
        <appender-ref ref="fileout" />
        <appender-ref ref="stdout" />
    </root>
</configuration>
```

For a complete spring boot application with json logging please refer to sample applications [orders](https://github.com/anandsunderraman/structured-logging-tutorial/tree/master/orders) or [shipping](https://github.com/anandsunderraman/structured-logging-tutorial/tree/master/shipping)

# Conclusion

JSON logging can be achieved in other languages / frameworks as well like node.js and python.

For node.js libraries like [winston](https://github.com/winstonjs/winston) can be used.