We're using SLF4J in combination with Logback in several Spring (Boot) applications and recently started using the logstash-logback-encoder to implement structured logging. As we also still have to support plain text logs, we wondered whether it was possible to append arguments automatically to log messages without having to add them manually to the message using the {}
markers.
To illustrate the desired behaviour this is what we'd wish for:
log.info("My message", kv("arg1", "firstArgument"), kv("arg2", "secondArgument"))
resulting in the following desired output, where the arguments are automatically appended in parentheses at the end of the message:
My message (arg1="firstArgument", arg2="secondArgument")
Or another example with both explicit arguments in the message and arguments at the end:
log.info("Status changed: {} => {}", v("from", "READY"), v("to", "UNAVAILABLE"), kv("service", "database"))
resulting in the following desired output:
Status changed: READY => UNAVAILABLE (from="READY", to="UNAVAILABLE", service="database")
Is this possible with SLF4J/Logback? And if not, do you know other logging frameworks or ways to achieve this (in Java)?
I'm not aware of any log frameworks that let you do this, but you can trivially write your own. Because this really is just a simple API extension, and thus, all you need to duplicate is specifically the various log
messages. For example, this one-liner would take care of it:
public static class LoggingExtensions {
@lombok.Value public static final class LogKeyValue {
String key, value;
}
public static LogKeyValue kv(String key, Object value) {
return new LogKeyValue(key, String.valueOf(value));
}
public static void info(Logger log, String message, Object... args) {
int extra = 0;
int len = args.length;
// Last arg could be a throwable, leave that alone.
if (len > 0 && args[len - 1] instanceof Throwable) len--;
for (int i = len - 1; i >= 0; i--) {
if (!(args[i] instanceof LogKeyValue)) break;
extra++;
}
if (extra > 0) {
StringBuilder sb = new StringBuilder(message.length() + 2 + (extra.size() - 1) * 2);
sb.append(message).append("({}");
for (int i = 1; i < extra; i++) sb.append(", {}");
message = sb.append(")").toString();
}
log.info(message, args);
}
}
This code tacks ({}, {} {})
at the end of the message, 1 for each 'kv' type. Note that most logging frameworks, including slf4j, do let you tack 1 exception at the end, even without a matching {}
in the message, and this method would thus require that you first list all {}
args, then any kv
args, then 0 or 1 throwables.
Some caveats, though:
return;
immediately. You can then also follow along and create this 'explosion'. See slf4j which has 10 methods for every log level, and many other frameworks have even more (they have a variant for 1, 2, 3, and sometimes even 4 arguments before resorting to varargs).