log4j2 shuts down all appenders with slf4j

Question

I could use some help with my log4j2 configuration. When I debug the logger, it looks like it shuts down all of the appenders, and then I never receive any application logs. Luckily I know that log4j is at least finding the properties file and giving logger initialization debug output.

Here is my log4j2.properties file:

status = debug
name = PropertiesConfig
filters = threshold

filter.threshold.type = ThresholdFilter
filter.threshold.level = info

appenders = console

appender.console.type = Console
appender.console.name = STDOUT
appender.console.layout.type = PatternLayout
appender.console.layout.pattern = %d{yy-MM-dd HH:mm:ss:SSS} %-5p %c{1}:%L - %m%n

rootLogger.level = debug
rootLogger.appenderRefs = stdout
rootLogger.appenderRef.stdout.ref = STDOUT

appender.file.type = File
appender.file.name = application
appender.file.fileName=${filename}/propertieslogs.log
appender.file.layout.type=PatternLayout
appender.file.layout.pattern=[%-5level] %d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %c{1} - %msg%n

Here is the logger debug init output:

DEBUG Starting LoggerContext[name=ROOT] from configuration at null
DEBUG Starting LoggerContext[name=ROOT, org.apache.logging.log4j.core.LoggerContext@448dc39b] with configuration org.apache.logging.log4j.core.config.properties.PropertiesConfiguration@70ffa0b4...
DEBUG Shutdown hook enabled. Registering a new one.
DEBUG Apache Log4j Core 2.11.1 initializing configuration org.apache.logging.log4j.core.config.properties.PropertiesConfiguration@70ffa0b4
DEBUG Installed 1 script engine
DEBUG Oracle Nashorn version: 1.8.0_162, language: ECMAScript, threading: Not Thread Safe, compile: true, names: [nashorn, Nashorn, js, JS, JavaScript, javascript, ECMAScript, ecmascript], factory class: jdk.nashorn.api.scripting.NashornScriptEngineFactory
DEBUG PluginManager 'Core' found 118 plugins
DEBUG PluginManager 'Level' found 0 plugins
DEBUG PluginManager 'Lookup' found 14 plugins
DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef].
DEBUG PluginManager 'TypeConverter' found 26 plugins
DEBUG createAppenderRef(ref="STDOUT", level="null", Filter=null)
DEBUG Building Plugin[name=root, class=org.apache.logging.log4j.core.config.LoggerConfig$RootLogger].
DEBUG createLogger(additivity="null", level="DEBUG", includeLocation="null", ={STDOUT}, ={}, Configuration(PropertiesConfig), Filter=null)
DEBUG Building Plugin[name=loggers, class=org.apache.logging.log4j.core.config.LoggersPlugin].
DEBUG createLoggers(={root})
DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout].
DEBUG PatternLayout$Builder(pattern="%d{yy-MM-dd HH:mm:ss:SSS} %-5p %c{1}:%L - %m%n", PatternSelector=null, Configuration(PropertiesConfig), Replace=null, charset="null", alwaysWriteExceptions="null", disableAnsi="null", noConsoleNoAnsi="null", header="null", footer="null")
DEBUG PluginManager 'Converter' found 44 plugins
DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.ConsoleAppender].
DEBUG ConsoleAppender$Builder(target="null", follow="null", direct="null", bufferedIo="null", bufferSize="null", immediateFlush="null", ignoreExceptions="null", PatternLayout(%d{yy-MM-dd HH:mm:ss:SSS} %-5p %c{1}:%L - %m%n), name="STDOUT", Configuration(PropertiesConfig), Filter=null)
DEBUG Starting OutputStreamManager SYSTEM_OUT.false.false
DEBUG Building Plugin[name=appenders, class=org.apache.logging.log4j.core.config.AppendersPlugin].
DEBUG createAppenders(={STDOUT})
DEBUG Building Plugin[name=filter, class=org.apache.logging.log4j.core.filter.ThresholdFilter].
DEBUG createFilter(level="INFO", onMatch="null", onMismatch="null")
DEBUG Configuration org.apache.logging.log4j.core.config.properties.PropertiesConfiguration@70ffa0b4 initialized
DEBUG Starting configuration org.apache.logging.log4j.core.config.properties.PropertiesConfiguration@70ffa0b4
DEBUG Started configuration org.apache.logging.log4j.core.config.properties.PropertiesConfiguration@70ffa0b4 OK.
DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false-1
DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false-1, all resources released: true
DEBUG Appender DefaultConsole-1 stopped with status true
DEBUG Stopped org.apache.logging.log4j.core.config.DefaultConfiguration@605d8cc OK
DEBUG Registering MBean org.apache.logging.log4j2:type=ROOT
DEBUG Registering MBean org.apache.logging.log4j2:type=ROOT,component=StatusLogger
DEBUG Registering MBean org.apache.logging.log4j2:type=ROOT,component=ContextSelector
DEBUG Registering MBean org.apache.logging.log4j2:type=ROOT,component=Loggers,name=
DEBUG Registering MBean org.apache.logging.log4j2:type=ROOT,component=Appenders,name=STDOUT
DEBUG org.apache.logging.log4j.core.util.SystemClock does not support precise timestamps.
DEBUG LoggerContext[name=ROOT, org.apache.logging.log4j.core.LoggerContext@448dc39b] started OK with configuration org.apache.logging.log4j.core.config.properties.PropertiesConfiguration@70ffa0b4.
DEBUG Log4jServletContextListener ensuring that Log4j starts up properly.
DEBUG Log4jServletContextListener ensuring that Log4j shuts down properly.
DEBUG Removing LoggerContext for [ROOT].
DEBUG Stopping LoggerContext[name=ROOT, org.apache.logging.log4j.core.LoggerContext@448dc39b]...
DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false
DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false, all resources released: true
DEBUG Appender STDOUT stopped with status true
DEBUG Stopped org.apache.logging.log4j.core.config.properties.PropertiesConfiguration@70ffa0b4 OK
DEBUG Stopped LoggerContext[name=ROOT, org.apache.logging.log4j.core.LoggerContext@448dc39b] with status true

Thanks for any help! I need it.

I'd really like to get the async appenders working at some point, but its hard to find examples via the log4j2.properties syntax for log4j2

P.S. - here is my pom.xml:

    <!-- log4j is used for logging within the application -->
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-core</artifactId>
        <version>2.11.1</version>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-api</artifactId>
        <version>2.11.1</version>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-web</artifactId>
        <version>2.11.1</version>
        <scope>runtime</scope>
    </dependency>

    <!-- slf4j is used to tie Spring to log4j  -->
    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>slf4j-api</artifactId>
        <version>1.7.25</version>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-slf4j-impl</artifactId>
        <version>2.11.1</version>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-jcl</artifactId>
        <version>2.8.2</version>
    </dependency>
    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>slf4j-log4j12</artifactId>
        <version>1.7.25</version>
    </dependency>
    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>jcl-over-slf4j</artifactId>
        <version>1.7.25</version>
    </dependency>

Winfredwinfrey

Hey what solution did you find for this? I am also stuck on same thing. – Kwangju

Never found one. If I could go back to that project I know what I'd do though. I'd stop explicitly adding loggers for each class via log4j, then switch to Slf4j. Install lombok and add @Slf4j to the top of the class, then just use log.debug or whatever. Slf4j collects all of the logs from any logging implementation, and might as well use it, it seems to work great and have more control - using the downstream logger log4j2 that slf4j collects anyway was a headache and I never got it working. – Winfredwinfrey

Answer 1

I just experienced what seems to be a similar problem. In my case, I was able to receive application logs, but with what appeared to be a default log4j2 config. The logs were INFO level. None of the levels set for loggers in the log4j2 config (XML) were being applied. I saw a very similar output in the startup logs as posted by the OP, including the message about "shutting down OutputStreamManager".

Mine is a spring-boot application and I was able to resolve the problem by disabling the spring-boot LoggingSystem. I added this system variable to my startup command: -Dorg.springframework.boot.logging.LoggingSystem=none

Once I did that, the logging worked as expected, according to the levels set in my log4j2 XML config. It appears to be spring-boot hijacking the log system, rather than a conflict between SLF4J an LOG4J2.

Note that I still see the same logging startup messages -- the OutputStreamManager is still shutting down. Speculation: this is normal behavior, possibly just shutting down the bootstrap logger that prints the log4j2 initialization process.

Versions:

• log4j: 2.13.3
• slf4j: 1.7.30
• spring-boot: 2.2.7-RElEASE

Losse

Interesting. I've also learned recently that it can help a lot to exclude spring boot starter logging from any imported spring packages - which includes logback by default. This allows you to use your preferred logging system (log4j or log4j2) without spring's system interfering with your preference. I'll vote this up because it seems helpful and I appreciate the reply, but I can't test this anymore so I might leave the answer selection until more feedback is given by other users (or upvotes). – Winfredwinfrey