1

I created a class to log requests (and responses) received by a JEE7 REST API.

The class uses SLF4J and logback to construct a log event in JSON format such as

{
   "timestamp" : "2019-05-14 11:46:40.419",
   "level" : "INFO",
   "thread" : "default task-5",
   "mdc" : {
     "request.headers.Connection" : "keep-alive",
     "request.headers.Accept" : "*/*",
     "request.requestUri" : "http://localhost:8080/play/v1.0/map",
     "request.headers.User-Agent" : "PostmanRuntime/7.11.0",
     "request.headers.Cache-Control" : "no-cache",
     "request.method" : "GET",
     "request.headers.accept-encoding" : "gzip, deflate",
     "request.headers.Host" : "localhost:8080",
     "request.headers.Postman-Token" : "e03c8d8b-ebea-475c-bfaf-0ff8d4646081",
     "response.status" : "200",
     "message" : "200 GET /play/v1.0/map"
   },
   "logger" : "javax.ws.rs.container.ContainerRequestFilter",
   "message" : "you",
   "context" : "default"
 }

The problem is that WildFly prepends its own information to the logs, so current result looks like this:

11:46:40,420 INFO  [stdout] (default task-5) {
11:46:40,420 INFO  [stdout] (default task-5)   "timestamp" : "2019-05-14 11:46:40.419",
11:46:40,420 INFO  [stdout] (default task-5)   "level" : "INFO",
11:46:40,420 INFO  [stdout] (default task-5)   "thread" : "default task-5",
11:46:40,420 INFO  [stdout] (default task-5)   "mdc" : {
11:46:40,420 INFO  [stdout] (default task-5)     "request.headers.Connection" : "keep-alive",
11:46:40,421 INFO  [stdout] (default task-5)     "request.headers.Accept" : "*/*",
11:46:40,421 INFO  [stdout] (default task-5)     "request.requestUri" : "http://localhost:8080/play/v1.0/map",
11:46:40,421 INFO  [stdout] (default task-5)     "request.headers.User-Agent" : "PostmanRuntime/7.11.0",
11:46:40,421 INFO  [stdout] (default task-5)     "request.headers.Cache-Control" : "no-cache",
11:46:40,421 INFO  [stdout] (default task-5)     "request.method" : "GET",
11:46:40,421 INFO  [stdout] (default task-5)     "request.headers.accept-encoding" : "gzip, deflate",
11:46:40,421 INFO  [stdout] (default task-5)     "request.headers.Host" : "localhost:8080",
11:46:40,421 INFO  [stdout] (default task-5)     "request.headers.Postman-Token" : "e03c8d8b-ebea-475c-bfaf-0ff8d4646081",
11:46:40,421 INFO  [stdout] (default task-5)     "response.status" : "200",
11:46:40,421 INFO  [stdout] (default task-5)     "message" : "200 GET /play/v1.0/map"
11:46:40,421 INFO  [stdout] (default task-5)   },
11:46:40,421 INFO  [stdout] (default task-5)   "logger" : "javax.ws.rs.container.ContainerRequestFilter",
11:46:40,421 INFO  [stdout] (default task-5)   "message" : "you",
11:46:40,421 INFO  [stdout] (default task-5)   "context" : "default"
11:46:40,422 INFO  [stdout] (default task-5) }

I want my log file to contain only JSON object, one per line (above examples are pretty-printed for clarity)

WildFly's logging configuration documentation is not clear on how to achieve this.

Can someone help me?

EDIT 1

logback.xml

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

<configuration scan="true">
    <contextName>/psp/v1.0</contextName>

    <!-- ADD jboss-deployment-structure.xml -->
    <!-- WildFly adds slf4j as a default logging dependency. To avoid this exclude the main implementation in jboss-deployment-structure.xml descriptor -->

    <!-- don't log logback startup info -->
    <statusListener class="ch.qos.logback.core.status.NopStatusListener"/>

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <layout class="ch.qos.logback.contrib.json.classic.JsonLayout">
            <jsonFormatter
                    class="ch.qos.logback.contrib.jackson.JacksonJsonFormatter">
                <prettyPrint>false</prettyPrint>
            </jsonFormatter>
            <timestampFormat>yyyy-MM-dd' 'HH:mm:ss.SSS</timestampFormat>
            <appendLineSeparator>true</appendLineSeparator>
        </layout>
    </appender>

    <root level="info">
        <appender-ref ref="STDOUT"/>
    </root>
</configuration>
Cec
  • 1,726
  • 3
  • 18
  • 31
  • 1
    You could use a file appender rather than your STDOUT console appender, so that logback writes directly to his own log file rather than to the stdout that jboss intercepts – Aaron May 14 '19 at 13:46
  • Hi @Aaron I'm thinking about going in this direction, but at the moment we have one logback.xml per deployment and I'm guessing that having multiple "logback instances" logging onto the same file might be problematic. So either each deployment logs to its own file, or we need to create a WF module to log with logback (I'm following http://loctranhoang.blogspot.com/2017/08/slf4j-with-logback-in-wildfly10.html). Do you believe I'm overthinking this? – Cec May 14 '19 at 14:14
  • 1
    [This answer](https://stackoverflow.com/a/11949903/1678362) agrees that you shouldn't share log files with multiple FileAppenders. [This answer](https://stackoverflow.com/a/37194565/1678362) describes how to set up a console-handler in Wildfly's configuration that will simply output the messages it receives – Aaron May 14 '19 at 14:59
  • I'm not sure how you'd deal with part of the data being JSON and part of the data not being JSON. Using file or files seems like a better approach IMO. – James R. Perkins May 16 '19 at 00:34

1 Answers1

0

If you are using logback as a logging backend, then you can configure it with a json appender.

You will need to add these dependencies to your pom.xml:

<dependencies>
    <dependency>
        <groupId>ch.qos.logback</groupId>
        <artifactId>logback-classic</artifactId>
        <version>1.1.7</version>
    </dependency>

    <dependency>
        <groupId>ch.qos.logback.contrib</groupId>
        <artifactId>logback-json-classic</artifactId>
        <version>0.1.5</version>
    </dependency>

    <dependency>
        <groupId>ch.qos.logback.contrib</groupId>
        <artifactId>logback-jackson</artifactId>
        <version>0.1.5</version>
    </dependency>

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

And then, you can add the appender to logback (logback.xml) as follows:

<appender name="json" class="ch.qos.logback.core.ConsoleAppender">
    <layout class="ch.qos.logback.contrib.json.classic.JsonLayout">
        <jsonFormatter
            class="ch.qos.logback.contrib.jackson.JacksonJsonFormatter">
            <prettyPrint>true</prettyPrint>
        </jsonFormatter>
        <timestampFormat>yyyy-MM-dd' 'HH:mm:ss.SSS</timestampFormat>
    </layout>
</appender>

<logger name="jsonLogger" level="TRACE">
    <appender-ref ref="json" />
</logger>
Hichem BOUSSETTA
  • 1,791
  • 1
  • 21
  • 27