Logback-classic 1.4.5 emits replayed events at the TRACE level

[prdoyle]

When I run my junit tests (in gradle, using ./gradlew test), I see this message, followed by thousands of log messages at the TRACE level:

SLF4J: A number (20761) of logging calls during the initialization phase have been intercepted and are
SLF4J: now being replayed. These are subject to the filtering rules of the underlying logging system.

However, contrary to what this says, these events do not, in fact, seem to be subject to the filtering rules. I've written a logback-test.xml configured as follows, which should be ignoring all TRACE events, and this same configuration worked as expected in logback-classic 1.2.11.

<configuration>
        <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
                <encoder>
                        <pattern>%d %-5level [%thread] %logger{25}: %msg%n</pattern>
                </encoder>
                <immediateFlush>true</immediateFlush>
        </appender>
        <root level="WARN">
                <appender-ref ref="CONSOLE" />
        </root>
</configuration>

I've confirmed that this file is indeed getting picked up by inserting a tag called <nonexistent/> and verifying that Logback warns about the unrecognized tag.

Has anyone else experienced this? What's the right way to configure this so I only get messages at WARN and above during my junit tests?

[prdoyle]

Update: if I add a recognizable prefix to the pattern tag, I am seeing that in the TRACE-level statements. This means the appender configuration is active, but the root tag doesn't seem to be working. 🤔

[prdoyle]

Update: if I change the root logger to specify <appender-ref ref="NONEXISTENT" /> then the logs all disappear. This means the root tag (and its appender-ref tag) are both being processed.

Only the log level seems to be ignored.

[ceki]

Hi @prdoyle,

The implementation of the Logger.log(LoggingEvent) method changed between logback versions 1.2 and 1.3/1.4. The latter method implementation assumes that when the system invoked, there was a prior decision made for logging (with no further filtering) whereas the prior implementation assumes that some further filtering is required.

Can you create a issue regarding this in the SLF4J project in our jira?

[prdoyle]

Sure! Thanks for the reply!

[prdoyle]

Ticket is here.