Log4j2 - Why is my "Logger" element hiding content from my "Root" logger?

Question

Before someone closes this question off as a duplicate, just hear me out... I have read through countless blog posts, tutorials, FAQs and SO questions for days now and I'm no closer to understanding why I'm getting this specific behaviour.

Configuration

My log4j2.xml config file contains the following:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="DEBUG">
    <Properties>
        <Property name="APP_NAME">MyCoolApp</Property>
        <Property name="BASE_PACKAGE">my.cool.package</Property>
        <Property name="LOG_DIR">${env:LOG_ROOT:-logs}</Property>
        <Property name="LOG_PATTERN">%d [%t] %-5level %c{1.}:%L:%M | %m%n</Property>
    </Properties>

    <Appenders>
        <RollingFile name="AppLogFile" fileName="${LOG_DIR}/${APP_NAME}.log" filePattern="${LOG_DIR}/archive/${APP_NAME}.%d{yyyy-MM-dd}.log.gz">
            <PatternLayout pattern="${LOG_PATTERN}"/>
            <TimeBasedTriggeringPolicy/>
        </RollingFile>

        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="${LOG_PATTERN}"/>
        </Console>
    </Appenders>

    <Loggers>
        <Logger name="${BASE_PACKAGE}" level="INFO">
            <AppenderRef ref="AppLogFile"/>
        </Logger>

        <Root level="TRACE">
            <AppenderRef ref="Console"/>
        </Root>
    </Loggers>
</Configuration>

Then each class initialises a logger with private static final Logger LOGGER = LogManager.getLogger();.

Runtime

From my understanding of log levels, loggers and appenders, this should give me the following:

All INFO and higher level logging output to file
All TRACE and higher level logging output to console

Meanwhile, if I run the app when the AppLogFile appender is enabled, I get less output to the console; counting from only after the Log4j initialisation, I get 255 lines compared to 367.

Looking through the console and file output, when the AppLogFile appender is enabled, I don't get any TRACE or DEBUG output, only INFO and higher. When I comment out just that appender (without changing anything else), then I get everything to console, including TRACE and DEBUG.

I've tried playing around with reordering the "console" and "file" related elements, I've tried explicitly enabling and disabling the logger's additivity property, I've tried using filters in the appenders and loggers, and even multiple appender references inside one logger with explicit level properties.

All I want is to get everything to go to the console and everything INFO level and higher to go to a file. What am I missing here..?

Just switch both elements in <Loggers> element (Root with ref console comes first than logger with ref logfile). — KarelG
Just tried that again, but I get the same results as before. I edited my question to add notes on what logging output is missing, just in case that helps narrow it down.. — user909694

Andreas Andreas · Accepted Answer · 2017-06-30T11:52:01

The level attribute and the <AppenderRef> element are entirely independent:

Specifying level changes the logging level of the given logger and all sub-loggers.
Specifying <AppenderRef> adds¹ another appender to the given logger and all sub-loggers.

The fact that you do both at the same time, doesn't affect those independent effects.

If you want to limit log entries for the Appender, specify the level attribute on the <AppenderRef> instead.

^{1) If you wanted the Appender to replace, you need to specify additivity="false"}

(OP edit) Just for the sake of clarity, between what I learned from this answer and the Log4j2 FAQ; I streamlined things a bit and ended up with the following <Loggers> configuration:

<Loggers>
    <Root level="TRACE">
        <AppenderRef ref="AppLogFile" level="INFO"/>
        <AppenderRef ref="Console"/>
    </Root>
</Loggers>

Log4j2 - Why is my "Logger" element hiding content from my "Root" logger?

Configuration

Runtime

1 Answers