CODEWITHSUNDEEP
javamultithreading
a3y3
a3y3

Reputation: 1191

Java MultiThreading output seemingly ambiguous on thread-safe System.out

Here is my code:

class Question extends Thread    {
    static String info;

    public Question(String info )    {
        this.info = info;
    }
    private void inProtected () {
        synchronized ( info )       {
            System.out.println("--> " + info +  " Hi");
            System.out.println("<-- " + info +  " Hi");
        }
    }

    public void run () {
        inProtected();
    }
    public static void main (String args []) {
        new Question("a").start();
        try {
            sleep(1);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        new Question("ab").start();

    }
}

This code produces sometimes, an output like this:

--> ab Hi
--> a Hi //Wait a second, what? How can "a" print after "ab"?
<-- ab Hi
<-- ab Hi

I've looked at the code of System.out and several answers on StackOverflow and I know for a fact that System.out is thread safe. Then, how is this execution order possible, given info is static, and the main thread creates the two threads (with "a" and "ab") in order?

Edit: I am perfectly aware that the method inProtected is not synchronized since the value is changed by the different threads. My question is, how is it possible that "a" prints after "ab", since the main thread creates the threads in order, which consequently modify the static variable info?

Upvotes: 1

Views: 184

Answers (2)

Oleksandr Pyrohov
Oleksandr Pyrohov

Reputation: 16216

The System.out.print in the synchronized block isn't protected by the same lock ("a" and "ab" are different String objects), therefore inProtected isn't actually protected.

Also, the order in which the threads are executed is determined by the operating system. There are no guarantees that new Question("a") will be started before new Question("ab").

Update:

The weird thing is, I can't replicate the behavior if I remove the sleep in the main method.

the presence of the try { sleep(1) } gives the first thread a possibility to start and read/cache the string "a" prior to the execution of the new Question("ab"), where the value changes to "ab".

By the way, you can replace:

try { sleep(1); } catch (Exception e) { }

with something like:

for (int i = 0; i < 1_000_000; i++);

and you will get a similar behavior as with sleep.

Upvotes: 2

Illyes Istvan
Illyes Istvan

Reputation: 579

This is what happens in you example:

Main thread:

  • create first thread: info = "a" (1)
  • start Thread1 (2)
  • sleep 1 millisecond (3)
  • create second thread: info = "ab" (4)
  • start Thread2 (5)

Thread1:

  • prints first line: "a" (7) -> even though info was already changed to "ab" by Main thread, it is not yet visible to Thread1
  • prints second line: "ab" (8)

Thread2:

  • prints first line: "ab" (6)
  • prints second line: "ab" (9)

Observations

  1. Calling sleep does not offer any contract that Thread1 will start execution before Thread2. It is up to the thread scheduler of the OperatingSystem to decide which thread will start execution first and there is no deterministic ordering between them in this case.
  2. Thread1 can read a stale value from info, since there is no happens before relation on memory actions for this field.

Volatile

To avoid seeing a stale value of the info field, one could declare it as volatile. This will ensure that a write to this field 'happens before; any subsequent read.

More about happens before relations and memory visibility here: Memory Consistency Properties

Upvotes: 2

Related Questions