System.out.println prints out of order in Play Framework console

Question

I'm using Play 2.4 with Activator 1.3.7, and I'm noticing System.out.println doesn't always print in order to the console in the browser. It's pretty rare, but I caught it in action today. Here's the order of the print statements:

    System.out.println("width : " + mobileCrawl.getWidth());
    System.out.println("window width : " + mobileCrawl.getWindowWidth());
    System.out.println("scroll width : " + mobileCrawl.getScrollWidth());
    System.out.println("seed : " + mobileCrawl.getSeed());
    System.out.println("resolved seed : " + mobileCrawl.getResolvedSeed());
    System.out.println("crawl date : " + mobileCrawl.getCrawlDate());
    System.out.println("400 : " + mobileCrawl.isDetected400());
    System.out.println("401 : " + mobileCrawl.isDetected401());
    System.out.println("402 : " + mobileCrawl.isDetected402());
    System.out.println("403 : " + mobileCrawl.isDetected403());
    System.out.println("404 : " + mobileCrawl.isDetected404());
    System.out.println("500 : " + mobileCrawl.isDetected500());
    System.out.println("501 : " + mobileCrawl.isDetected501());
    System.out.println("502 : " + mobileCrawl.isDetected502());
    System.out.println("503 : " + mobileCrawl.isDetected503());

And here is the order it printed in (URLs are changed):

width : 980
window width : 980
scroll width : 980
seed : http://google.com/
resolved seed : https://www.google.com/
400 : false
401 : false
402 : false
crawl date : Fri Dec 18 11:18:09 MST 2015
403 : false
500 : false
404 : true
501 : false
502 : false
503 : false

The date printed three lines after it should have. These are all print statements coming from the same thread, they are all from System.out, not any from System.err, so there shouldn't be any interleaving.

How can these print out of order? I thought System.out guaranteed order.

When you say "to the console in the browser" you mean you get this output in the Activator UI console (ie in your browser)? If so this happens in the console (terminal) also? — Salem, Dec 18 '15 at 20:25
@Salem yes, this is the output in the Activator UI Console. I'm not aware of any other console available for me to check. I can't easily run this code in an environment outside of Activator. — Indigenuity, Dec 18 '15 at 21:09
This should never happen when you are running under single thread. Any chance this output is from multiple threads? — Max, Jan 01 '16 at 01:14

score 0 · Answer 1 · answered Mar 09 '16 at 14:30

0

As Max commented, that shouldn't happen if you're running single-threaded. Maybe try synchronizing your calls to see if something is messing with your threads without your knowledge?:

public synchronized void println(String s) { System.out.println(s); }

answered Mar 09 '16 at 14:30

Mike

159
10

These print statements are all in the same method. There's no way a method is going to be executed half on one thread and half on another. – Indigenuity Mar 09 '16 at 18:02
`PrintStream.println()` already contains synchronization, so one more layer of synchromization will not be sure to alter the behaviour. – Ole V.V. Dec 03 '16 at 09:30

System.out.println prints out of order in Play Framework console

1 Answers1