Log4j 2 JSON pattern layout + Logging JSON payload

Amila Iddamalgoda picture Amila Iddamalgoda · Aug 22, 2016 · Viewed 8.2k times · Source

I am using ELK stack along with log4j 2 via sl4j with json pattern layout to log messages. All my logs are logged as json messages.Also in one of my logs I am trying to log the json response received from the third party service. But this response json body is not appended to the json structure. But it rather appended as a string including the escape characters.

how the ultimate logs being logged out.

 {
    "timeMillis": 1471862316416,
    "thread": "FioranoMQ Pubsub Session Thread",
    "level": "INFO",
    "loggerName": "com.mlp.eventing.bridge.fiorano.TopicMessageListener",
    "message": "{\"Msgtype\":\"SentToRabbitMqTest\",\"MessageData\":\"10\",\"opration\":\"devide\"}",
    "endOfBatch": false,
    "loggerFqcn": "org.apache.logging.slf4j.Log4jLogger",
    "threadId": 28,
    "threadPriority": 5
}

In above message segment is appended as escaped strings rather than the entire json structure. My expected out put should be

{
    "timeMillis": 1471862316416,
    "thread": "FioranoMQ Pubsub Session Thread",
    "level": "INFO",
    "loggerName": "com.mlp.eventing.bridge.fiorano.TopicMessageListener",
    "message": {
        "Msgtype": "SentToRabbitMqTest",
        "MessageData": "10",
        "opration": "devide"
    },
    "endOfBatch": false,
    "loggerFqcn": "org.apache.logging.slf4j.Log4jLogger",
    "threadId": 28,
    "threadPriority": 5
}

I am expecting to extract the fields in the message segment using the grok filters for json in shipper.conf

Below are my configurations :- log4j2.xml

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="info"> <!-- log4j internals tracing -->
    <properties>
        <property name="pattern">%d{yyyy-MM-dd HH:mm:ss.SSS} | %-5.5p | %-20.20C:%-5.5L | %msg%n</property>
        <property name="filePath">/opt/mlp/logs</property> 
        <property name="fileName">logs</property>
    </properties>
    <Appenders>
        <RollingFile name="RollingFile" fileName="${filePath}/${fileName}.log"
                     filePattern="${filePath}/${fileName}-%d{yyyy-MM-dd}-%i.log" append="true">
            <JSONLayout complete="false" compact="true" eventEol="true" />  
            <PatternLayout>
                <pattern>${pattern}</pattern>
            </PatternLayout>
            <Policies>
                <SizeBasedTriggeringPolicy size="1000 KB"/> 
            </Policies>l
        </RollingFile>
        <Console name="STDOUT" target="SYSTEM_OUT">
            <PatternLayout>
                <pattern>${pattern}</pattern>
            </PatternLayout>
        </Console>
    </Appenders>
    <Loggers>
        <Root level="debug">
            <AppenderRef ref="RollingFile"/>
            <AppenderRef ref="STDOUT"/>
        </Root>
    </Loggers>
</Configuration>

sample code snippet

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

class A {
private static final Logger LOG = LoggerFactory.getLogger(Main.class);

public void testMethod()  {

JSONObject responseJson = callService();// json simple object
LOG.info(responseJson);

}

}

maven dependencies

<dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>
            <version>1.7.21</version>
        </dependency>

        <dependency>
            <groupId>org.apache.logging.log4j</groupId>
            <artifactId>log4j-slf4j-impl</artifactId>
            <version>2.6.2</version>
        </dependency>

        <!-- end adding sl4j 2 for the message bridge -->

        <dependency>
            <groupId>org.apache.logging.log4j</groupId>
            <artifactId>log4j-api</artifactId>
            <version>2.6.2</version>
        </dependency>

        <dependency>
            <groupId>org.apache.logging.log4j</groupId>
            <artifactId>log4j-core</artifactId>
            <version>2.6.2</version>
        </dependency>

        <!--
        to enable json support for log4j enable following libraries
        -->

        <dependency>
            <groupId>com.fasterxml.jackson.core</groupId>
            <artifactId>jackson-core</artifactId>
            <version>2.7.5</version>
        </dependency>

        <dependency>
            <groupId>com.fasterxml.jackson.core</groupId>
            <artifactId>jackson-databind</artifactId>
            <version>2.7.5</version>
        </dependency>

        <dependency>
            <groupId>com.fasterxml.jackson.core</groupId>
            <artifactId>jackson-annotations</artifactId>
            <version>2.7.5</version>
        </dependency>

Answer

Kirill picture Kirill · Jan 25, 2019

To be able to log JSON unescaped, you should use Log4j2 logger instead of Slf4j. This feature is available starting from Log4j 2.11.

Log4j logger is able to log ObjectMessage, which will be converted to a nested JSON. ObjectMessage constructor accepts Map, so JSONObject have to be converted to map (e.g. with help of Jackson ObjectMapper).

In the layout configuration add objectMessageAsJsonObject="true":

<JSONLayout complete="false" compact="true" eventEol="true" objectMessageAsJsonObject="true" />

Full working example:

import com.fasterxml.jackson.core.type.TypeReference;
import com.fasterxml.jackson.databind.ObjectMapper;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.message.ObjectMessage;
import org.json.JSONObject;

import java.io.IOException;
import java.util.HashMap;
import java.util.Map;

public class test {

    public static void main(String[] args) throws IOException {
        HashMap<Object, Object> map = new HashMap<>();
        map.put("foo", "bar");
        JSONObject jsonObject = new JSONObject(map);

        Map<String, Object> newMap = new ObjectMapper().readValue(jsonObject.toString(), new TypeReference<Map<String, Object>>() {});

        Logger log4jLogger = LogManager.getLogger("mainLogger");
        log4jLogger.info(new ObjectMessage(newMap));
    }
}

This will produce:

{"thread":"main","level":"INFO","loggerName":"mainLogger","message":{"foo":"bar"},"endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","instant":{"epochSecond":1548434758,"nanoOfSecond":572000000},"threadId":1,"threadPriority":5}