System.out mysteriously disappears, although the code/line executes

Question

Okay so I have tested this code on java 8, 11, and 14, they all have the same result. This is bad practice and an unrealistic scenario, but I would like to understand the JVM internals that causes this to happen.

If you run this code you will notice that everything except the print part itself of system.out.println inside if execute. At some point with a slightly different java version I managed to get it to print by changing "play" too volatile, but even that doesn't work now.

Please at least test the code before claiming it is simply deadlocking the variables or using the cache, it is not, the if executes and everything inside it works except the print part itself.

public class Main {
    public static void main(String[] args) {
        TestClass t = new TestClass();
        System.out.println("Starting test");
        new MyRunnable(t).start();
        while (true)
            t.testUpdate(System.currentTimeMillis());
    }
}

public class MyRunnable extends Thread {

    private TestClass t;

    public MyRunnable(TestClass t) {
        this.t = t;
    }

    @Override
    public void run() {
        try {
            Thread.sleep(500L);
            t.setPlay(true);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }
}

public class TestClass {
    private boolean play = false;
    private long lastUpdate = 0;
    private long updateRate = 2000;
    private boolean hasSysoBeenHit = false;

    public void testUpdate(long callTime) {
        System.out.println(play);
        System.out.println((callTime-lastUpdate));
        if (this.play && ((callTime-lastUpdate) >= updateRate)) {
            System.out.println("Updating! " + (hasSysoBeenHit = true));

            this.lastUpdate = callTime;
        }
        System.out.println("hasbeenhit? " + hasSysoBeenHit);
    }

    public void setPlay(boolean t) {
        System.out.println("Starting game...");
        this.play = t;
    }
}

Searching on the internet would have explained this quite easily. Well maybe not easy, but you would have found the reason fairly fast. This is because the JVM is collecting the println output of threads. There isn't really a way to get around this, it's just the way the JVM is implemented. If you want to do this you need a different way to get data reported back. Take a look at https://stackoverflow.com/questions/9467759/multiple-threads-using-system-out-println-in-java — Fullslack, Jan 19 '21 at 07:17
What print part doesn't execute? I see no issue, besides the fact that `play` does need to be a `volatile` — areus, Jan 19 '21 at 09:16
How come only "Updating!" gets skipped in this case? everything else keeps printing in that method, all prints are from the same thread except one. It is not outdated, or shared buffer clearly since everything else works. Also areus the fact why it has to be volatile to print (doesn't work for me even then though anymore?) is what I'm after. — Agammar Kekker, Jan 20 '21 at 10:19

score 0 · Answer 1 · answered Jan 21 '21 at 05:06

0

Your code is suffering from a data race on the TestClass.play field: there are 2 threads accessing this field and at least one of them does a write. This is already indicated by @aerus.

If you make the field volatile, the data race gets removed. Look for the volatile variable rule in the Java Memory model.

I would also move the logic for the play checking to the begin of the testUpdate method:

public void testUpdate(long callTime) {
    if(!play)return;
    ...

answered Jan 21 '21 at 05:06

pveentjer

10,545
3
23
40

Did you test the code...? And "improving" it isn't the point of this question. A full on while(true) infinitely shouldn't exist for ticking a game anyways. I know what volatiles are, but if you actually run this code you can see it's not that if() can't access it. In fact, the other thread only accesses it once at all, after 500ms not to mention print play, time and "hasbeenhit" all print fine after 500ms, the side-effect in print (Updating + (hassysobeenhit = true)) turns that boolean true and you can see it. Still no "Updating!" print though. – Agammar Kekker Jan 22 '21 at 06:27

System.out mysteriously disappears, although the code/line executes

1 Answers1