#134 RollingFileAppender multiple-thread problem

appenders (19)

RollingFileAppender class cann't work properly when his intance is used by multiple categorys in multiple-thread circum because (_fd) file description can be closed when used by another thread in the same time ,furtherly more than one threasd can enter into the rolling file process in the same time.


  • Alexander Perepelkin


    Thanks for the feedback.
    Could you paste here a simple program which would reveal explained weakness please?
    That would help a lot in resolving that trouble.

  • chang.yunlei

    chang.yunlei - 2013-01-01


  • chang.yunlei

    chang.yunlei - 2013-01-01

    I Have writed my testing code in testCategory.cpp that file is contained in the project. I lanch 20 threads to make them log into one dest file.At some time,you can see the file keeps increasing without rolling over.I sure that must occur some exception in file system,there is the bug lies in

  • Alexander Perepelkin

    I can see from the code you supplied that you have several different categories (aka loggers) all of which make use of the same single appender.
    I am afraid that this particular kind of multithreading configuration is supported well neither by log4cpp nor by log4j. I put some links below for your consideration.
    This behaviour has the explanation:
    each logger posts every message to all its own appenders consequently, locking its own mutex to disable any change on the appenders list during that iteration. But that mutex has impact only on this particular logger and not on others.
    In your configuration you have several loggers each of which runs in its own thread and thus having no interlocks on their mutexes. Further, since they all share the same appender (RollingFileAppender), that appender appears to be in continuous use, meaning that operations with its file descriptor are performed from all the threads in chaotic order given by tasks scheduler. Since there are always active IO operations on this file, it can not be closed and rolled over.
    However, usually logging operations are not so frequent, since writing on disk takes time, and first logging thread has time enough to log and close the file before second thread comes in wanting to log its message. Anyway, writing logs is not usually the primary target of the application.

    There may be two possible solutions for your case.
    Either you can make use of the same logger from all of your threads (which will utilize the mutex inside that single logger), and then file will be rolled over gracefully. In this case your threads will compete for posting their messages into file, but this should not cause any performance degradation since blocking IO operations are much slower than switching between threads. This is only configuration matter and does not imply any change in log4cpp sources.
    Or, if having many loggers is ultimately important issue here, then you may adjust log4cpp source code for this need: introduce a mutex into the appender and lock it every time when appender needs to do its action no matter which logger requested it. This way no more than one thread will be able to perform IO operation at the same single point in time, so there will also be a room for rolling file over. But this solution will cause much more overhead than the existing one, so most of the library users certainly do not want that change in the main branch.

    Take a look on how people struggle with that trouble on Internet:

  • chang.yunlei

    chang.yunlei - 2013-01-04

    firstly,maybe the correctness is the first clsss requirement.You can see in Log4j,the RollingFileAppender impl is called by AppenderSkeleton and then rollover process is protected by AppenderSkeleton 's synchronized doAppend(LoggingEvent event) method.
    Second,some user maybe need some vairious log info prefixs that can be attained by using category name,but only supply a few log files as their appenders.

    that maybe useful and have meaning :)

  • Alexander Perepelkin

    logging framework should stay as lightweight as it is possible.
    This is where performance and correctness have to make compromise.

    Currently performance is preferred, and I believe reasons are explained in my previous message.
    You would choose to keep log4cpp closer to log4j behavior and lock the mutex every time RollingFileAppender::_append(const LoggingEvent& event) is called, wouldn't you?
    I am not quite sure about this, but it seems that Java's synchronized methods are much lighter and do not necessarily fall back on system objects, but log4cpp has to. Locking mutex one more time when you want to call _append() is pretty heavy cost to pay.

    I did not get really your second suggestion. Is there an analog in log4j of the option that you just described?


Get latest updates about Open Source Projects, Conferences and News.

Sign up for the SourceForge newsletter:

No, thanks