[
https://issues.apache.org/jira/browse/LOG4J2-636?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Remko Popma resolved LOG4J2-636.
--------------------------------
Resolution: Cannot Reproduce
I initially thought this was caused by a concurrency issue but I now think I
was on the wrong track...
I now think this was caused by a similar problem as what caused LOG4J2-392:
incorrect shutdown caused the RollingRandomAccessFileManager to be stopped
multiple times. Managers keep track of a ref count, and will not close the
stream until the ref count is zero. If the RandomAccessFileManager is stopped
multiple times, the ref count becomes zero prematurely and the file is closed
even though it is still in use.
I think that one of the fixes in this area may have addressed the problem: I am
unable to reproduce this issue with the current code on the master branch. This
is what I did to try to reproduce the issue:
* Use the configuration above, with monitorInterval="5" (5 seconds)
* Logging is synchronous (don't configure the Log4jContextSelector to use async
loggers)
* Create a test app that starts 10 threads that each do nothing but log in an
eternal loop.
* Let the main thread modify the config file's lastModifiedTime every second to
trigger reconfiguration
I confirmed that reconfiguration is taking place but everything is working
correctly and the above error does not occur.
Below is the code I used. It does not reproduce the issue, so I will mark this
issue as "Resolved - Can't Reproduce". Please reopen this issue if the problem
still occurs in version 2.0.2 or later.
{code}
public static void main() {
final File config = new File("./log4j2.xml");
System.setProperty("log4j.configurationFile",
"file://" + config.getAbsolutePath().replaceAll("\\\\", "/"));
final Logger logger = LogManager.getLogger("ReloadTest");
final LoggerContext context = (LoggerContext) LogManager.getContext();
final int[] reconfigCount = new int[1];
final ConfigurationListener listener = new ConfigurationListener() {
public void onChange(Reconfigurable reconfigurable) {
reconfigCount[0]++;
context.getConfiguration().removeListener(this);
context.getConfiguration().addListener(this);
}
};
context.getConfiguration().addListener(listener);
final int numThreads = 10;
ExecutorService executor = Executors.newFixedThreadPool(numThreads);
for (int i = 0; i < numThreads; i++) {
executor.submit(new Runnable() {
public void run() {
while (true) {
logger.info("Reconfig count is " + reconfigCount[0]);
}
}
});
}
for (int i = 0; i < 100; i++) {
Thread.sleep(1000);
config.setLastModified(System.currentTimeMillis());
reconfigCount[0]++;
}
}
{code}
> IOException: Stream Closed RollingRandomAccessFile
> --------------------------------------------------
>
> Key: LOG4J2-636
> URL: https://issues.apache.org/jira/browse/LOG4J2-636
> Project: Log4j 2
> Issue Type: Bug
> Components: Appenders
> Affects Versions: 2.0-rc1
> Environment: Linux 3.2.0-4-amd64 #1 SMP Debian 3.2.54-2 x86_64
> GNU/Linux
> Reporter: Adrian Wilford
> Assignee: Remko Popma
> Labels: Rollover
> Fix For: 2.1
>
>
> After some time, RollingRandomAccessFile can no longer write logging events
> (have not run out of disk space).
> {code}
> 2014-05-13 10:05:18,284 ERROR Unable to write to stream logs/CALEEBaskets.log
> for appender RollingRandomAccessFile
> 2014-05-13 10:05:18,284 ERROR An exception occurred processing Appender
> RollingRandomAccessFile
> org.apache.logging.log4j.core.appender.AppenderLoggingException: Error
> writing to RandomAccessFile logs/CALEEBaskets.log
> at
> org.apache.logging.log4j.core.appender.rolling.RollingRandomAccessFileManager.flush(RollingRandomAccessFileManager.java:109)
> at
> org.apache.logging.log4j.core.appender.rolling.RollingRandomAccessFileManager.write(RollingRandomAccessFileManager.java:90)
> at
> org.apache.logging.log4j.core.appender.OutputStreamManager.write(OutputStreamManager.java:129)
> at
> org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:120)
> at
> org.apache.logging.log4j.core.appender.RollingRandomAccessFileAppender.append(RollingRandomAccessFileAppender.java:96)
> at
> org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:97)
> at
> org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:425)
> at
> org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:406)
> at
> org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:367)
> at org.apache.logging.log4j.core.Logger.log(Logger.java:112)
> at
> org.apache.logging.log4j.spi.AbstractLogger.debug(AbstractLogger.java:338)
> at
> com.corticalSystems.CALEE.algorithms.baskets.persistence.orderLogging.OrderLoggingDAL.createNewOrder(OrderLoggingDAL.java:163)
> at
> com.corticalSystems.CALEE.algorithms.baskets.logic.ConstituentLogicThread.sendNewOrder(ConstituentLogicThread.java:1087)
> at
> com.corticalSystems.CALEE.algorithms.baskets.logic.ConstituentLogicThread.run(ConstituentLogicThread.java:1587)
> at java.lang.Thread.run(Thread.java:744)
> Caused by: java.io.IOException: Stream Closed
> at java.io.RandomAccessFile.writeBytes0(Native Method)
> at java.io.RandomAccessFile.writeBytes(RandomAccessFile.java:520)
> at java.io.RandomAccessFile.write(RandomAccessFile.java:550)
> at
> org.apache.logging.log4j.core.appender.rolling.RollingRandomAccessFileManager.flush(RollingRandomAccessFileManager.java:106)
> ... 14 more
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-dev-h...@logging.apache.org
