Are we sure log4j is flushing the output for a FileWriter?

[Scott Ellsworth <sc...@alodar.com>]

Hi, all.

I have a project in which we have used log4j extensively.  Our program logs 
a message on start, so there should be something in the log file pretty 
much instantly, but it appears that if the program is halted suddenly, the 
log file will be completely empty.

I have tried halting it by closing the Java launcher DOS window, and I note 
that I then get an empty log file.  This is true even if the program has 
been running for five or ten minutes.  I am using a plain old FileAppender, 
which inherits from WriterAppender, and thus ImmediateFlush should force 
the writes to take place within seconds at most.

If I do not kill the process, then the writes take place either when we 
have a few k in the log buffer, or when the process terminates 
gracefully.  This is normal behavior for buffered output, but I even tried 
explicitly setting ImmediateFlush to see if that made a difference.

NB - there is quite a bit of time where the program sits idle, so I know 
that the initial message is not getting swallowed by threading or something 
similarly vile.

I have tried both 1.1.3 and 1.1.2.

So, can anyone confirm that FileWriter is honoring the immediate flush 
requests under Windows and JDK 1.3.1?

The config file is below.

log4j.rootCategory=DEBUG, A_log

log4j.appender.A_log=org.apache.log4j.FileAppender
log4j.appender.A_log.Threshold=DEBUG
log4j.appender.A_log.File=pov.log
log4j.appender.A_log.ImmediateFlush=true
log4j.appender.A_log.Append=false
log4j.appender.A_log.layout=org.apache.log4j.PatternLayout
log4j.appender.A_log.layout.ConversionPattern=%d (%r) %-5p %-30c{2} - %m\n

log4j.category.com.isisph.bioinfo.general.POV=DEBUG
Scott Ellsworth
scott@alodar.com


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: log4j-user-help@jakarta.apache.org

Re: Are we sure log4j is flushing the output for a FileWriter?

[Claus Wagner <Cl...@ascom.ch>]

Scott Ellsworth wrote:
> 
> Hi, all.
> 
> I have a project in which we have used log4j extensively.  Our program logs
> a message on start, so there should be something in the log file pretty
> much instantly, but it appears that if the program is halted suddenly, the
> log file will be completely empty.
> 
> I have tried halting it by closing the Java launcher DOS window, and I note
> that I then get an empty log file.  This is true even if the program has
> been running for five or ten minutes.  I am using a plain old FileAppender,
> which inherits from WriterAppender, and thus ImmediateFlush should force
> the writes to take place within seconds at most.
> 
> If I do not kill the process, then the writes take place either when we
> have a few k in the log buffer, or when the process terminates
> gracefully.  This is normal behavior for buffered output, but I even tried
> explicitly setting ImmediateFlush to see if that made a difference.
> 
> NB - there is quite a bit of time where the program sits idle, so I know
> that the initial message is not getting swallowed by threading or something
> similarly vile.
> 
> I have tried both 1.1.3 and 1.1.2.
> 
> So, can anyone confirm that FileWriter is honoring the immediate flush
> requests under Windows and JDK 1.3.1?
> 
> The config file is below.
> 
> log4j.rootCategory=DEBUG, A_log
> 
> log4j.appender.A_log=org.apache.log4j.FileAppender
> log4j.appender.A_log.Threshold=DEBUG
> log4j.appender.A_log.File=pov.log
> log4j.appender.A_log.ImmediateFlush=true
> log4j.appender.A_log.Append=false
> log4j.appender.A_log.layout=org.apache.log4j.PatternLayout
> log4j.appender.A_log.layout.ConversionPattern=%d (%r) %-5p %-30c{2} - %m\n
> 
> log4j.category.com.isisph.bioinfo.general.POV=DEBUG
> Scott Ellsworth
> scott@alodar.com
> 


Scott:

I observed a similar behaviour but with a different appender (a custom
RMI appender). It had to deregister with rmiregistry on shutdown. A
managed this for proper exiting of the application. However, this didn't
work when, for example, the application got killed via Ctrl-C or
something similar.

My solution to this was adding a shudown hook to my application.
Registering the shutdown hook was like

	// allocate thread which runs when the Java vm gets killed.
	allocateCleanupThread();

	// register that thread with the runtime
	Runtime runtime = java.lang.Runtime.getRuntime();
	runtime.addShutdownHook( cleanupThread );

Where's the best place to put this? The main() or the constructor of the
class holding the resource?

I have an attribute as follows:

        CleanupThread cleanupThread;

which is defined as follows (as an inner class):

    class CleanupThread extends Thread
    {
        public void run() {
            cleanupResources();
        }
    }

The method allocateCleanupThread() may look as follows:

    public void allocateCleanupThread () {
	if( cleanupThread == null ) {
	    cleanupThread = new CleanupThread();
	    //System.out.println( "cleanupThread has been created." );
	}
    }

As said above, I used it to deregister from rmiregistry on sudden Java
virtual machine shutdown via Ctrl-C. But maybe you can use such a thing
also to flush streams or do other resource cleanups.

HTH

Regards
Claus Wagner

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: log4j-user-help@jakarta.apache.org