1

Consider the following code:

Thread t1 = new Thread(() -> {
  System.out.println("t1 running");
  System.err.println("foo 1");
});
Thread t2 = new Thread(() -> {
  System.out.println("t2 running");
  System.out.println("foo 2");
});
Thread t3 = new Thread(() -> {
  System.out.println("t3 running");
  System.out.println("foo 3");
});

t1.start();
t1.join();
t2.start();
t2.join();
t3.start();
t3.join();

All of the threads above is supposed to execute sequentially since I'm not starting them all at once and I do call Thread.join() on each of them to block the main thread from executing until each has been executed. I'd expect the following atomic output:

t1 running
foo 1
t2 running
foo 2
t3 running
foo 3

But this is the actual result, which does kind of confuse me:

t1 running
t2 running
foo 2
t3 running
foo 3
foo 1

As far as I'm concerned the only possible reason for that would be if there was another thread created for System.err under the hood printing "foo 1". Please do enlighten me on what is the real cause for such behaviour.

  • 2
    maybe the `out` and `err` streams are being flushed differently? – mhrsalehi Jul 01 '22 at 17:07
  • 1
    Add `System.out.flush();` to the end of each thread. (And add `System.err.flush();` to the end of the first thread.) System out and System error are buffered, usually. – VGR Jul 01 '22 at 17:09
  • 2
    I think this is a "problem" on the terminal side, not the Java side. As in, this depends on the order that the terminal reads the two different streams of the Java process. – Slaw Jul 01 '22 at 17:09
  • 1
    @VGR Even with flushing both `out` and `err` in each thread, I still see "foo 1" sometimes appear first, and sometimes appear last. – Slaw Jul 01 '22 at 17:10
  • @VGR no luck, same output. – her0ftheday Jul 01 '22 at 17:11
  • 1
    Have a look explaining at this Gemnastic's answer https://stackoverflow.com/questions/1883321/system-out-println-and-system-err-println-out-of-order – Sergey Afinogenov Jul 01 '22 at 17:17
  • 1
    Strangely (or maybe not), I only see this out-of-order printing in IntelliJ and running the program via Gradle. Using `javac` + `java` in Window's terminal, with or without flushing, I see the expected output every time (though that's no guarantee). – Slaw Jul 01 '22 at 17:21
  • 1
    @VGR flush doesn't guarantee the order. – mhrsalehi Jul 01 '22 at 17:24
  • 4
    OutputStream performs flush method. If the intended destination of this stream is an abstraction provided by the underlying operating system, then flushing the stream guarantees only that bytes previously written to the stream are passed to the operating system for writing; it does not guarantee that they are actually written. – Sergey Afinogenov Jul 01 '22 at 17:30

1 Answers1

3

of course the code executes sequentially, you can check this(not by checking logs order in different streams!):

    AtomicInteger counter = new AtomicInteger(0);
    Thread t1 = new Thread(() -> {
        System.out.println("t1 running [" + counter.incrementAndGet() + "]");
        System.err.println("foo 1 [" +counter.incrementAndGet() +"]");
    });
    Thread t2 = new Thread(() -> {
        System.out.println("t2 running [" +counter.incrementAndGet() +"]");
        System.out.println("foo 2 [" + counter.incrementAndGet() +"]");
    });
    Thread t3 = new Thread(() -> {
        System.out.println("t3 running [" + counter.incrementAndGet() +"]");
        System.out.println("foo 3 [" + counter.incrementAndGet()+"]");
    });

    t1.start();
    t1.join();
    t2.start();
    t2.join();
    t3.start();
    t3.join();

output:

t1 running [1]
t2 running [3]
foo 2 [4]
t3 running [5]
foo 3 [6]
foo 1 [2]

note that the out and err streams can being flushed differently (in my case I see the correct expected order when I run this code in terminal, but I see the incorrect order when I run in IntelliJ, see this)

mhrsalehi
  • 1,124
  • 1
  • 12
  • 29