Inconsistency using Java's volatile keyword

Question

I have the following program:

class Resource {
    static volatile int i = 0;
}

class MyThread extends Thread {
    Resource resource;
    String name;
    public MyThread(Resource resource, String name ) {
        this.resource = resource;
        this.name = name;
    }
    
    @Override
    public void run() {
        int count = 1;
        while(count <= 1000) {
            if ("T1".equals(name)) {
                if (count % 5 == 0) {
                    resource.i = count;
                    System.out.println(name + ", Resource's value = " + resource.i);
                }
            } else {
                System.out.println(name + ", Resource's value = " + resource.i);
            }
            count++;
        }
    }
}

public class TestVolatile {

    public static void main(String[] args) {
        Resource resource =  new Resource();
        new MyThread(resource, "T1").start();
        new MyThread(resource, "T2").start();
        new MyThread(resource, "T3").start();
    }
}

---

Based on some condition, I am setting the value of volatile variable by one thread named T1, expecting the value to be reflected in other two threads T2 and T3. I am doing an atomic operation, but I am getting unexpected output:

T2, Resource's value = 20
T2, Resource's value = 20
T2, Resource's value = 20
T2, Resource's value = 20
T2, Resource's value = 20
T1, Resource's value = 20
T1, Resource's value = 25
T1, Resource's value = 30
T1, Resource's value = 35
T3, Resource's value = 20
T3, Resource's value = 40
T3, Resource's value = 40
T3, Resource's value = 40
T3, Resource's value = 40
T1, Resource's value = 40
T3, Resource's value = 40
T1, Resource's value = 45
T1, Resource's value = 50
T1, Resource's value = 55
T1, Resource's value = 60
T3, Resource's value = 45
T3, Resource's value = 65
T3, Resource's value = 65
.
.

My understanding is once T1 sets the values into Resource's i, following it, printing Resource's i value under T2 and T3 should have been the same value set by T1. In output line 9, T1 = 35 but in line 10, T3 = 20. How come ? I am not doing any non atomic operation. Kindly let me know if I am missing out something. Thanks.

Answer 1

Even if code looks like "one-liner", behind the scene it is not

T1 does within if (count%5 == 0)

write resource.i
concatenate `name` and static text
read resource.id
concatenate previous text and value of resource.i 
call System.out.println 

T2 and T3 do

concatenate `name` and static text
read resource.id
concatenate previous text and value of resource.i 
call System.out.println 

All operations above are executed concurrently, so one of possible timelines could be

T2 concatenate `name` and static text
T2 read resource.id
T1 write resource.i
T1 concatenate `name` and static text
T1 read resource.id
T1 concatenate previous text and value of resource.i 
T1 call System.out.println 
T2 concatenate previous text and value of resource.i 
T2 call System.out.println 

Answer 2

IMO, Your problem is here:

System.out.println(name + ", Resource's value = " + resource.i);

That is not an atomic operation. It must at least;

• Fetch the value of resource.i,
• Convert the value to decimal notation,
• Construct a new String by copying the values of name and the given literal string and the decimal number previously computed,
• And then finally, it must call System.out.println on the new string.

It might do more than that (e.g., it might construct more than just one new object).

A lot can happen in between the moment when a calling thread fetches the value of resource.i and the moment when it finally enters a synchronized statement somewhere within the System.out.println call. For example, It's entirely believable that the T1 thread could call println three times in between the moment when the T3 thread fetches resource.i (value equals 20), and the moment when the T3 thread finally calls println with the string, "T3, Resource's value = 20".