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

v1.1.3
open
Václav Zeman
3
2013-11-29
2013-06-14
Thorsten Schmidt
No

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.

Discussion

1 2 > >> (Page 1 of 2)
  • Václav Zeman
    Václav Zeman
    2013-06-17

    • labels: --> v1.1.1
    • assigned_to: Václav Zeman
     
  • Václav Zeman
    Václav Zeman
    2013-06-17

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

     
  • 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 Zeman
    Václav Zeman
    2013-06-18

    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 Zeman
    Václav Zeman
    2013-06-18

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

     
  • 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 Zeman
    Václav Zeman
    2013-06-18

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

     
  • 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 Zeman
    Václav Zeman
    2013-06-19

    Error 13 is EACESS. I can reproduce the problem.

     
  • Václav Zeman
    Václav Zeman
    2013-06-19

    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.

     
1 2 > >> (Page 1 of 2)