Echopraxia, a Better Java Logging API

TL;DR: I pushed the 1.0.0 artifacts for Echopraxia, and here's a Spring Boot Example. Echopraxia is a Java logging API like SLF4J, but built around structured logging, i.e. the basic log entry is a JSON object and log files are typically NDJSON. It also has conditions, context, and also has semantic and fluent logging options.

Echopraxia is a sequel to the Scala logging API Blindsight, hence the name: "Echopraxia is the involuntary repetition or imitation of an observed action." It has a number of the same concepts involved, notably adding conditions and context to loggers, and a bias towards structured logging, pushing for arguments as fields and values corresponding to JSON.

I'm going to write about developing this library, since it's still fresh in my mind and I think I learned some things. I did this last time with Blindsight, comparing it to other logging libraries, so here I'm just going to compare it to Blindsight.

Some people will read this and ask "better than what?" Do I think Echopraxia is better than SLF4J? Yes. Do I think it's better than Log4J2's API? Yes. That's not a criticism – both of those libraries came out well before structured logging was a thing, and so we should be able to build something better with the knowledge and tools we have.

Do I think it's better than Maple or shax or structured-logging? Well… yes in the sense that Echopraxia has more features, but it's a closer race. And there are optimized logging libraries like beautiful_logger and zerolog that fit into their own category, and the OG logging library remains Bunyan.

Echopraxia is not intended as a replacement for SLF4J. Because it's a structured logging library with a limited number of implementations, it's an appropriate solution when you control the logging output and have decided you're going to do structured logging in your application. Echopraxia should not be used in publicly available libraries; if your library is being used in someone else's application, they have control over the logging output, not you.

Where Echopraxia really works is when you're building framework support code for your application – as you build up your domain objects, you can write custom field builders and make those available through your team, then log everything with a consistent schema. I think this works particularly well when you're adding diagnostic logging, because you can get "debugger-lite" output from your internal state in an application running somewhere in a datacenter. It goes a long way to debugging and observing your code in production.

The biggest feature of Echopraxia is that it's Java. I love Scala as a programming language, but I know that many programmers don't have the option to use Scala as their primary programming language, and the feature set itself is not completely dependent on Scala's features. (Unless you count flow logging, which does not look pretty in Java.) So, I took the time in December to sit down and rework the feature set into ideomatic Java.

The second biggest feature of Echopraxia is the argument API. In Blindsight, arguments and markers are handled through a DSL or type classes. In Echopraxia, the approach is philosophically similar but different in implementation. Echopraxia does not accept Object, and there's no arg1/arg2 or varadic array passed in. Instead, logging arguments is done with a field builder owned by the Logger.

public void debug(String message, Field.BuilderFunction<FB> f);

This means that a field builder fb is passed in, and is used to create a single field with name name and value small mammal:

logger.info("Hello {}", fb -> singletonList(fb.string("name", "small mammal")));

The list of fields is passed through to a "core logger" that is provided by service loader pattern. The core logger is responsible for converting that list of fields into some kind of structured JSON. The logstash implementation converts fields to StructuredArguments.

The key feature here is that you aren't stuck with the tedium of breaking down your domain objects into digestible fields. Instead, you can define your own custom field builder on the Logger and work at the domain level. For example, you can create HttpRequestFieldBuilder with a requestFields method and then just pass in the HTTP request:

private final Logger<HttpRequestFieldBuilder> logger =
  LoggerFactory.getLogger(getClass())
    .withFieldBuilder(HttpRequestFieldBuilder.class)
    .withFields(
      fb -> {
        HttpServletRequest request =
          ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes())
            .getRequest();
        return fb.requestFields(request);
});

This also brings in the idea of context. In Echopraxia, you can define fields that will always be logged, even if they're not passed in as arguments. Here, every logging call will log fields from the request when using that logger. In Blindsight, contextual logging was done using withMarker – Echopraxia only allows fields, and does not depend on the SLF4J API at all.

Conditional logging in Echopraxia is likewise similar to Blindsight's conditional logging. In Blindsight, markers are exposed to a condition. In Echopraxia, a context which has fields is exposed, so a query for a creation_date field would look like this:

Condition creationDateCondition =
  (level, context) ->
    context.getFields()
    .stream()
    .anyMatch(field -> field.name().equals("creation_date"));

Applying conditions is also a bit different. Although logger.withCondition and logger.is*Enabled(condition) are the same, in Blindsight a Method is an object, so you can do logger.debug.when(condition). Rather than when, Echopraxia just uses overloaded methods that take a condition as the first arguments:

Condition condition = ...
logger.debug(condition, "some message");

Likewise, Blindsight has scripting but has a "scripting aware logger" that leverages the sourcecode macros to be able to do scripting based off line number and method. This was super cool magic, but it had no place in Echopraxia. However, scripting in Echopraxia, because we are working with fields directly, has some advantages!

The scripting language in both cases is Tweakflow, but

import strings as s from 'std.tf';
alias s.ends_with? as ends_with?;

library blindsight {
  function evaluate: (long level, string enc, long line, string file) ->
    if (ends_with?(enc, "main")) then true
    else false;
}

See what's passed in: the level, enclosing text, the line, and the file name. No facility for conditions. This is even more bizarre considering that the blog post explicitly shows script conditions as the main use case. I'd like to say this was inexpliciable, but I know how this happened – my brain did a cool thing, was onto the next cool thing, and forgot to put "cool thing a" into "cool thing b". I created a blindsight-scripting example Github project, but never folded it into the actual project.

In Echopraxia scripts, the level and a dictionary of fields are passed in, and script conditions are easy. For example, you can decide to trace only requests that match up to a given IP address range, and change that on the fly.

import * as std from "std";
alias std.strings as str;

library echopraxia {
  function evaluate: (string level, dict fields) ->
    str.starts_with?(fields[:request_remote_addr], "127");
}

I am still very big on the possibilities of better targeted logging through dynamic scripting, but that's another blog post.

Finally, there's semantic logging and fluent logging.

Fluent Logging in Echopraxia is mostly the same as in Blindsight – the main difference is that there's no markers option, message replaces rather than concatenates, and arguments are done using a modified field builder that returns a single field.

Semantic logging, also known as "strongly typed" logging, was a bit more complex to work out. In Blindsight, semantic logging was implemented with ToStatement implicits. In Echopraxia, semantic logging is done by ensuring the factory has all the functions it needs to do the work:

import com.tersesystems.echopraxia.semantic.*;

SemanticLogger<Person> logger =
    SemanticLoggerFactory.getLogger(
        getClass(),
        Person.class,
        person -> "person.name = {}, person.age = {}",
        p -> b -> Arrays.asList(b.string("name", p.name), b.number("age", p.age)));

Person person = new Person("Eloise", 1);
logger.info(person)

I really like that it's possible to semantic logging by having a Person => FieldBuilder rendered. I'm a bit sad that I had to hide the field builder type, but I think that no-one really wants to see SemanticLogger<Person, SomeFieldBuilder> on a logger, and I think it's reasonable to expect it not to change after creation.

Finally, after removing the SLF4J from Echopraxia, there needs to be an escape hatch for when you really do need to add a marker. This comes down to the core logger, which you can cast for implementation specific methods, and then all the factories will take a core logger as input.

LogstashCoreLogger core = (LogstashCoreLogger) CoreLoggerFactory.getLogger(getClass());
CoreLogger coreWithMarker = core.withMarkers(MarkerFactory.getMarker("SECURITY"));
Logger<?> logger = LoggerFactory.getLogger(coreWithMarker, Field.Builder.instance);

Likewise, the context can be cast to an implementation if you need something special:

Condition hasAnyMarkers = (level, context) -> {
   LogstashLoggingContext c = (LogstashLoggingContext) context;
   List<org.slf4j.Marker> markers = c.getMarkers();
   return markers.size() > 0;
};

That about wraps it up! One of the things possible with Echopraxia is that it does map onto other logging APIs besides SLF4J, so it can work with Log4J2 API or JUL, or even directly – all you need to do is swap out the core logger. I am still working on a Log4J2 implementation of Echopraxia, but I don't get how to use a custom JSON template to render fields in the top level JSON object – if someone has experience with structured logging and Log4J please reach out.