Best way to write custom json messages using log4j2

Question

I have been using log4j for different kind of projects and have some experience with log4j2. All implementations used the default appender and layout. Currently i need to write a application which writes in json format. So i tried the log4j2 JSONLayout layout by setting up a very simple log4j2 logger.

public class JSONLogger {

    private static final Logger LOGGER = LogManager.getLogger();

    public static void main(String[] args) {
        JSONLogger jsonlogger = new JSONLogger() ;
    }

    public JSONLogger() {
        LOGGER.log(Level.FATAL, "hi mum!") ;

         int val1 = 10, val2 = 11, val3 = 12;

         LOGGER.log(Level.FATAL,"val1={}, val2={}, val3={}", val1, val2, val3);
    }

}

jsonLoggerProperties.xml

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="DEBUG">
    <Properties>
        <Property name="log-path">/Users/petervannes/NetBeansProjects/JSONLogger/logfiles</Property>
    </Properties>

    <Appenders>
        <RollingFile name="json_file_appender" fileName="${log-path}/jsonlogger.json"
                     filePattern="${log-path}/%d{yyyyMMdd}_jsonlogger-%i.json" >
            <JSONLayout complete="true" compact="false"/>
            <Policies>
                <SizeBasedTriggeringPolicy size="1 KB" />
            </Policies>
            <DefaultRolloverStrategy max="4"/>
        </RollingFile>

    </Appenders>


    <Loggers>
        <root level="debug" additivity="false">
            <AppenderRef ref="json_file_appender"/>
        </root>
    </Loggers>
</Configuration>

Resulting in an log entry similar to;

, {
  "timeMillis" : 1474573600359,
  "thread" : "main",
  "level" : "FATAL",
  "loggerName" : "JSONLogger",
  "message" : "val1=10, val2=11, val3=12",
  "contextStack" : [ "fieldName2" ],
  "endOfBatch" : false,
  "loggerFqcn" : "org.apache.logging.log4j.spi.AbstractLogger",
  "threadId" : 1,
  "threadPriority" : 5
}

What i need is to log to a JSON format like this;

, {
  "DateTime" : "08/01/2016 21:33:22.334",
  "level" : "FATAL",
  "Summary" : "Something has gone wrong",
  "ChainManager" : "Manager A",
  "Optionals" : { "Key_1": "Value1",
                  "Key_2": "Value2" }
}

Is this possibile with the log4j2 JSONLayout or is there any other layout i can use to get this format ?

Kienan

Answer 1

The question is about writing a custom json messages using log4j2.

This is possible since version 2.11 of log4j2 version:

https://issues.apache.org/jira/browse/LOG4J2-2190

The new parameter of for JSONLayout is called

objectMessageAsJsonObject

. Sample project files;

log4j2.properties

status = error


appender.ana_whitespace.type = RollingFile
appender.ana_whitespace.name = ana_whitespace
appender.ana_whitespace.fileName = ${sys:es.logs.base_path:-target}${sys:file.separator}ana_whitespace.log
appender.ana_whitespace.layout.type = JsonLayout
appender.ana_whitespace.layout.propertiesAsList = false
appender.ana_whitespace.layout.compact = false
appender.ana_whitespace.layout.eventEol = true
appender.ana_whitespace.layout.objectMessageAsJsonObject = true
appender.ana_whitespace.layout.complete= true
appender.ana_whitespace.layout.properties= true
appender.ana_whitespace.filePattern = ${sys:es.logs.base_path:-target}${sys:file.separator}ana_whitespace-%d{yyyy-MM-dd}.log
appender.ana_whitespace.filter.1.type = MarkerFilter
appender.ana_whitespace.filter.1.onMismatch=DENY
appender.ana_whitespace.filter.1.onMatch=ACCEPT
appender.ana_whitespace.filter.1.marker=ANA_WHITESPACE
appender.ana_whitespace.policies.type = Policies
appender.ana_whitespace.policies.time.type = TimeBasedTriggeringPolicy
appender.ana_whitespace.policies.time.interval = 1
appender.ana_whitespace.policies.time.modulate = true
appender.ana_whitespace.policies.size.type = SizeBasedTriggeringPolicy
appender.ana_whitespace.policies.size.size = 10 MB

rootLogger.level = info
rootLogger.appenderRef.ana_whitespace.ref = ana_whitespace

Example Java code

package de.es.stemmer;

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

import org.apache.http.client.ClientProtocolException;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.Marker;
import org.apache.logging.log4j.MarkerManager;
import org.apache.logging.log4j.ThreadContext;
import org.apache.logging.log4j.core.LoggerContext;
import org.apache.logging.log4j.message.ObjectMessage;

public class JsonLoggerTest {
    final static Logger log = LogManager.getLogger(JsonLoggerTest.class);
    final static Marker MARKER_WHITESPACE = MarkerManager.getMarker("ANA_WHITESPACE");

    public static void main(String[] args) throws ClientProtocolException, IOException {
        System.setProperty("es.logs.base_path", "target");
        System.setProperty("es.logs.cluster_name", "_cluster");
        LoggerContext.getContext().reconfigure();
        ThreadContext.put("orig", "MDC_origValue");
        ThreadContext.put("source", "MDC_sourceSnippet");
        Map<String, String> map = new TreeMap<>();
        map.put("orig", "msg_origValue");
        map.put("source", "msg_sourceSnippet");
        ObjectMessage msg = new ObjectMessage(map);
        log.info(MARKER_WHITESPACE, msg);
        ThreadContext.remove("orig");
        ThreadContext.remove("source");
    }

}

JSON Log Entry

[
{
  "thread" : "main",
  "level" : "INFO",
  "loggerName" : "de.es.stemmer.JsonLoggerTest",
  "marker" : {
    "name" : "ANA_WHITESPACE"
  },
  "message" : {
    "orig" : "msg_origValue",
    "source" : "msg_sourceSnippet"
  },
  "endOfBatch" : false,
  "loggerFqcn" : "org.apache.logging.log4j.spi.AbstractLogger",
  "instant" : {
    "epochSecond" : 1526576578,
    "nanoOfSecond" : 184000000
  },
  "contextMap" : {
    "orig" : "MDC_origValue",
    "source" : "MDC_sourceSnippet"
  },
  "threadId" : 1,
  "threadPriority" : 5
}

]

Unemployed

Whilst that is helpful - and you can put out custom structured data in the message - it doesn't really address the problem of not wanting huge amounts of noise and/or fields that are not formatted to meet specific needs. Noise in this case would certainly be loggerFqcn, endOfBatch, an instant instead of a human readable timestamp and might also include, the threadPriority and threadId (depending on your use case) and possibly other fields. So to my mind not really custom at all. – Scarce

Answer 2

I know this is an old question but I think there is a better way to do it.

You should use the JSON Template Layout.

And then you will be able to configure your JsonLayout with a template like this one:

{
  "mdc": {
    "$resolver": "mdc"
  },
  "exception": {
    "exception_class": {
      "$resolver": "exception",
      "field": "className"
    },
    "exception_message": {
      "$resolver": "exception",
      "field": "message"
    },
    "stacktrace": {
      "$resolver": "exception",
      "field": "stackTrace",
      "stackTrace": {
        "stringified": true
      }
    }
  },
  "line_number": {
    "$resolver": "source",
    "field": "lineNumber"
  },
  "class": {
    "$resolver": "source",
    "field": "className"
  },
  "@version": 1,
  "source_host": "${hostName}",
  "message": {
    "$resolver": "message",
    "stringified": true
  },
  "thread_name": {
    "$resolver": "thread",
    "field": "name"
  },
  "@timestamp": {
    "$resolver": "timestamp"
  },
  "level": {
    "$resolver": "level",
    "field": "name"
  },
  "file": {
    "$resolver": "source",
    "field": "fileName"
  },
  "method": {
    "$resolver": "source",
    "field": "methodName"
  },
  "logger_name": {
    "$resolver": "logger",
    "field": "name"
  }
}

There are many configurations available using templates.

See more about it here:

https://logging.apache.org/log4j/2.x/manual/json-template-layout.html

Marolda

any idea on how to add custom fields to it? – Alderete

What do you mean @AmitK? This template layout is created so you can set any custom field you want. What do you need? This "@version", for example, is a custom field with the name "@version". You can set any field you want. – Marolda

If I add a "data" field, how can the code dynamically add data into the field? – Himmler

I'm not sure of what you want.. You can create a "data" field but you will need to use one of the available resolvers.. If you clarify what you want I may be able to help. – Marolda

@LucasSoares I think the question is that from a java log.info(), it doesn't allow you to add additional properties or pass them in. The expected ability would be log.info("message").addField("extra field", data); or something like this. The provided examples are to add a format or parser which while adding a field like data do so on every log line. – Skillern

Why not @SolutionFindingBrowser? You can use MDC (ThreadContext) to log custom fields and format it using the MDC resolver.. – Marolda

Using MDC is possible, but then you have to remember to clear the MDC after logging, or wrap it in a try-with-resources. It's not a particularly elegant solution to the problem. – Fodder

I think the above concerns are addressed in my answer below (https://mcmap.net/q/324742/-best-way-to-write-custom-json-messages-using-log4j2) - check it out! – Dorie

Answer 3

If you're looking for a way to generate customized JSON log messages without any of the "noise" added by log4j2 you could create an implementation of the Message interface and use a different layout - for example PatternLayout. Below is an example of this approach:

First a class to implement Message inferface

import java.util.HashMap;
import java.util.Map;

import org.apache.logging.log4j.message.Message;

import com.google.gson.Gson;
import com.google.gson.GsonBuilder;

public class JSONMessage implements Message {

    private static final long serialVersionUID = 538439258494853324L;
    private String messageString;
    private static final Gson GSON = new GsonBuilder()
            .setPrettyPrinting()
            .create();

    public JSONMessage(){
        this(null);
    }

    public JSONMessage(Object msgObj){
        parseMessageAsJson(msgObj);
    }

    public JSONMessage(String msgStr){
        Map<String,String> msgObj = new HashMap<>();
        msgObj.put("message", msgStr);
        parseMessageAsJson(msgObj);
    }

    private void parseMessageAsJson(Object msgObj){
        messageString = GSON.toJson(msgObj);
    }

    @Override
    public String getFormattedMessage() {
        return messageString;
    }

    @Override
    public String getFormat() {
        return messageString;
    }

    @Override
    public Object[] getParameters() {
        return null;
    }

    @Override
    public Throwable getThrowable() {
        return null;
    }

}

Next the log4j2.xml configuration:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN" name="App">
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
                <PatternLayout pattern="%m%n" />
        </Console>
    </Appenders>

    <Loggers>
        <Root level="trace">
            <AppenderRef ref="Console" />
        </Root>
    </Loggers>
</Configuration>

Now a simple application class to generate a log event

import java.util.HashMap;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;


public class App {

    private static final Logger logger = LogManager.getLogger();

    public static void main( String[] args )
    {
        HashMap<String,Object> msgMap = new HashMap<>();
        msgMap.put("someInt", 123);
        msgMap.put("note", "Maybe you put a message here");

        HashMap<String,Object> anotherMap = new HashMap<>();
        anotherMap.put("key1", "value1");
        anotherMap.put("key2", "value2");
        msgMap.put("map", anotherMap);
        logger.info(new JSONMessage(msgMap));
    }
}

Here is some sample output:

{
  "note": "Maybe you put a message here",
  "map": {
    "key1": "value1",
    "key2": "value2"
  },
  "someInt": 123
}

Note that I'm using Gson to create the JSON output, but you could use any library you want. Also note that this code does not generate "complete" JSON in that it does not add the square brackets at the start and end of the log or the comma between message objects.

Gamaliel

Hello! I tried this approach but the JSON is being added to the property message instead of creating separated fields: "message" : "{\"foo\":\"bar\",\"module\":\"My module"}" instead of something like { "message": "my message", "foo": "bar", "module" "my module" } Maybe I'm doing something wrong? – Dagoba

Answer 4

I found a solution which works for me; slf4j-json-logger. It is a slf4j framework, so should be included in the pom.xml. Sample project files;

pom.xml

  <?xml version="1.0" encoding="UTF-8"?>
  <project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
     <modelVersion>4.0.0</modelVersion>
     <groupId>com.reddipped</groupId>
     <artifactId>JSONLogger_2</artifactId>
     <version>1.0-SNAPSHOT</version>
     <packaging>jar</packaging>
     <properties>

        <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
        <maven.compiler.source>1.6</maven.compiler.source>
        <maven.compiler.target>1.6</maven.compiler.target>

        <mainClass>com.reddipped.jsonlogger_2.Test</mainClass>

        <slf4j.version>1.7.21</slf4j.version>
        <!-- current log4j 2 release -->
        <log4j.version>2.6.2</log4j.version> 

     </properties>

     <dependencies>
        <dependency>
           <groupId>org.slf4j</groupId>
           <artifactId>slf4j-api</artifactId>
           <version>${slf4j.version}</version>
        </dependency>
        <!-- Binding for Log4J -->
        <dependency>
           <groupId>org.apache.logging.log4j</groupId>
           <artifactId>log4j-slf4j-impl</artifactId>
           <version>${log4j.version}</version>
        </dependency>
        <!-- Log4j API and Core implementation required for binding -->
        <dependency>
           <groupId>org.apache.logging.log4j</groupId>
           <artifactId>log4j-api</artifactId>
           <version>${log4j.version}</version>
        </dependency>
        <dependency>
           <groupId>org.apache.logging.log4j</groupId>
           <artifactId>log4j-core</artifactId>
           <version>${log4j.version}</version>
        </dependency>
        <!-- Logger slf4j-json-logger -->
        <dependency>
           <groupId>com.savoirtech.logging</groupId>
           <artifactId>slf4j-json-logger</artifactId>
           <version>2.0.2</version>
        </dependency>
     </dependencies> 
  </project>

log4j2.xml

  <?xml version="1.0" encoding="UTF-8"?>

  <!--

  Use java property log4j.configurationFile to specify log4j2.xml location
  if not available in classpath

  -    Dlog4j.configurationFile="/Users/petervannes/NetBeansProjects/JSONLogger_2/src/mann/java/resources/log4j2.xml"

  -->
  <configuration status="trace">
     <Properties>
        <Property name="log-path">/Users/petervannes/NetBeansProjects/JSONLogger_2/logfiles</Property>
     </Properties>
     <appenders>
        <RollingFile name="RollingFile" fileName="${log-path}/jsonlogger.json"
                  filePattern="${log-path}/%d{yyyyMMdd}_jsonlogger-%i.json" >
           <PatternLayout>
              <pattern>%m%n</pattern>
           </PatternLayout> 
           <Policies>
              <TimeBasedTriggeringPolicy />
              <SizeBasedTriggeringPolicy size="1 KB" />
           </Policies>
           <DefaultRolloverStrategy max="4"/>
        </RollingFile>
     </appenders>
     <Loggers>
        <Logger name="JSONLogger" level="debug" additivity="false">
           <AppenderRef ref="RollingFile" />
        </Logger>
        <Root level="debug">
           <AppenderRef ref="RollingFile" />
        </Root>
     </Loggers>
  </configuration>

Example Java code

  package com.reddipped.jsonlogger_2;

  import com.savoirtech.logging.slf4j.json.LoggerFactory;
  import java.util.HashMap;
  import java.util.Map;

  /**
   *
   * @author petervannes
   */
  public class Test {
      public static void main(String[] args) {   
        Test t = new Test() ;
     }


     public Test() {

        LoggerFactory.setIncludeLoggerName(false);
        LoggerFactory.setDateFormatString("yyyy-MM-dd HH:mm:ss.SSS");

         com.savoirtech.logging.slf4j.json.logger.Logger LOGGER =  LoggerFactory.getLogger("JSONLogger");

     Map<String, String> optionalFields = new HashMap();
     optionalFields.put("CaseNumber", "C12.12343");
     optionalFields.put("Step","Assignment") ;
     optionalFields.put("Department","BPM") ;

     String LOB = "Business Administration" ;
     String Service = "DocumentService" ;
     String Process = "AddAttachements" ;
     String Reason = "Technical" ; 

     LOGGER.error().message("Conversion error 'incompatible PDF document'")
           .field("LOB",LOB)
           .field("Service", Service)
           .field("Process",Process)
           .field("Reason", Reason)
           .map("OptionalFields", optionalFields).log() ;
     }

  }

JSON Log Entry

  {
    "message": "Conversion error  'incompatible PDF document'",
    "LOB": "Business Administration",
    "Service": "DocumentService",
    "Process": "AddAttachements",
    "Reason": "Technical",
    "OptionalFields": {
     "Step": "Assignment",
     "Department": "BPM",
     "CaseNumber": "C12.12343"
    },
    "level": "ERROR",
    "thread_name": "main",
    "class": "com.reddipped.jsonlogger_2.Test",
    "@timestamp": "2016-09-23 10:18:06.623"
  }

Kienan

Nice but i wish i could achieve this without sl4j. log4j2.8 still has support – Preference

You can, i had to search for an alternative path because slF4j was interferring. – Kienan

Well in my comment I mean to say log4j 2.8 still does not have json logs support. It prints in json format but not the message I add. – Preference

I had the same requirement, so I built a small plugin for Log4j2 called "extended-jsonlayout". You can find it here - github.com/savantly-net/log4j2-extended-jsonlayout – Ubald

@Kienan Is there a way to remove the "class", "thread_name" and "@timestamp" attributes from the JSON output? – Prothrombin

Answer 5

It is possible using MapMessage, FormattedMessage (or ParameterizedMessage if you only use {} placeholders and want a better performance) and Map Resolver Template.

1. Define a helper method to build log message:

public static MapMessage buildMessage(
        final String message,
        final Object messageArgument,
        final String supplementalDataKey,
        final String supplementalDataValue) {
    return new MapMessage<>(Map.of(
        "message", new FormattedMessage(message, messageArgument),
        supplementalDataKey, supplementalDataValue));
}

2. Use it with logger:

LOGGER.log(
    Level.FATAL, 
    buildMessage(
        "Message: {}", "argumentValue",
        "SupplementalDataKey", "SupplementalDataValue");

3. Define template:

{
  ...
  "message": {
    "$resolver": "map",
    "key": "message",
    "stringified": true
  },
  "SupplementalData": {
    "SupplementalDataKey": {
      "$resolver": "map",
      "key": "SupplementalDataKey"
    }
  },
  ...
}

As you can see, the trick here is to redefine message in the template as part of the MessageMap, and then include supplemental data field.

Dorie

You should use ParameterizeMessage instead of FormattedMessage, since the latter supports multiple formatter and is therefore less performant. You are also missing a Level parameter in your Logger#log call. – Borries

BTW: your answer is a nice solution to apache/logging-log4j2#1813. – Borries

Thank you @PiotrP.Karwasz - I've addressed your comments in the latest edit. – Dorie