Two loggers referencing same file appender, one writes the other does not

user_1373232 0
Viewed 212

Given the following logback xml config:

<appender name="APPLICATION" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <File>${log.dir}/app-traffic</File>
        <encoder>
            <pattern>%message%n</pattern>
        </encoder>
        <rollingPolicy class="org.app.traffic.policy.AppTimeBasedRollingPolicy">
            <FileNamePattern>${log.dir.archived}/app-traffic.%d{yyyyMMdd}</FileNamePattern>
        </rollingPolicy>
    </appender>

    <logger name="org.my.package.FirstClass" additivity="false">
        <level value="INFO"/>
        <appender-ref ref="APPLICATION"/>
    </logger>
    <logger name="org.my.different.package.SecondClass" additivity="false">
        <level value="INFO"/>
        <appender-ref ref="APPLICATION"/>
    </logger>

The FirstClass does not write to the app-trafic log, even though I see it triggers it's info() method while debugging. The SecondClass logger writes to the log successfully.

How can this be?

EDIT: Debugging the first logger info call shows it is getting filtered as only WARN messages are allowed? No idea why this since both configs are for INFO

logback logging
2 Answers

I would suggest enabling debugging output from logback itself, using the flag

-Dlogback.debug=true

on startup. Look through the output if it picks up a different config file than expected (perhaps a logback-test.xml) or if the log level is set somewhere else...

user_63152420

The issue root cause was due to a class on my application which implemented ch.qos.logback.classic.selector.ContextSelector. There were two of these actually and one was wrongfully imported. and set:

System.setProperty(ClassicConstants.LOGBACK_CONTEXT_SELECTOR, LogbackContextSelector.class.getName());

It has a method getLoggerContext which changed the logback context in runtime in a very voodoo-like way. Took a while to find this. Hope it helps someone in the future.

user_13732320
Related