[
https://issues.apache.org/jira/browse/LOG4J2-679?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14042187#comment-14042187
]
Rene Schoenlein edited comment on LOG4J2-679 at 6/24/14 3:32 PM:
-----------------------------------------------------------------
I am pretty convinced now that this is a race condition in method
"execute(final File source, final File destination, final boolean
renameEmptyFiles)" of class
"org.apache.logging.log4j.core.appender.rolling.action.FileRenameAction".
My working assumption is, that during parent folder creation it can happen that
more than one thread is trying to create the potential non-existing sub-folder
structure at the same time.
("org.apache.logging.log4j.core.appender.rolling.action.FileRenameAction" RC-1):
{code}
...
if (parent != null && !parent.exists()) { <-- parent.exists() might be false
for multiple callers
if (!parent.mkdirs()) { <-- one caller will succeed with TRUE, but for all
other threads already past "!parent.exists()" the result will be "FALSE" even
if the "to be created" folder structure exists now.
LOGGER.error("Unable to create directory {}", parent.getAbsolutePath());
return false;
}
}
...
{code}
was (Author: rene schoenlein):
I am pretty convinced now that this is most likely a race condition in method
"execute(final File source, final File destination, final boolean
renameEmptyFiles)" of class
"org.apache.logging.log4j.core.appender.rolling.action.FileRenameAction".
My working assumption is, that during parent folder creation it can happen that
more than one thread is trying to create the potential non-existing sup-folder
structure at the same time.
("org.apache.logging.log4j.core.appender.rolling.action.FileRenameAction" RC-1):
{code}
...
if (parent != null && !parent.exists()) { <-- parent.exists() might be false
for multiple callers
if (!parent.mkdirs()) { <-- one caller will succeed with TRUE, but for all
other threads already past "!parent.exists()" the result will be "FALSE" even
if the "to be created" folder structure exists now.
LOGGER.error("Unable to create directory {}", parent.getAbsolutePath());
return false;
}
}
...
{code}
> Log rotation partly failed with error: "Unable to create directory ..."
> -----------------------------------------------------------------------
>
> Key: LOG4J2-679
> URL: https://issues.apache.org/jira/browse/LOG4J2-679
> Project: Log4j 2
> Issue Type: Bug
> Components: Appenders
> Affects Versions: 2.0-rc1
> Environment: JDK 1.6, tomcat 6,
> Reporter: Rene Schoenlein
> Priority: Critical
>
> Log rotation partly failed with error: "Unable to create directory ..."
> I am using the following configuration (simplified for the purpose of this
> ticket):
> {code}
> <Configuration status="info" name="App1" monitorInterval="60">
> <Properties>
> <Property name="defaultLayout">[%t %d{EEE MMM dd HH:mm:ss z yyyy}
> <%level{TRACE=6, DEBUG=5, INFO=4, WARN=3, ERROR=2, FATAL=1}>]
> %m%n</Property>
> <Property name="patternCharset">UTF-8</Property>
> <Property name="logDir">/var/log/app1/</Property>
> <Property name="backupDir">/var/backups/app1/%d{yyyy}/%d{MM}/</Property>
> </Properties>
> <Appenders>
> <RollingRandomAccessFile name="A" fileName="${logDir}A.log"
> filePattern="${backupDir}A.log-%d{yyyyMMdd}">
> <PatternLayout pattern="${defaultLayout}" charset="${patternCharset}"/>
> <Policies>
> <TimeBasedTriggeringPolicy interval="1" modulate="true"/>
> </Policies>
> </RollingRandomAccessFile>
> <RollingRandomAccessFile name="B" fileName="${logDir}B.log"
> filePattern="${backupDir}B.log-%d{yyyyMMdd}">
> <PatternLayout pattern="${defaultLayout}" charset="${patternCharset}"/>
> <Policies>
> <TimeBasedTriggeringPolicy interval="1" modulate="true"/>
> </Policies>
> </RollingRandomAccessFile>
> <!-- ... additional appenders, only differing in
> appender-name/log-file-name, where removed for this ticket -->
> <RollingRandomAccessFile name="C" fileName="${logDir}Y.log"
> filePattern="${backupDir}Y.log-%d{yyyyMMdd}">
> <PatternLayout pattern="${defaultLayout}" charset="${patternCharset}"/>
> <Policies>
> <TimeBasedTriggeringPolicy interval="1" modulate="true"/>
> </Policies>
> </RollingRandomAccessFile>
> <RollingRandomAccessFile name="D" fileName="${logDir}Z.log"
> filePattern="${backupDir}Z.log-%d{yyyyMMdd}">
> <PatternLayout pattern="${defaultLayout}" charset="${patternCharset}"/>
> <Policies>
> <TimeBasedTriggeringPolicy interval="1" modulate="true"/>
> </Policies>
> </RollingRandomAccessFile>
> </Appenders>
> <Loggers>
> <Logger name="A" level="INFO" additivity="false">
> <AppenderRef ref="A"/>
> </Logger>
> <Logger name="B" level="INFO" additivity="false">
> <AppenderRef ref="B"/>
> </Logger>
> <!-- ... additional loggers, only differing in logger-name/appender-ref,
> where removed for this ticket -->
> <Logger name="C" level="INFO" additivity="false">
> <AppenderRef ref="C"/>
> </Logger>
> <Logger name="D" level="INFO" additivity="false">
> <AppenderRef ref="D"/>
> </Logger>
> </Loggers>
> </Configuration>
> {code}
> As part of last nights log-rotation, sub-folders "/2014/06/" had to be
> created on top of the already existing "/var/backups/app1/" folder structure.
> During this log-rotation task, 2 out of ~20 files (all constantly written by
> the same application) where not rotated in the desired folder
> "/var/backups/app1/2014/06/" but are still actively used in the base folder.
> The only hint I could find regarding this issue was the following log output
> from log4j (matching the rotation time):
> 2014-06-24 00:00:00,084 ERROR Unable to create directory
> /var/backups/app1/2014/06
> 2014-06-24 00:00:00,084 ERROR Unable to create directory
> /var/backups/app1/2014/06
> Strangely all other log-file where correctly rotated to the identical
> destination directory.
> Until now i was not able to reproduce this behavior in my testing environment
> but i suspect that there might be an issue with handling multiple
> log-rotations in parallel for a "to be created" sub-directory.
--
This message was sent by Atlassian JIRA
(v6.2#6252)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
