Details
-
Improvement
-
Resolution: Not a bug
-
Major
-
None
-
1.2.4
-
Spring Boot 2.5.3, Java 8, Alpine Linux (the "openjdk:8u212-jdk-alpine" Docker image)
Description
When file rolling throws an exception, it is not logged anywhere unless the Logback system is in debug mode (e.g. the -Dlogback.debug=true system property). This means no one will know anything is wrong until downstream problems start occurring (e.g. the disk fills up with one giant log file).
To be specific, I had Logback configured to roll to a directory with insufficient permissions. I had no idea anything was wrong, I just knew that my log file kept growing without rolling over. Once I put Logback into debug mode, I saw the following in the console:
INFO in c.q.l.co.rolling.helper.RenameUtil - Renaming file [/<...>/publisher/logs/publisher.log] to [publisher.2021-07-28.3.log4651272232523896.tmp]
WARN in c.q.l.co.rolling.helper.RenameUtil - Failed to rename file [/<...>/publisher/logs/publisher.log] as [publisher.2021-07-28.3.log4651272232523896.tmp].
WARN in c.q.l.co.rolling.helper.RenameUtil - Detected different file systems for source [/<...>/publisher/logs/publisher.log] and target [publisher.2021-07-28.3.log4651272232523896.tmp]. Attempting rename by copying.
ERROR in ch.qos.logback.core.util.FileUtil@64370f58 - Failed to copy [/<...>/publisher/logs/publisher.log] to [publisher.2021-07-28.3.log4651272232523896.tmp] java.io.FileNotFoundException: publisher.2021-07-28.3.log4651272232523896.tmp (Permission denied)
at java.io.FileNotFoundException: publisher.2021-07-28.3.log4651272232523896.tmp (Permission denied)
at at java.io.FileOutputStream.open0(Native Method)
at at java.io.FileOutputStream.open(FileOutputStream.java:270)
at at java.io.FileOutputStream.<init>(FileOutputStream.java:213)
at at java.io.FileOutputStream.<init>(FileOutputStream.java:101)
at at ch.qos.logback.core.util.FileUtil.copy(FileUtil.java:102)
at at ch.qos.logback.core.rolling.helper.RenameUtil.renameByCopying(RenameUtil.java:113)
at at ch.qos.logback.core.rolling.helper.RenameUtil.rename(RenameUtil.java:63)
at at ch.qos.logback.core.rolling.TimeBasedRollingPolicy.renameRawAndAsyncCompress(TimeBasedRollingPolicy.java:189)
at at ch.qos.logback.core.rolling.TimeBasedRollingPolicy.rollover(TimeBasedRollingPolicy.java:176)
at at ch.qos.logback.core.rolling.RollingFileAppender.attemptRollover(RollingFileAppender.java:211)
at at ch.qos.logback.core.rolling.RollingFileAppender.rollover(RollingFileAppender.java:190)
at at ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:231)
at at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:102)
at at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84)
at at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51)
at at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270)
at at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257)
at at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:421)
at at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:383)
at at ch.qos.logback.classic.Logger.log(Logger.java:765)
at at org.apache.kafka.common.utils.LogContext$LocationAwareKafkaLogger.writeLog(LogContext.java:434)
at at org.apache.kafka.common.utils.LogContext$LocationAwareKafkaLogger.debug(LogContext.java:229)
at at org.apache.kafka.clients.NetworkClient.doSend(NetworkClient.java:524)
at at org.apache.kafka.clients.NetworkClient.doSend(NetworkClient.java:503)
at at org.apache.kafka.clients.NetworkClient.send(NetworkClient.java:463)
at at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.trySend(ConsumerNetworkClient.java:499)
at at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:255)
at at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.pollNoWakeup(ConsumerNetworkClient.java:306)
at at org.apache.kafka.clients.consumer.internals.AbstractCoordinator$HeartbeatThread.run(AbstractCoordinator.java:1363)
WARN in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - RolloverFailure occurred. Deferring roll-over.