[logback-dev] [JIRA] Updates for LOGBACK-1565: Exceptions while rolling only appear in Logback's debug mode

[QOS.CH (JIRA)]

logback / LOGBACK-1565 [Open]
Exceptions while rolling only appear in Logback's debug mode

==============================

Here's what changed in this issue in the last few minutes.
This issue has been created
This issue is now assigned to you.

View or comment on issue using this link
https://jira.qos.ch/browse/LOGBACK-1565

==============================
 Issue created
------------------------------

Steven Paligo created this issue on 28/Jul/21 8:33 PM
Summary:              Exceptions while rolling only appear in Logback's debug mode
Issue Type:           Improvement
Affects Versions:     1.2.4
Assignee:             Logback dev list
Components:           logback-core
Created:              28/Jul/21 8:33 PM
Environment:          Spring Boot 2.5.3, Java 8, Alpine Linux (the "openjdk:8u212-jdk-alpine" Docker image)
Labels:               TimeBasedRollingPolicy
Priority:             Major
Reporter:             Steven Paligo
Description:
  When the file rolling throws an exception, it is never logged anywhere unless the Logback system is in debug mode (e.g. the -Dlogback.debug=true system property). This means no one will know something 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:
  {code:java}
  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 at 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.
  
  {code}


==============================
 This message was sent by Atlassian Jira (v8.8.0#808000-sha1:e2c7e59)