Strange behavior with printStackTrace()

Question

printStackTrace() acts as if it runs in its own thread after waiting for input. Here's my code:

try {
    new Scanner(System.in).nextLine();
    throw new Exception();
} catch (Exception e) {
    e.printStackTrace();
}
System.out.print("STUFF");

I sometimes get the expected output (with STUFF at the end), but sometimes I get this:

blabla // the scanner input
java.lang.ExceptionSTUFF
    at Test.main(Test.java:7)

and sometimes this:

blabla
java.lang.Exception
STUFF   at Test.main(Test.java:7)

Replacing the scanner with System.in.read() yields the same results. Removing the line entirely yields the expected result. In the actual program where I noticed this problem, the stack trace was much longer, and the STUFF output always appeared either as expected or as in the second output above - at the beginning of the second line.

What's causing this, and how can I solve it?

score 4 · Accepted Answer · edited May 23 '17 at 12:21

4

printStackTrace, as per the documentation, prints to the standard error stream:

public void printStackTrace() – Prints this throwable and its backtrace to the standard error stream.

...which is System.err. Then you are writing to System.out. Those two are different streams and therefore get flushed to the actual output at different times. Leaving the code as it is, it is equivalent to the problem outlined in this question.

To fix the issue, you could either manually flush your output streams or print your exception to System.out instead of System.err. You could use the variant of printStackTrace that accepts a PrintStream with standard output as a parameter: e.printStackTrace(System.out);

edited May 23 '17 at 12:21

Community

1
1

answered Jul 07 '15 at 12:03

wonderb0lt

2,035
1
23
37

`e.printStackTrace(System.out)` works well enough, but then eclipse doesn't show the text in red. Doesn't really matter since the program is not meant to be run in eclipse, but I'd still like to get the flush solution to work if possible, so how do I do that? I tried adding `System.out.flush(); System.err.flush();` directly after `e.printStackTrace()`, but the problem persisted. – H.v.M. Jul 07 '15 at 12:24
With really excessive flushing before AND after the `printStackTrace` I could get it mostly consistent, with a `Thread.sleep(100)` consistent (which another answer to the first linked question [suggests](http://stackoverflow.com/a/23706808/660848)) – wonderb0lt Jul 07 '15 at 12:34

score 1 · Answer 2 · edited Jun 20 '20 at 09:12

This is actually not a strange behaviour at all; Java is designed to work this way. For most part it's a feature we all love to have which makes our code run more efficiently than we actually wrote it. And what 'it' refers to is that the JVM is designed to re-arrange and optimize our code into better byte-code than we mere mortal developers can bother with even trying to achieve.

You could look at it a little bit like this; Java is kind of a framework we're using through out code that will do what we want it to, in the most efficient way possible (that it's been programmed with at least). The Java API is the API to the Java framework we're using.

And to tie this back to your code; you're initializing two streams, two buffered streams, one is System.out, one is the printStackTrace(). When you execute your code, Java will re-arrange your code and thread it to run as optimal as Java can make it. This means that which ever stream completes first will get to print to console.

Java has no value in what gets printed when, that's a value we humans have; we have a preference in reading things in special orders. That's why Java is a challenge for us developers to write thread-safe code that doesn't care when it gets executed; given the same input it should always return the same output.

Since your System.out stream is faster to print than the stack-trace stream it will probably always print ahead of the stacktrace since they are buffered streams. Buffered streams require time to buffer, something that's both threading and differently time-consuming. Why shouldn't Java give you the stream that's done first and free up that thread and CPU?

Solution:

You should try to counter this by designing your code in a manner where it doesn't matter which gets printed when.

score 0 · Answer 3 · answered Jul 07 '15 at 12:02

This is the nature of printing things to the console. Everything, standard out, standard error, etc is spooled up to be printed out to the console, but because java is inherently multi-threaded, there's no guarantee for what order these items get added to the queue for printing.

Multi-threading can do funky things!

Strange behavior with printStackTrace()

3 Answers3

Solution:

Related