Logging

Overview

Logging is a core aspect of every application. The recommended approach to logging is structured logging.

To have have efficient and structured logging, your application needs to log to files. (The console is not ideal for structured data due to various libraries, including JVM using it for messages in various formats…) One good approach is to log to avro binary files compressed with snappy. An additional benefit is that you can leverage your hadoop stack to analyze your logs. The log record schema is described at

Let’s look at how logging structured data is done in detail:

• Let’s call the demo app endpoint with debug logging on:

curl -X POST "https://demo.spf4j.org/avql/query" -H "accept: application/json" -H "log-level: DEBUG" -H "Content-Type: text/plain" -d "select * from planets"

• And take a look at logs:

{
  "origin": "jaxrs-spf4j-demo-5f846dbdc8-nmg2k:/var/log/jaxrs-spf4j-demo-5f846dbdc8-nmg2k_2020-02-08.avro:7622",
  "trId": "XNm4uQJip.1.12uqj7.m0l",
  "level": "INFO",
  "ts": "2020-02-08T12:28:22.848Z",
  "logger": "org.spf4j.demo.resources.aql.PlanetsResourceImpl->getData",
  "thr": "http:8080-worker-2",
  "msg": "returning",
  "xtra": [[
    {
    "name": "earth",
    "planetClass": "M",
    "age": 512731872312,
    "description": ""
    },
    {
    "name": "vulcan",
    "planetClass": "M",
    "age": 612731872312,
    "description": ""
    },
    {
    "name": "andoria",
    "planetClass": "M",
    "age": 602731872312,
    "description": ""
    }
  ]],
  "attrs": {
  "origLevel": "DEBUG"
  }
},

• Let’s look at the code that logs the above:

  import org.spf4j.log.ExecContextLogger;
  import org.slf4j.Logger;
  import org.slf4j.LoggerFactory;
  ...
  log = new ExecContextLogger(LoggerFactory.getLogger("org.spf4j.demo.resources.aql.PlanetsResourceImpl->getData"));
  ...
  log.debug("returning", result);

• The wrapping of the slf4j logger with ExecContextLogger allows us to enable debug logging at request level (-H “log-level: DEBUG”).

• In the log.debug statement, the result object is not part of he message format as such instead of being dropped by logback (by default), it is logged in json format. Any parameter that is not an argument for the message format will be logged in json format. This is implemented using Slf4jMessageFormatter.java and the and appender from.

Components