Exceptions are ignored even with ignoreExceptions="false" when booting

[david0]

Description

We have an rolling file appender with ignoreExceptions="false" and immediateFlush="true" so that in case of any problem with this appender we would expect exceptions.

That works fine for the running application but if the appenders files are not writable during application boot, there are error messages but they are just logged and not thrown. Hence the applications starts "successfully" but with a malfunctioning logging (missing loggers)

I would expect that errors during boot time are thrown if ignoreExceptions is failse

Configuration

Version: 2.19.0

Operating system: Mac OS/X 13.3.1

JDK: OpenJDK Runtime Environment Corretto-17.0.3.6.1 (build 17.0.3+6-LTS)

Logs

2023-04-24 17:34:44,830 main ERROR Unable to create file /tmp/unreadable/error.log java.io.IOException: Permission denied
	at java.base/java.io.UnixFileSystem.createFileExclusively(Native Method)
	at java.base/java.io.File.createNewFile(File.java:1043)
	at org.apache.logging.log4j.core.appender.rolling.RollingFileManager$RollingFileManagerFactory.createManager(RollingFileManager.java:735)
	at org.apache.logging.log4j.core.appender.rolling.RollingFileManager$RollingFileManagerFactory.createManager(RollingFileManager.java:718)
	at org.apache.logging.log4j.core.appender.AbstractManager.getManager(AbstractManager.java:144)
	at org.apache.logging.log4j.core.appender.OutputStreamManager.getManager(OutputStreamManager.java:100)
	at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.getFileManager(RollingFileManager.java:217)
	at org.apache.logging.log4j.core.appender.RollingFileAppender$Builder.build(RollingFileAppender.java:135)
	at org.apache.logging.log4j.core.appender.RollingFileAppender$Builder.build(RollingFileAppender.java:62)
	at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:124)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:1138)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:1063)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:1055)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:664)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:258)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:304)
	at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:621)
	at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:694)
	at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:711)
	at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:253)
	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:155)
	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:47)
	at org.apache.logging.log4j.LogManager.getContext(LogManager.java:196)
	at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getContext(AbstractLoggerAdapter.java:137)
	at org.apache.logging.slf4j.Log4jLoggerFactory.getContext(Log4jLoggerFactory.java:61)
	at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:47)
	at org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:33)
	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:391)
	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:416)
	at com.github.david0.log4jexceptionsboot.Log4jExceptionsBootApplication.<clinit>(Log4jExceptionsBootApplication.java:11)

2023-04-24 17:34:44,836 main ERROR Could not create plugin of type class org.apache.logging.log4j.core.appender.RollingFileAppender for element RollingFile: java.lang.IllegalStateException: ManagerFactory [org.apache.logging.log4j.core.appender.rolling.RollingFileManager$RollingFileManagerFactory@53fe15ff] unable to create manager for [/tmp/unreadable/error.log] with data [org.apache.logging.log4j.core.appender.rolling.RollingFileManager$FactoryData@449a4f23[pattern=/tmp/unreadable/error.%d{yyyy-MM-dd}.%i.log.gz, append=true, bufferedIO=true, bufferSize=8192, policy=CompositeTriggeringPolicy(policies=[OnStartupTriggeringPolicy, SizeBasedTriggeringPolicy(size=1073741824), TimeBasedTriggeringPolicy(nextRolloverMillis=0, interval=1, modulate=false)]), strategy=DefaultRolloverStrategy(min=1, max=30, useMax=true), advertiseURI=null, layout=%d %p %C{1.} [%t] %m%n, filePermissions=null, fileOwner=null]] java.lang.IllegalStateException: ManagerFactory [org.apache.logging.log4j.core.appender.rolling.RollingFileManager$RollingFileManagerFactory@53fe15ff] unable to create manager for [/tmp/unreadable/error.log] with data [org.apache.logging.log4j.core.appender.rolling.RollingFileManager$FactoryData@449a4f23[pattern=/tmp/unreadable/error.%d{yyyy-MM-dd}.%i.log.gz, append=true, bufferedIO=true, bufferSize=8192, policy=CompositeTriggeringPolicy(policies=[OnStartupTriggeringPolicy, SizeBasedTriggeringPolicy(size=1073741824), TimeBasedTriggeringPolicy(nextRolloverMillis=0, interval=1, modulate=false)]), strategy=DefaultRolloverStrategy(min=1, max=30, useMax=true), advertiseURI=null, layout=%d %p %C{1.} [%t] %m%n, filePermissions=null, fileOwner=null]]
	at org.apache.logging.log4j.core.appender.AbstractManager.getManager(AbstractManager.java:146)
	at org.apache.logging.log4j.core.appender.OutputStreamManager.getManager(OutputStreamManager.java:100)
	at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.getFileManager(RollingFileManager.java:217)
	at org.apache.logging.log4j.core.appender.RollingFileAppender$Builder.build(RollingFileAppender.java:135)
	at org.apache.logging.log4j.core.appender.RollingFileAppender$Builder.build(RollingFileAppender.java:62)
	at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:124)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:1138)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:1063)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:1055)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:664)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:258)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:304)
	at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:621)
	at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:694)
	at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:711)
	at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:253)
	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:155)
	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:47)
	at org.apache.logging.log4j.LogManager.getContext(LogManager.java:196)
	at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getContext(AbstractLoggerAdapter.java:137)
	at org.apache.logging.slf4j.Log4jLoggerFactory.getContext(Log4jLoggerFactory.java:61)
	at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:47)
	at org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:33)
	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:391)
	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:416)
	at com.github.david0.log4jexceptionsboot.Log4jExceptionsBootApplication.<clinit>(Log4jExceptionsBootApplication.java:11)

2023-04-24 17:34:44,837 main ERROR Unable to invoke factory method in class org.apache.logging.log4j.core.appender.RollingFileAppender for element RollingFile: java.lang.IllegalStateException: No factory method found for class org.apache.logging.log4j.core.appender.RollingFileAppender java.lang.IllegalStateException: No factory method found for class org.apache.logging.log4j.core.appender.RollingFileAppender
	at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.findFactoryMethod(PluginBuilder.java:260)
	at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:136)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:1138)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:1063)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:1055)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:664)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:258)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:304)
	at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:621)
	at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:694)
	at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:711)
	at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:253)
	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:155)
	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:47)
	at org.apache.logging.log4j.LogManager.getContext(LogManager.java:196)
	at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getContext(AbstractLoggerAdapter.java:137)
	at org.apache.logging.slf4j.Log4jLoggerFactory.getContext(Log4jLoggerFactory.java:61)
	at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:47)
	at org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:33)
	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:391)
	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:416)
	at com.github.david0.log4jexceptionsboot.Log4jExceptionsBootApplication.<clinit>(Log4jExceptionsBootApplication.java:11)

2023-04-24 17:34:44,838 main ERROR Null object returned for RollingFile in Appenders.
2023-04-24 17:34:44,844 main ERROR Unable to locate appender "errorLogFile" for logger config "root"
17:34:44.861[main] ERROR  c.g.d.l.Log4jExceptionsBootApplication: running

Reproduction

using this:
example.tar.gz

mkdir /tmp/unreadable
chmod 0000 /tmp/unreadable

mvn spring-boot:run

[thisdudeiknew]

I'm experiencing this bug as well; I believe the fix is around here
Where instead of line 523 being:

return true;

it should be:

return success;

[ppkarwasz]

@david0,

The ignoreExceptions setting works at runtime not configuration time. Adapting it to work at configuration time would be a major refactoring of the code. We might do it in the future.

@thisdudeiknew,

You are right, that method should return success. Can you submit a PR (possibly with a regression test)?

[thisdudeiknew]

@ppkarwasz PR created: #1549.