#167 RollingFileAppender does not create a backup file when logging from multiple processes

[Thorsten Schmidt]

Version: 1.1.1 & 1.1.2-rc1
OS: Win7 64bit
Build: Unicode Debug DLL
Compiler: VS 2010

Summary: Logging from multiple active processes into the same log file only empties the content of the log file after the file size exceeds the size specified in the RollingFileAppender MaxFileSize property.

Description:
Multiple instances of my application log into the same file. The logger is configured as a RollingFileAppender using the MaxFileSize and MaxBackupIndex property. After the log file exceeds the specified filesize the content of the file is erased and no backup file is created. Using only one active process results in the expected behaviour -> Renaming the old file as backup and creating a new logfile.

[Václav Haisman]

What is your log4cplus configuration? Are you using the UseLockFile configuration property?

[Thorsten Schmidt]

The UseLockFile property is not used.
The configuration file content is:

log4cplus.rootLogger=OFF,STDOUT,LOGFILE
log4cplus.logger.Service=ALL
log4cplus.logger.Session=ALL

log4cplus.appender.STDOUT=log4cplus::ConsoleAppender
log4cplus.appender.STDOUT.ImmediateFlush = true
log4cplus.appender.STDOUT.layout=log4cplus::PatternLayout
log4cplus.appender.STDOUT.layout.ConversionPattern=%D{%m/%d/%y %H:%M:%S} %-6p %-10c{1} [%-4t] - %m %n

log4cplus.appender.LOGFILE=log4cplus::RollingFileAppender
log4cplus.appender.LOGFILE.File=service-log.log
log4cplus.appender.LOGFILE.MaxFileSize=10KB
log4cplus.appender.LOGFILE.MaxBackupIndex=2
log4cplus.appender.LOGFILE.layout=log4cplus::PatternLayout
log4cplus.appender.LOGFILE.layout.ConversionPattern=%D{%m/%d/%y %H:%M:%S} %-6p %-10c{1} [%-4t] - %m %n

[Václav Haisman]

You should use it then. Add this to your configuration:

log4cplus.appender.LOGFILE.UseLockFile=true

This will turn on synchronization based on file locking, so that all of the logging processes do not step each on the other.

[Václav Haisman]

Also, log4cplus.appender.LOGFILE.MaxFileSize=10KB will not be respected by log4cplus. This is historical behaviour. The minimum is 200KB.

[Thorsten Schmidt]

Ok, that explains why the log file file is cleared after 200 KB =)
I have added the lockfile property and a lockfile is created. Unfortunatly the problem still exists. If the logfile exceeds the filesize of 200 kb the common logfile will be cleared and no backup file is created.

[Václav Haisman]

Please add log4cplus.configDebug = true to you configuration. Log4cplus will then print some debugging information regarding the file manipulation. It might help.

[Thorsten Schmidt]

Process 1: (permanently running)

log4cplus: UseLockFile is true but LockFile is not specified
log4cplus: Just opened file: service-log.log

Process 2..N: (starts and ends, while process 1 is still running)

log4cplus: UseLockFile is true but LockFile is not specified
log4cplus: Just opened file: service-log.log
LOG-MESSAGES...
log4cplus: Entering ConsoleAppender::close()..
log4cplus: Destroying appender named [STDOUT].
log4cplus: Destroying appender named [LOGFILE].
log4cplus: Destroying appender named [LOGFILE].

When logfile-size exceeds the limit and the problem occurs:

log4cplus: UseLockFile is true but LockFile is not specified
log4cplus: Just opened file: service-log.log
LOG-MESSAGE...
log4cplus: Renaming file service-log.log to service-log.log.1
log4cplus:ERROR Failed to rename file from service-log.log to service-log.log.1; error 13
LOG-MESSAGE...
log4cplus: Entering ConsoleAppender::close()..
log4cplus: Destroying appender named [STDOUT].
log4cplus: Destroying appender named [LOGFILE].
log4cplus: Destroying appender named [LOGFILE].

[Václav Haisman]

Error 13 is EACESS. I can reproduce the problem.

[Václav Haisman]

Basically, the problem is that the underlying Win32 file HANDLE is not open with FILE_SHARE_DELETE flag. This flag, beside shared delete, allows renaming files that have handles open to them.

I have done some research and I think this is fixable, or rather, there is a possible workaround. This will require use of MSVCRT specific extensions. It will require us to open the file using Win32 API CreateFile() with the appropriate flags, then wrapping the returned HANDLE with _get_osfhandle(), and then wrapping that with _fdopen() to get FILE *, and then creating new fstream out of this. This will take some time to do and test. Don't hold your breath.

[Thorsten Schmidt]

Thank you. I will wait for the next update.

[Darius]

Hello, any status on this issue? When it is expected to be resolved?

[Václav Haisman]

I have an idea how to solve that (using custom streambuf, using Win32 file HANDLE directly and setting the appropriate sharing privileges) but it is a bit complex and I have not finished that, yet.

[Darius]

Maybe you can say how long it will take to resolve this issue?
We need to know because we want to release software to production. Also we are willing to wait for some time if this will be resolved in some short time.
In the meantime, maybe you can suggest some workaround for this issue?

[Václav Haisman]

I do not have a time frame. Real life is interfering.

As for a workaround, you will have to log each process to a separate file.

[Stephan Bielmann]

Are there some news about solving this issue? Unfortunately we do have the very same problem, multiple processes one single log file and rotation not working. However we rely on having just one single log file, as we do have quite a log of processes logging to it.

[Václav Haisman]

I have actually started working on this issue back then and got somewhat far but I got stuck on it. Here is a testing code that wherein I have been trying to develop a custom streambuf and stream to use with FileAppender on Windows. It is not complete. I am not confident it is correct, enough, to be used, yet.