spring boot 2 + log4j2 over slf4j not writing logs to file

Question

In my application, I'm using spring boot 2.0.3 and have slf4j with log4j2 configured for logging.

However, I'm not able to get the setup write the logs to the file. I tried many ways but could not make it work. I don't understand what I'm missing here :/

My pom.xml

       <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
            <version>${spring.boot.version}</version>
            <exclusions>
                <exclusion>
                    <groupId>org.springframework.boot</groupId>
                    <artifactId>spring-boot-starter-logging</artifactId>
                </exclusion>
            </exclusions>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-log4j2</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-tomcat</artifactId>
            <version>${spring.boot.version}</version>
            <scope>provided</scope>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-autoconfigure</artifactId>
            <version>${spring.boot.version}</version>
        </dependency>

My log4j2.properties file

status = debug
name= properties_configuration

# Give directory path where log files should get stored
property.basePath = /A/B/c-web

# ConsoleAppender will print logs on console
appender.console.type = Console
appender.console.name = consoleLogger
appender.console.target = SYSTEM_OUT
appender.console.layout.type = PatternLayout

# Specify the pattern of the logs
appender.console.layout.pattern = %d{yyyy-MM-dd HH:mm:ss.SSS} %level [%t] [%c] [%M] [%l] - %msg%n


# RollingFileAppender will print logs in file which can be rotated based on time or size
appender.rolling.type = RollingFile
appender.rolling.name = fileLogger
appender.rolling.fileName= ${basePath}/c-web.log
appender.rolling.filePattern= ${basePath}/archive/c-web_%d{yyyyMMdd}.log.gz
appender.rolling.layout.type = PatternLayout
appender.rolling.layout.pattern = %d{yyyy-MM-dd HH:mm:ss.SSS} %level [%t] [%c] [%M] [%l] - %msg%n
appender.rolling.policies.type = Policies

# Rotate log file each day and keep 30 days worth
appender.rolling.policies.time.type = TimeBasedTriggeringPolicy
appender.rolling.policies.time.interval = 1
appender.rolling.policies.time.modulate = true
appender.rolling.strategy.type = DefaultRolloverStrategy
appender.rolling.strategy.delete.type = Delete
appender.rolling.strategy.delete.basePath = ${basePath}/archive
appender.rolling.strategy.delete.maxDepth = 1
appender.rolling.strategy.delete.ifLastModified.type = IfLastModified
# Delete files older than 30 days
appender.rolling.strategy.delete.ifLastModified.age = 30d

# Mention package name here in place of example. Classes in this package or subpackages will use ConsoleAppender and RollingFileAppender for logging         
logger.rolling.name = com.x
logger.rolling.level = debug
logger.rolling.additivity = false
logger.rolling.appenderRef.rolling.ref = fileLogger
logger.rolling.appenderRef.console.ref = consoleLogger

# Configure root logger for logging error logs in classes which are in package other than above specified package
rootLogger.level = info
rootLogger.additivity = false
rootLogger.appenderRef.rolling.ref = fileLogger
rootLogger.appenderRef.console.ref = consoleLogger

Application log during bootup

2018-10-28 20:14:50,463 main DEBUG PluginManager 'Core' found 116 plugins
2018-10-28 20:14:50,463 main DEBUG PluginManager 'Level' found 0 plugins
2018-10-28 20:14:50,468 main DEBUG Building Plugin[name=property, class=org.apache.logging.log4j.core.config.Property].
2018-10-28 20:14:50,483 main DEBUG PluginManager 'TypeConverter' found 26 plugins
2018-10-28 20:14:50,493 main DEBUG createProperty(name="basePath", value="/A/B/c-web")
2018-10-28 20:14:50,493 main DEBUG Building Plugin[name=properties, class=org.apache.logging.log4j.core.config.PropertiesPlugin].
2018-10-28 20:14:50,498 main DEBUG configureSubstitutor(={basePath=/A/B/c-web}, Configuration(properties_configuration))
2018-10-28 20:14:50,499 main DEBUG PluginManager 'Lookup' found 13 plugins
2018-10-28 20:14:50,499 main DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef].
2018-10-28 20:14:50,499 main DEBUG createAppenderRef(ref="consoleLogger", level="null", Filter=null)
2018-10-28 20:14:50,500 main DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef].
2018-10-28 20:14:50,500 main DEBUG createAppenderRef(ref="fileLogger", level="null", Filter=null)
2018-10-28 20:14:50,500 main DEBUG Building Plugin[name=logger, class=org.apache.logging.log4j.core.config.LoggerConfig].
2018-10-28 20:14:50,504 main DEBUG createLogger(additivity="false", level="DEBUG", name="com.x", includeLocation="null", ={consoleLogger, fileLogger}, ={}, Configuration(properties_configuration), Filter=null)
2018-10-28 20:14:50,506 main DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef].
2018-10-28 20:14:50,507 main DEBUG createAppenderRef(ref="consoleLogger", level="null", Filter=null)
2018-10-28 20:14:50,507 main DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef].
2018-10-28 20:14:50,507 main DEBUG createAppenderRef(ref="fileLogger", level="null", Filter=null)
2018-10-28 20:14:50,508 main DEBUG Building Plugin[name=root, class=org.apache.logging.log4j.core.config.LoggerConfig$RootLogger].
2018-10-28 20:14:50,509 main DEBUG createLogger(additivity="null", level="INFO", includeLocation="null", ={consoleLogger, fileLogger}, ={}, Configuration(properties_configuration), Filter=null)
2018-10-28 20:14:50,509 main DEBUG Building Plugin[name=loggers, class=org.apache.logging.log4j.core.config.LoggersPlugin].
2018-10-28 20:14:50,510 main DEBUG createLoggers(={com.x, root})
2018-10-28 20:14:50,510 main DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout].
2018-10-28 20:14:50,515 main DEBUG PatternLayout$Builder(pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} %level [%t] [%c] [%M] [%l] - %msg%n", PatternSelector=null, Configuration(properties_configuration), Replace=null, charset="null", alwaysWriteExceptions="null", disableAnsi="null", noConsoleNoAnsi="null", header="null", footer="null")
2018-10-28 20:14:50,515 main DEBUG PluginManager 'Converter' found 47 plugins
2018-10-28 20:14:50,528 main DEBUG Building Plugin[name=IfLastModified, class=org.apache.logging.log4j.core.appender.rolling.action.IfLastModified].
2018-10-28 20:14:50,529 main DEBUG createAgeCondition(age="P30D", ={})
2018-10-28 20:14:50,530 main DEBUG org.apache.logging.log4j.core.util.SystemClock does not support precise timestamps.
2018-10-28 20:14:50,531 main DEBUG Building Plugin[name=Delete, class=org.apache.logging.log4j.core.appender.rolling.action.DeleteAction].
2018-10-28 20:14:50,532 main DEBUG createDeleteAction(basePath="/A/B/c-web/archive", followLinks="false", maxDepth="1", testMode="false", PathSorter=null, ={IfLastModified(age=P30D)}, ScriptCondition=null, Configuration(properties_configuration))
2018-10-28 20:14:50,532 main DEBUG Building Plugin[name=DefaultRolloverStrategy, class=org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy].
2018-10-28 20:14:50,542 main DEBUG DefaultRolloverStrategy$Builder(max="null", min="null", fileIndex="null", compressionLevel="null", ={DeleteAction[basePath=/A/B/c-web/archive, options=[], maxDepth=1, conditions=[IfLastModified(age=P30D)]]}, stopCustomActionsOnError="null", tempCompressedFilePattern="null", Configuration(properties_configuration))
2018-10-28 20:14:50,542 main DEBUG Building Plugin[name=TimeBasedTriggeringPolicy, class=org.apache.logging.log4j.core.appender.rolling.TimeBasedTriggeringPolicy].
2018-10-28 20:14:50,544 main DEBUG TimeBasedTriggeringPolicy$Builder(interval="1", modulate="true", maxRandomDelay="null")
2018-10-28 20:14:50,544 main DEBUG Building Plugin[name=Policies, class=org.apache.logging.log4j.core.appender.rolling.CompositeTriggeringPolicy].
2018-10-28 20:14:50,545 main DEBUG createPolicy(={TimeBasedTriggeringPolicy(nextRolloverMillis=0, interval=1, modulate=true)})
2018-10-28 20:14:50,545 main DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.RollingFileAppender].
2018-10-28 20:14:50,549 main DEBUG RollingFileAppender$Builder(fileName="/A/B/c-web/c-web.log", filePattern="/A/B/c-web/archive/c-web_%d{yyyyMMdd}.log.gz", append="null", locking="null", Policies(CompositeTriggeringPolicy(policies=[TimeBasedTriggeringPolicy(nextRolloverMillis=0, interval=1, modulate=true)])), DefaultRolloverStrategy(DefaultRolloverStrategy(min=1, max=7, useMax=true)), advertise="null", advertiseUri="null", createOnDemand="null", filePermissions="null", fileOwner="null", fileGroup="null", bufferedIo="null", bufferSize="null", immediateFlush="null", ignoreExceptions="null", PatternLayout(%d{yyyy-MM-dd HH:mm:ss.SSS} %level [%t] [%c] [%M] [%l] - %msg%n), name="fileLogger", Configuration(properties_configuration), Filter=null)
2018-10-28 20:14:50,554 main DEBUG Starting RollingFileManager /A/B/c-web/c-web.log
2018-10-28 20:14:50,556 main DEBUG PluginManager 'FileConverter' found 2 plugins
2018-10-28 20:14:50,557 main DEBUG Setting prev file time to 2018-10-28T19:16:05.000+0530
2018-10-28 20:14:50,559 main DEBUG Initializing triggering policy CompositeTriggeringPolicy(policies=[TimeBasedTriggeringPolicy(nextRolloverMillis=0, interval=1, modulate=true)])
2018-10-28 20:14:50,560 main DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout].
2018-10-28 20:14:50,561 main DEBUG PatternLayout$Builder(pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} %level [%t] [%c] [%M] [%l] - %msg%n", PatternSelector=null, Configuration(properties_configuration), Replace=null, charset="null", alwaysWriteExceptions="null", disableAnsi="null", noConsoleNoAnsi="null", header="null", footer="null")
2018-10-28 20:14:50,561 main DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.ConsoleAppender].
2018-10-28 20:14:50,563 main DEBUG ConsoleAppender$Builder(target="SYSTEM_OUT", follow="null", direct="null", bufferedIo="null", bufferSize="null", immediateFlush="null", ignoreExceptions="null", PatternLayout(%d{yyyy-MM-dd HH:mm:ss.SSS} %level [%t] [%c] [%M] [%l] - %msg%n), name="consoleLogger", Configuration(properties_configuration), Filter=null)
2018-10-28 20:14:50,564 main DEBUG Starting OutputStreamManager SYSTEM_OUT.false.false
2018-10-28 20:14:50,565 main DEBUG Building Plugin[name=appenders, class=org.apache.logging.log4j.core.config.AppendersPlugin].
2018-10-28 20:14:50,565 main DEBUG createAppenders(={fileLogger, consoleLogger})
2018-10-28 20:14:50,566 main DEBUG Configuration org.apache.logging.log4j.core.config.properties.PropertiesConfiguration@23cd925 initialized
2018-10-28 20:14:50,566 main DEBUG Starting configuration org.apache.logging.log4j.core.config.properties.PropertiesConfiguration@23cd925
2018-10-28 20:14:50,567 main DEBUG Started configuration org.apache.logging.log4j.core.config.properties.PropertiesConfiguration@23cd925 OK.
2018-10-28 20:14:50,567 main DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false-1
2018-10-28 20:14:50,568 main DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false-1, all resources released: true
2018-10-28 20:14:50,568 main DEBUG Appender DefaultConsole-1 stopped with status true
2018-10-28 20:14:50,568 main DEBUG Stopped org.apache.logging.log4j.core.config.DefaultConfiguration@699259d8 OK
2018-10-28 20:14:50,611 main DEBUG Registering MBean org.apache.logging.log4j2:type=6be184cd
2018-10-28 20:14:50,613 main DEBUG Registering MBean org.apache.logging.log4j2:type=6be184cd,component=StatusLogger
2018-10-28 20:14:50,615 main DEBUG Registering MBean org.apache.logging.log4j2:type=6be184cd,component=ContextSelector
2018-10-28 20:14:50,618 main DEBUG Registering MBean org.apache.logging.log4j2:type=6be184cd,component=Loggers,name=
2018-10-28 20:14:50,619 main DEBUG Registering MBean org.apache.logging.log4j2:type=6be184cd,component=Loggers,name=com.x
2018-10-28 20:14:50,620 main DEBUG Registering MBean org.apache.logging.log4j2:type=6be184cd,component=Appenders,name=fileLogger
2018-10-28 20:14:50,621 main DEBUG Registering MBean org.apache.logging.log4j2:type=6be184cd,component=Appenders,name=consoleLogger
2018-10-28 20:14:50,623 main DEBUG org.apache.logging.log4j.core.util.SystemClock does not support precise timestamps.
2018-10-28 20:14:50,623 main DEBUG Reconfiguration complete for context[name=6be184cd] at URI <project-path>/target/classes/log4j2.properties (org.apache.logging.log4j.core.LoggerContext@ac76de5) with optional ClassLoader: null
2018-10-28 20:14:50,623 main DEBUG Shutdown hook enabled. Registering a new one.
2018-10-28 20:14:50,624 main DEBUG LoggerContext[name=6be184cd, org.apache.logging.log4j.core.LoggerContext@ac76de5] started OK.
2018-10-28 20:14:50,971 main DEBUG Using configurationFactory org.apache.logging.log4j.core.config.ConfigurationFactory$Factory@7ae5dec6
2018-10-28 20:14:50,974 main INFO Log4j appears to be running in a Servlet environment, but there's no log4j-web module available. If you want better web container support, please add the log4j-web JAR to your web archive or server lib directory.

Please let me know if you need any other information.

appreciate your help. Thanks in advance.

Answer 1

It turned out to be pretty simple.Spring boot was not loading the log4j2 configuration file properly during the Application starup.I just had to explicitly mention it. I was able to get it working by adding

logging.config=src/main/resources/log4j2.properties

to my application.properties file.