Java: Redirecting System.out and System.err to a rolling log file


Something really nice about Java is its extensible logging subsystem.  It's kind of like syslog, but more powerful due to its pluggability.

One thing which is really useful is its auto-management of rolling log files, ensuring that the filesystem will never get full due to huge amounts of logs.

Something I've been hit with on various occasions when using code I've inherited from elsewhere is sporadic use of stdout and stderr from code in jars that I don't control, with calls to System.out.println(). System.err.println(), and ex.printStackTrace(). These are usually rarely called, generally in exception handlers, and it can be hard to make sure that there aren't any at all! These outputs are typically used for debugging, but they aren't something I want showing up on my console when running my Java app... I'd rather it go to a file, but I don't want the possibility of a file growing for ever and risk filling up the filesystem.

This blog article shows how to redirect System.out and System.err to your logging subsystem, so that such output gets integrated into your debugging log stream, this is something we do out-of-the-box in the open-source Common Agent Container project, which is used in various products including in our management stacks for system and data-center management -  xVM Ops Center and xVM Server.

Defining two new Logger Levels

Java Log records are written by a given Logger at a given logging Level.  For each Logger, one can filter log records by Level. It's useful for us to define our own log levels for stdout and stderr in order to permit the easy filtering of these messages, and in order for these messages to stand out from ordinary log messages in the log file.


import java.io.InvalidObjectException;
import java.io.ObjectStreamException;
import java.util.logging.Level;

/\*\*
 \* Class defining 2 new Logging levels, one for STDOUT, one for STDERR,
 \* used when multiplexing STDOUT and STDERR into the same rolling log file
 \* via the Java Logging APIs.
 \*/
public class StdOutErrLevel extends Level {

    /\*\*
     \* Private constructor
     \*/
    private StdOutErrLevel(String name, int value) {
        super(name, value);
    }
    /\*\*
     \* Level for STDOUT activity.
     \*/
    public static Level STDOUT =
        new StdOutErrLevel("STDOUT", Level.INFO.intValue()+53);
    /\*\*
     \* Level for STDERR activity
     \*/
    public static Level STDERR =
        new StdOutErrLevel("STDERR", Level.INFO.intValue()+54);

    /\*\*
     \* Method to avoid creating duplicate instances when deserializing the
     \* object.
     \* @return the singleton instance of this <code>Level</code> value in this
     \* classloader
     \* @throws ObjectStreamException If unable to deserialize
     \*/
    protected Object readResolve()
        throws ObjectStreamException {
        if (this.intValue() == STDOUT.intValue())
            return STDOUT;
        if (this.intValue() == STDERR.intValue())
            return STDERR;
        throw new InvalidObjectException("Unknown instance :" + this);
    }       

}

Two new Log Levels

Creating a LoggingOutputStream

System.out and System.err are PrintStream objects. We can replace them with our own PrintStream instances that write to our own OutputStreams... in this case, we implement a LoggingOutputStream that writes log records.

Note that in order to avoid lots of blank log records, we don't write a record if flush() is called twice in a row, or with just a blank line.

import java.io.ByteArrayOutputStream; 
import java.io.IOException; 
import java.util.logging.Level; 
import java.util.logging.Logger; 
 
/\*\* 
 \* An OutputStream that writes contents to a Logger upon each call to flush() 
 \*/ 
class LoggingOutputStream extends ByteArrayOutputStream { 
 
    private String lineSeparator; 
 
    private Logger logger; 
    private Level level; 
 
    /\*\* 
     \* Constructor 
     \* @param logger Logger to write to 
     \* @param level Level at which to write the log message 
     \*/ 
    public LoggingOutputStream(Logger logger, Level level) { 
        super(); 
        this.logger = logger; 
        this.level = level; 
        lineSeparator = System.getProperty("line.separator"); 
    } 
 
    /\*\* 
     \* upon flush() write the existing contents of the OutputStream
     \* to the logger as a log record. 
     \* @throws java.io.IOException in case of error 
     \*/ 
    public void flush() throws IOException { 
 
        String record; 
        synchronized(this) { 
            super.flush(); 
            record = this.toString(); 
            super.reset(); 
 
            if (record.length() == 0 || record.equals(lineSeparator)) { 
                // avoid empty records 
                return; 
            } 
 
            logger.logp(level, "", "", record); 
        } 
    } 
} 
Our LoggingOutputStream writes a log record on each call to flush()

Initializing Logging to go to a rolling file

Now we've got all the bits to write from a PrintStream to a Logger, so let's set up our application:

First of all, we set up the logging system so that, instead of writing to stdout, log records are written to a rotating log file:

public class Main {

 public static void main(String[] args) throws Exception {
        // initialize logging to go to rolling log file
        LogManager logManager = LogManager.getLogManager();
        logManager.reset();

        // log file max size 10K, 3 rolling files, append-on-open
        Handler fileHandler = new FileHandler("log", 10000, 3, true);
        fileHandler.setFormatter(new SimpleFormatter());
        Logger.getLogger("").addHandler(fileHandler);
 
 ...
Initialize logging to go to a rolling log file


Redirecting System.out and System.err to the logging subsystem


Now that log records go to a rotating file, we can redirect System.out and System.err to go to LoggingOutputStreams


        ...

        // preserve old stdout/stderr streams in case they might be useful      
        PrintStream stdout = System.out;                                       
        PrintStream stderr = System.err;                                       

        // now rebind stdout/stderr to logger                                  
        Logger logger;                                                         
        LoggingOutputStream los;                                               

        logger = Logger.getLogger("stdout");                                   
        los = new LoggingOutputStream(logger, StdOutErrLevel.STDOUT);          
        System.setOut(new PrintStream(los, true));                             

        logger = Logger.getLogger("stderr");                                   
        los= new LoggingOutputStream(logger, StdOutErrLevel.STDERR);           
        System.setErr(new PrintStream(los, true));                             

        ...
Redirecting System.out and System.err to go to a LoggingOutputStream

Showing this in action

And here's some code showing how System.out and System.err are redirected to the log file


        ...
        // show stdout going to logger
        System.out.println("Hello world!");

        // now log a message using a normal logger
        logger = Logger.getLogger("test");
        logger.info("This is a test log message");

        // now show stderr stack trace going to logger
        try {
            throw new RuntimeException("Test");
        } catch (Exception e) {
            e.printStackTrace();
        }

        // and output on the original stdout
        stdout.println("Hello on old stdout");


    }                                                                          

}                                                                              

Sample writes to stdout and stderr

And here's what the output looks like... the usual writes to System.out and System.err have now gone to our rotating log file:



$ java Main
Hello on old stdout
$ cat log.0
STDOUT: Hello world!
Jan 18, 2007 2:11:38 PM Main main
INFO: This is a test log message
Jan 18, 2007 2:11:38 PM 
STDERR: java.lang.RuntimeException: Test
Jan 18, 2007 2:11:38 PM 
STDERR:         at Main.main(Main.java:50)

$

Example output


Resources

The sources for this article are here.

Comments:

I am interested in using one of your example files (LoggingOutputStream.java) and would like to know if you have any licensing restrictions. Thank you.

Posted by dorothy on February 21, 2007 at 06:09 PM CET #

Hi Dorothy, The code in this article is free for any use. I'd appreciate having a back-reference URL to the blog article in a comment in the code, but that's all. Thanks for the question! [ Nick ]

Posted by Nick on February 22, 2007 at 03:37 AM CET #

Thanks. I will definitely include the URL to your blog article.

Posted by Dorothy on February 22, 2007 at 10:39 AM CET #

I just wanted to know if it was normal to return in the LoggingOutputStream.flush(). In my case, It ignored all the message I tries to output. I try with
if (record.length() > 0 && !record.equals(lineSeparator))
logger.log(level, record);
And it work perfectly :). Thank you for this article, it was usefull for me.

Posted by Raphaël on February 26, 2007 at 09:03 AM CET #

The indentation could be improved in the article, but the code as shown is the same as yours with the test inverted, isn't it? Anyway, it works for me!

Posted by Nick on February 26, 2007 at 09:41 AM CET #

You were true, I just inverted the test.

I try to output my logging trace and System.out and System.err both in ConsoleHandler and in FileHandler.

The problem seems to be that ConsoleHandler output IS System.err.In this case I can't output Exception in ConsoleHandler and FileHandler at the same time.

Is it true ? have you got a method to do it "cleanly"

Thank you for your great job

Posted by Raphaël on March 02, 2007 at 01:47 AM CET #

Hi Raphael, Attaching a ConsoleHandler to the logger causes the log records it selects to be written to System.err... since my code redirects System.err to be written to log records, you get an infinite loop. This sounds like a weird thing to be wanting to do, anyway, I cannot imagine a use-case I'd want a ConsoleHandler when writing console output to logs, but if you want to persist, you should either set the logging level of the handler above our newly defined levels or add a Filter object to the ConsoleHandler to reject all log records of level STDERR to avoid the infinite loop. Hope this helps!

Posted by Nick Stephen on March 02, 2007 at 07:46 AM CET #

Post a Comment:
Comments are closed for this entry.
About

nickstephen

Search

Archives
« April 2014
SunMonTueWedThuFriSat
  
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
   
       
Today