Log4j2 doesn't flush data to log until program is closed or manually open in file explorer

[tversic]

Hi everyone, I have been stuck on this problem for a while now.
When using log4j2 logging, (RandomAccessFile appenders I have also tried with RollingFile appenders) logs in windows explorer remain empty or partly written until I open the file manually from windows explorer or I close the application that is logging inside that file.

I have managed to replicate that issue with next code. (disregard method names sync and async that was left from old testing)

My configuration looks like this

I have tried adding immediateFlush="true", BufferedIO=false, and it makes no difference in behavior, I know that logging is synchronous but it was worth a try.
I have also tried loggerContext.updateLoggers and no result.
Closing LoggerManager fixes the problem, but I need to reuse it logger after closing and I would need to do many closes and restarts and it is not efficient.

Log in windows explorer while app is running

After I click on the log file, the log file size is updated

Notice: I have noticed that if I change my configuration, so both appenders write inside same folder this issue disappears, in this use case, but in other project where I have 4-5 appenders and they all write to same folder but different files I still have this issue, so the problem is really inconsistent, I think this might be something related to windows/file explorer/log4j2 in combination, but cant put my finger on the problem.

I have seen this stack overflow post, but it is 9 years old and it still doesnt give definitive answer: https://stackoverflow.com/questions/26676331/log4j-rollingfileappender-not-writing-to-log-until-application-close

[ppkarwasz]

@garydgregory,

Could you look at this? Can it be explained somehow by Windows strange file locking semantics? Maybe the file has an exclusive lock until the JVM releases it?

[jvz]

Could be related to #2025 for the immediateFlush option at least.

[tversic]

Yeah, I noticed that that setting doesn't make difference even though it should, so log4j2 could have issues with immediateFlush combined with rollingFileAppened as I understand, and it is bug scheduled to be resolved right?

[ppkarwasz]

@tversic,

Hi everyone, I have been stuck on this problem for a while now. When using log4j2 logging, (RandomAccessFile appenders I have also tried with RollingFile appenders) logs in windows explorer remain empty or partly written until I open the file manually from windows explorer or I close the application that is logging inside that file.

If I understand it correctly the problem is:

• when the application is logging Windows Explorer shows always 0 bytes in the folder list,
• if you open the file (e.g. with an editor), you discover that the file has actually some content,
• if the application exits, Windows Explorer shows the correct file size.

If that is the case, it is more a limitation of Windows Explorer than anything else: it does not refresh the file list.

[tversic]

yeah that is behavior, and yeah I was thinking that maybe that was limitation of windows explorer, but I would really like to put my finger on exact thing that is in the way, and find out if there is some way around that behavior, so thats why I just want to make sure

[tcmot]

I have also encountered such a problem, very confused. Windows files will not be updated unless you right-click to view file properties.

[tcmot]

RandomAccessFile 

FileChannel channel = randomAccessFile.getChannel();
randomAccessFile.write();
channel.force(true);

Use the force method，the file be updated in real time. But affects performance.
Log4j2，not use the force method.

[tversic]

I have tried that in test project, but it seems like it is not working sadly

[tversic]

As I understood from this article this problem is NTFS problem and not Log4j2 problem,. (link: https://devblogs.microsoft.com/oldnewthing/20111226-00/?p=8813)