Bug 17887 - RollingFileAppender does not work for 10 threads
Summary: RollingFileAppender does not work for 10 threads
Status: REOPENED
Alias: None
Product: Log4j - Now in Jira
Classification: Unclassified
Component: Appender (show other bugs)
Version: 1.2
Hardware: Sun Solaris
: P3 major
Target Milestone: ---
Assignee: log4j-dev
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2003-03-11 17:44 UTC by Natalie Wang
Modified: 2008-09-02 05:51 UTC (History)
3 users (show)



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Natalie Wang 2003-03-11 17:44:58 UTC
RollingFileAppender does not work for 10 threads.

1. It does not roll over
2. It truncated the file when it should roll over, but never appends it again.
3. It happened very often
Comment 1 Natalie Wang 2003-03-11 17:55:29 UTC
I make the file size to 2MB or 4MB. Is it a limitation for the file size?
Comment 2 Ceki Gulcu 2003-03-15 18:43:18 UTC

The RollingFileAppender is designed to work in a multi-threaded setting. Would 
it be possible for you to supply a test case? Many thanks in advance.
Comment 3 Ceki Gulcu 2003-04-22 15:38:51 UTC
In the abscense of further information, I am marking this bug report as 
WORKSFORME.
Comment 4 Yves Debillo 2006-07-18 13:46:50 UTC
I also have this problem but are unable to generate a test scenario.  It occurs
only under heavy load after a few hours of running.

Could problem be related to the code in subAppend method?  It seems to be
related to the null-pointer exceptions issues in the subAppend method.

If one thread rolls over, the fileName might temporarily be reset to null.  A
second thread will write using a null filename.

I added a test in subAppend before calling the super method.  It resolves my
case but it is not a full solution because there is still some theoretical problem.

  protected
  void subAppend(LoggingEvent event) {
    if(fileName != null) 
      super.subAppend(event);
    if((fileName != null) &&
                     ((CountingQuietWriter) qw).getCount() >= maxFileSize)
      this.rollOver();
   }
Comment 5 Thorbjørn Ravn Andersen 2008-07-01 15:29:58 UTC
From an initial reading of the bug report this might be that two threads contend for rolling over the files (i.e. the triggering happens in two threads so the operations get mixed).

Perhaps a synchronized block around the renaming-bit could help?

Suggestions?

Comment 6 QualityChecker 2008-09-02 02:30:25 UTC
May be the reason :

The SocketServer TCP/IP server is designed to manage 10 (or 11 ?) maximum threads .
See org.apache.log4j.net.SocketServer.java constructor :

public
  SocketServer(File directory) {
    this.dir = directory;
    hierarchyMap = new Hashtable(11);
  }
There must be some mixing or hidden bugs between the clients if exceeding 10 clients.

Thanks for your feedback if this is the right reason.

See http://d.cr.free.fr/wswebconsulterfichiers.php?projet=demojava_log4j for (many..) extra bugs in log4j
Comment 7 QualityChecker 2008-09-02 03:17:35 UTC
(In reply to comment #6)
> May be the reason :
> The SocketServer TCP/IP server is designed to manage 10 (or 11 ?) maximum
> threads .
> See org.apache.log4j.net.SocketServer.java constructor :
> public
>   SocketServer(File directory) {
>     this.dir = directory;
>     hierarchyMap = new Hashtable(11);
>   }
> There must be some mixing or hidden bugs between the clients if exceeding 10
> clients.
> Thanks for your feedback if this is the right reason.
> See http://d.cr.free.fr/wswebconsulterfichiers.php?projet=demojava_log4j for
> (many..) extra bugs in log4j

11 is the initial allocation size for hierarchMap, of course, which is the default anyway. May be a lack of memory + unmanaged allocation error ?
Comment 8 Thorbjørn Ravn Andersen 2008-09-02 05:51:10 UTC
(In reply to comment #7)

> >   SocketServer(File directory) {
> >     this.dir = directory;
> >     hierarchyMap = new Hashtable(11);
> >   }
> > There must be some mixing or hidden bugs between the clients if exceeding 10
> > clients.
> > Thanks for your feedback if this is the right reason.
> > See http://d.cr.free.fr/wswebconsulterfichiers.php?projet=demojava_log4j for
> > (many..) extra bugs in log4j
> 
> 11 is the initial allocation size for hierarchMap, of course, which is the
> default anyway. May be a lack of memory + unmanaged allocation error ?

It is unusual to provide the initialCapacity to the HashTable constructor (especially for such a low value) but not illegal.

http://java.sun.com/javase/6/docs/api/java/util/Hashtable.html#Hashtable(int)

Could you please elaborate on why your tool thinks these two cases are related?