Recently, the project put forward the requirement that the log output be fixed in JSON format for back-end Flink program parsing.

Project background

The project is a simple Maven project. Logs are collected by Filebeat, so there is no need to configure output to Logstash.
Below is the dependency configuration in the pom.xml file, where logstash-logback-encoder is used to complete the log format conversion operation.

       <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>
            <version>1.7.28</version>
        </dependency>
        <dependency>
            <groupId>net.logstash.logback</groupId>
            <artifactId>logstash-logback-encoder</artifactId>
            <version>6.1</version>
        </dependency>
        <dependency>
            <groupId>ch.qos.logback</groupId>
            <artifactId>logback-classic</artifactId>
            <version>1.2.3</version>
        </dependency>
        <dependency>
            <groupId>ch.qos.logback</groupId>
            <artifactId>logback-access</artifactId>
            <version>1.2.3</version>
        </dependency>

Logback configuration

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="60 seconds" debug="false">
    <contextName>probe</contextName>

   <!-- Configuration file storage address  -->
    <property name="LOG_PATH" value="./logs"/>

    <!-- Read the contents of the application configuration file to get what you need below region attribute --->
    <property resource="application.properties"/>

    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
            <providers class="net.logstash.logback.composite.loggingevent.LoggingEventJsonProviders">
                <pattern>
                    <pattern>
                        {
                        "date":"%d{yyyy-MM-dd HH:mm:ss.SSS}",
                        "level":"%level",
                        <!-- system Attributes are determined dynamically by the program and are passed through Slf4j Provided MDC Make specific settings -->
                        "system":"%X{system} ",
                        <!-- Read the properties in the configuration file and set them to the log  -->
                        "region":"${application.region}",
                        "filepath":"%class:%line",
                        "msg":"%msg"
                        }
                    </pattern>
                </pattern>
            </providers>
            <charset>UTF-8</charset>
        </encoder>
        <append>true</append>

        <!--  Configuration Log File Rolling Storage Policy -->
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>${LOG_PATH}/probe.%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <MaxHistory>10</MaxHistory>
            <maxFileSize>10MB</maxFileSize>
            <totalSizeCap>300MB</totalSizeCap>
        </rollingPolicy>
    </appender>

    <root level="FILE">
        <appender-ref ref="console"/>
    </root>
</configuration>

The above is the configuration content in logback.xml file. It should be noted that the region in the log is obtained from the configuration file application.properties, while the system attribute is dynamically set by the program as the msg field.

MDC Sets system Properties

    /**
     * Measuring the delay of a single http request
     *
     * @param url Request address
     */
    private static void measureHttpTimeDelay(String url, Platform platform) {
        // Setting system Properties in MDC
        MDC.put("system", platform.toString());
        OkHttpClient client = new OkHttpClient();
        client.newBuilder().connectTimeout(5, TimeUnit.SECONDS)
                .readTimeout(5, TimeUnit.SECONDS)
                .build();
        Request request = new Request.Builder().url(url).build();
        Instant before = Instant.now();
        try (Response response = client.newCall(request).execute()) {
            Instant after = Instant.now();
            if (response.isSuccessful()) {
                long duration = Duration.between(before, after).toMillis();
                log.info("Request successful!" + response.message() + "time delay = " + duration + "ms");
            } else {
                log.info("The request failed!" + response.message());
            }
        } catch (IOException e) {
            log.error("get http response failed, url: {}, ex: {}", url, e.getMessage());
        }
        // Clear system Property Settings in MDC
        MDC.remove("system");
    }

The above program simulates a simple http request and records the corresponding logs.
It's important to note that MDC is implemented in ThreadLocal, so it's important to use MDC in multi-threaded environments.

Final Journal

The final log is shown in the following figure:

{"date":"2019-09-05 21:16:44.643","level":"INFO","system":"ALI_YUN ","region":"HUABEI","filepath":"com.test.Application:38","msg":"Request successful!OK time delay = 439ms"}
{"date":"2019-09-05 21:16:45.326","level":"INFO","system":"HUAWEI_YUN ","region":"HUABEI","filepath":"com.test.Application:38","msg":"Request successful!OK time delay = 165ms"}
{"date":"2019-09-05 21:16:46.513","level":"INFO","system":"ALI_YUN ","region":"HUABEI","filepath":"com.test.Application:38","msg":"Request successful!OK time delay = 485ms"}
{"date":"2019-09-05 21:16:56.130","level":"INFO","system":"HUAWEI_YUN ","region":"HUABEI","filepath":"com.test.Application:38","msg":"Request successful!OK time delay = 419ms"}