Print stacktrace with Log4j2 in JSON with JSONLayout in a single line

Question

I'm tryting to configure JsonLayaout with Log4j2. I would like to have the stacktrace in just one message in the JSON. I understand that I have to use the attribute "complete".

The example class that I have created is:

public class MyApp {

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

    public static void main(final String... args) {   
        logger.debug("Entering application.");

        try{
            int i = 0;
            int a = 5 / i;
        }catch(Exception e){
            //StringWriter sw = new StringWriter();
            //e.printStackTrace(new PrintWriter(sw));
            //String exceptionAsString = sw.toString();    
            logger.error(exceptionAsString);
        }
    }
}

The the log4j2.properties is:

name=PropertiesConfig
property.filename = logs
appenders = file, console
appender.console.type = Console
appender.console.name = STDOUT
appender.console.layout.type = JSONLayout
appender.console.layout.complete="false"
#appender.console.layout.compact = true
#appender.console.layout.pattern = [%-5level] %d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %c{1} - %msg%n
appender.file.type = File
appender.file.name = LOGFILE
appender.file.fileName=/var/tmp/propertieslogs.log
appender.file.layout.type=JSONLayout
appender.file.layout.complete="true"
#appender.file.layout.pattern=[%-5level] %d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %c{1} - %msg%n

rootLogger.level = debug
rootLogger.appenderRefs = stdout, logfile
rootLogger.appenderRef.stdout.ref = STDOUT
rootLogger.appenderRef.logfile.ref = LOGFILE

The output I'd like it:

[
  {
    "logger":"com.foo.Bar",
    "timestamp":"1376681196470",
    "level":"INFO",
    "threadId":1,
    "thread":"main",
    "threadPriority":1,
    "message":"Message flushed with immediate flush=true"
  },
  {
    "logger":"com.foo.Bar",
    "timestamp":"1376681196471",
    "level":"ERROR",
    "threadId":1,
    "thread":"main",
    "threadPriority":1,
    "message":"Message flushed with immediate flush=true",
    "throwable":"java.lang.IllegalArgumentException: badarg\\n\\tat org.apache.logging.log4j.core.appender.JSONCompleteFileAppenderTest.testFlushAtEndOfBatch(JSONCompleteFileAppenderTest.java:54)\\n\\tat sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)\\n\\tat sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)\\n\\tat sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)\\n\\tat java.lang.reflect.Method.invoke(Method.java:606)\\n\\tat org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)\\n\\tat org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)\\n\\tat org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)\\n\\tat org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)\\n\\tat org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271)\\n\\tat org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)\\n\\tat org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)\\n\\tat org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)\\n\\tat org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)\\n\\tat org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)\\n\\tat org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)\\n\\tat org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)\\n\\tat org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)\\n\\tat org.junit.runners.ParentRunner.run(ParentRunner.java:309)\\n\\tat org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50)\\n\\tat org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)\\n\\tat org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467)\\n\\tat org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683)\\n\\tat org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390)\\n\\tat org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197)\\n"
  }
]

But I get:

{
  "timeMillis" : 1474362834903,
  "thread" : "main",
  "level" : "ERROR",
  "loggerName" : "test.MyApp",
  "message" : "Exception:",
  "thrown" : {
    "commonElementCount" : 0,
    "localizedMessage" : "/ by zero",
    "message" : "/ by zero",
    "name" : "java.lang.ArithmeticException",
    "extendedStackTrace" : [ {
      "class" : "test.MyApp",
      "method" : "main",
      "file" : "MyApp.java",
      "line" : 24,
      "exact" : true,
      "location" : "classes/",
      "version" : "?"
    }, {
      "class" : "sun.reflect.NativeMethodAccessorImpl",
      "method" : "invoke0",
      "file" : "NativeMethodAccessorImpl.java",
      "line" : -2,
      "exact" : false,
      "location" : "?",
      "version" : "1.8.0_91"
    }, {
      "class" : "sun.reflect.NativeMethodAccessorImpl",
      "method" : "invoke",
      "file" : "NativeMethodAccessorImpl.java",
      "line" : 62,
      "exact" : false,
      "location" : "?",
      "version" : "1.8.0_91"
    }, {
      "class" : "sun.reflect.DelegatingMethodAccessorImpl",
      "method" : "invoke",
      "file" : "DelegatingMethodAccessorImpl.java",
      "line" : 43,
      "exact" : false,
      "location" : "?",
      "version" : "1.8.0_91"
    }, {
      "class" : "java.lang.reflect.Method",
      "method" : "invoke",
      "file" : "Method.java",
      "line" : 498,
      "exact" : false,
      "location" : "?",
      "version" : "1.8.0_91"
    }, {
      "class" : "com.intellij.rt.execution.application.AppMain",
      "method" : "main",
      "file" : "AppMain.java",
      "line" : 147,
      "exact" : true,
      "location" : "idea_rt.jar",
      "version" : "?"
    } ]
  },
  "endOfBatch" : false,
  "loggerFqcn" : "org.apache.logging.log4j.spi.AbstractLogger",
  "threadId" : 1,
  "threadPriority" : 5
}

Should I build an String to the message as I do in the code or how could I complete the throwable attribute in the log with all the stacktrace?

If I use this code:

   public static void main(final String... args) {

        // Set up a simple configuration that logs on the console.
        logger.debug("Entering application.");

        try{
            int i = 0;
            int a = 5 / i;
        }catch(Exception e){
            StringWriter sw = new StringWriter();
            e.printStackTrace(new PrintWriter(sw));
            String exceptionAsString = sw.toString();

            logger.error(exceptionAsString);
        }
    }
}

I get almost which I want to:

{
  "timeMillis" : 1474542115319,
  "thread" : "main",
  "level" : "DEBUG",
  "loggerName" : "MyApp",
  "message" : "Entering application.",
  "endOfBatch" : false,
  "loggerFqcn" : "org.apache.logging.log4j.spi.AbstractLogger",
  "contextMap" : [ ]
}{
  "timeMillis" : 1474542115573,
  "thread" : "main",
  "level" : "ERROR",
  "loggerName" : "MyApp",
  "message" : "java.lang.ArithmeticException: / by zero\n\tat MyApp.main(MyApp.java:23)\n\tat sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)\n\tat sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)\n\tat sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)\n\tat java.lang.reflect.Method.invoke(Method.java:498)\n\tat com.intellij.rt.execution.application.AppMain.main(AppMain.java:147)\n",
  "endOfBatch" : false,
  "loggerFqcn" : "org.apache.logging.log4j.spi.AbstractLogger",
  "contextMap" : [ ]
}

But, I guess that I could do it automatically without parse the stacktrace to String.

Euphemiah

Answer 1

<JsonLayout compact="true" eventEol="true" stacktraceAsString="true" >

This will help.

Wholesale

It didn't. I am not seeing stack traces with this :< – Banditry

Hi , using log4j 2.9.0 version and above will show stacktrace as a single line . suspect there was a bug on stacktraceAsString flag , on 2.5 version indeed setting stacktraceAsString=true not works . – Brigitta

Answer 2

I solved this using a custom Log4j layout:

@Plugin(name = "FlatJsonLayout", category = "Core", elementType = "layout", printObject = true)
public class FlatJsonLayout extends AbstractStringLayout {
    private final ObjectMapper objectMapper;

    FlatJsonLayout(Charset charset) {
        super(charset);
        SimpleModule module = new SimpleModule();
        module.addSerializer(LogEvent.class, new LogEventSerializer());
        module.addSerializer(Throwable.class, new ThrowableSerializer());
        module.addSerializer(ReadOnlyStringMap.class, new ContextDataSerializer() {
        });
        objectMapper = new ObjectMapper();
        objectMapper.registerModule(module);
        objectMapper.setSerializationInclusion(JsonInclude.Include.NON_EMPTY);
    }

    @Override
    public String toSerializable(LogEvent logEvent) {
        try {
            return objectMapper.writeValueAsString(logEvent);
        } catch (JsonProcessingException e) {
            throw new IllegalStateException(e);
        }
    }

    private static class LogEventSerializer extends StdSerializer<LogEvent> {
        LogEventSerializer() {
            super(LogEvent.class);
        }

        @Override
        public void serialize(LogEvent value, JsonGenerator gen, SerializerProvider provider) throws IOException {
            gen.writeStartObject();
            gen.writeNumberField("timeMillis", value.getTimeMillis());
            gen.writeStringField("threadName", value.getThreadName());
            gen.writeStringField("level", value.getLevel().name());
            gen.writeStringField("loggerName", value.getLoggerName());
            gen.writeObjectField("marker", value.getMarker());
            gen.writeObjectField("message", value.getMessage().getFormattedMessage());
            gen.writeObjectField("thrown", value.getThrown());
            gen.writeObjectField("ContextMap", value.getContextData());
            gen.writeObjectField("ContextStack", value.getContextStack());
            gen.writeStringField("loggerFQCN", value.getLoggerFqcn());
            gen.writeObjectField("Source", value.getSource());
            gen.writeBooleanField("endOfBatch", value.isEndOfBatch());
            gen.writeEndObject();
        }
    }

    private static class ThrowableSerializer extends StdSerializer<Throwable> {
        ThrowableSerializer() {
            super(Throwable.class);
        }

        @Override
        public void serialize(Throwable value, JsonGenerator gen, SerializerProvider provider) throws IOException {
            try (StringWriter stringWriter = new StringWriter()) {
                try (PrintWriter printWriter = new PrintWriter(stringWriter)) {
                    value.printStackTrace(printWriter);
                    gen.writeString(stringWriter.toString());
                }
            } catch (IOException e) {
                throw new IllegalStateException(e);
            }
        }
    }

    @PluginBuilderFactory
    public static <B extends Builder<B>> B newBuilder() {
        return new Builder<B>().asBuilder();
    }

    public static class Builder<B extends Builder<B>> extends org.apache.logging.log4j.core.layout.AbstractStringLayout.Builder<B> implements org.apache.logging.log4j.core.util.Builder<FlatJsonLayout> {
        Builder() {
            this.setCharset(StandardCharsets.UTF_8);
        }

        public FlatJsonLayout build() {
            return new FlatJsonLayout(this.getCharset());
        }
    }
}

The class has to be on the classpath of the application. It can then be configured in the log4j2.xml like this:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="info">
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <FlatJsonLayout/>
        </Console>
    </Appenders>
    <Loggers>
        <Root level="info">
            <AppenderRef ref="Console"/>
        </Root>
    </Loggers>
</Configuration>

Capitation

can you share which log4j version is in used ? – Brigitta

We are using version 2.13.3, but I believe this should work with any version >= 2.0.0 – Capitation

Answer 3

set compact="true" and eventEol="true" works for me

 <JsonLayout complete="false" compact="true" eventEol="true">

Backlash

Answer 4

On properties files appender.console.layout.complete is boolean not string so change:

appender.console.layout.complete="false"

to:

appender.console.layout.complete = false

Prolactin

Answer 5

using today - log4j version 2.9.0 or above will print stacktrace as single line when setting stacktraceAsString="true"

Brigitta