java - How to keep sysout and syserr streams from intermixing?

Question

In my code base is the (very simplified) following:

public static void main (String[] args) {
   System.out.println("Starting application");
   try {
      System.out.println("About to validate");
      validate(args);
   catch (Exception e) {
      e.printStackTrace();
   }
}

public static void validate(String[] args) {
   System.out.println("Your first arg is " + args[0]);
   if (someProblemWith(args)) {
      System.out.println("Your args are wrong.  It should be: ...");
      throw new BadArgsException(e);
   }
}

Which works fine. Note that my example code above is contrived and simply meant to show multiple log statements prior to exception and stack trace printing. This often means that my last logging statement is lost in the middle of the stack trace output. Is there an elegant way to ask the e.printStackTrace() statement to wait until the System.out has finished its work? I'm essentially looking for the stacktrace to be the very last thing printed when an error occurs. Here's a sample output of my program above:

 java.lang.Throwable
 ....
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 Your args are wrong.  It should be: ...
 at java.lang.reflect.Method.invoke(Method.java:597)
 at org.eclipse.jdt.internal.jarinjarloader.JarRsrcLoader.main(JarRsrcLoader.java:56)

Answer 1

The reason you are seeing the stack trace being printed between the System.out.println() statements, is because System.out is buffered, while System.err (used by stack trace) is unbuffered.

If you want the text to be displayed in the exact order in which things are happening, you need to "unbuffer" the System.out. The simplest way is to also just use System.err there instead of System.out.

Otherwise, call System.out.flush() before your stack traces happen in the catch clauses.

Option 2: Use the Logger class.

Option 3: Implement your own "buffer". In other words, first write everything to your own buffer, including the stack traces (using .toString() or however you wish) and then in the catch flushing you own buffer. (This is kind of redundant since you can just flush the System.out anyway).

-==-

FROM COMMENT

Sure. The Logger class can be used to create a much more robust and detailed logging experience. This is typically what is done in applications. An instance of the Logger class is grabbed from the Logger class (it is a singleton), taking as parameter the class from which is will be used. Then you log messages to it by using the .log() method. The nice thing about the Logger class is that you can set levels on it (example DEBUG, WARN...) and you are then able to filter / display only what you want. The "log" messages are then displayed in a uniform way in the console, typically in the format of:

2010-11-23 14:45:32,032 DEBUG [MyClass] Your message

The above format is from log4j, but you can use the standard Java Logger. The output should be similar, maybe a bit less. But I'm sure it can be configured.