Search code examples
logginglog4j2slf4j

slf4j marker when used with fluent apis is ignored by log4j2 configuration, but works fine with non-fluent apis


slf4j marker when used with LoggingEventBuilder apis (fluent) is ignored by log4j2 configuration, but when same marker is used with slf4j Logger non-fluent apis [e.g., trace(Marker marker, String msg)], it works fine with log4j2 filter configuration.

For example, I'm using following (log4j2) filter configuration.

NoMarkerFilter:
     onMatch: deny
     onMismatch: accept

Now, if I use non-fluent traditional apis to log events with markers, those events are accepted, and I can see those in log outputs.

But, when using LoggingEventBuilder fluent apis to log events with markers, log4j2 filter configuration ignores the markers. Same is the issue while using log4j2 MarkerFilter.

private static final Marker marker = MarkerFactory.getMarker("TESTMARKER");
log.trace(marker, "This is logged using traditional api"); //accepted and shown in output
log.atTrace().addMarker(marker).log("This is logged using fluent api"); //denied, and NOT showing in output

I checked slf4j and log4j2 documentations, and also googled around to find if log4j2 still doesn't support marker when used with fluent apis in slf4j, but couldn't find any such reference.

I've used lombok plugin alongwith log4j-core and log4j-slf4j2-impl dependencies

...
id "io.freefair.lombok" version "6.6.1"
...
implementation 'org.apache.logging.log4j:log4j-core:2.19.0'
implementation 'org.apache.logging.log4j:log4j-slf4j2-impl:2.19.0'

Expectation: slf4j marker used with fluent apis should work with log4j2 filter configuration, and shouldn't be ignored.


Solution

  • The default behavior of atTrace() in SLF4J (and until recently the Log4j2 API too) is to return a no-op LoggingEventBuilder (NopLoggingEventBuilder) if the message is less specific than TRACE. That's why messages with markers are not being logged.

    I agree with you the this is a bug. Currently:

    • for the Log4j2 API this has been fixed in version 2.20.0 (cf. LOG4J2-3647) (for both Log4j2 Core and Logback backends),
    • I logged a similar issue for Logback's SLF4J binding a month ago (LOGBACK-1719),
    • I didn't notice that the SLF4j-to-Log4j2 API bridge was affected too ("the mote that is in thy brother's eye..."). I have reported it as GH issue #1287, thanks for noticing.

    There are two workarounds you can use:

    1. Use Log4j2 API instead of SLF4J. Log4j2 API is basically a superset of SLF4J (cf. Log4j2 API Logger and SLF4J Logger) and except a package change it is mostly source compatible with SLF4J.

      Using the Log4j2 API, a call to atTrace() will return a real log builder if you use global filters and a no-op log builder if you don't (for improved performance, cf. the benchmarks in GH PR #1203).

    2. You can keep using SLF4J, but you need to replace:

      log.atTrace().addMarker(marker).log("This is logged using fluent api");
      

      with

      log.makeLoggingEventBuilder(Level.TRACE)
         .addMarker(marker)
         .log("This is logged using fluent api");
      

      (cf. SLF4J-560). This solution will incur in a performance penalty for disabled loggers (whether you use global filters or not) and will always create a temporary object (that need to be GC-ed).