Adding System.out.printlns causes tsan to miss a race?

[Jiri Daněk]

The following program contains unsynchronized access to a variable. When
the VERBOSE variable is false, jdk-tsan prints the appropriate warning.
When VERBOSE is set to true in the source code, no race is reported on my
machine.

Is this expected behavior at this stage of the project, or is there already
a relevant configuration option that would detect this race all the time?

I remember I saw this sort of problem discussed somewhere in relation to
tsan, or maybe DiViNe (https://divine.fi.muni.cz/): how much
synchronization does doing I/O imply.

I compiled jdk-tsan with gcc9, because I had issues compiling with clang_8
on nixOS. Does that make the test above invalid? I presume I could use
ubuntu in docker, if asked.

///Using jdk-tsan at commit///

changeset:   54170:dc19f181c3b9
branch:      tsan
tag:         tip
user:        manc
date:        Wed Jul 17 12:58:33 2019 -0700
summary:     Add a configure flag --<enable|disable>-tsan-launcher.

///command///

I am using just the -XX:+ThreadSanitizer flag with java

///Hello.java///

public class Main {
    private static boolean VERBOSE = false;

    public static void main(String[] args) {
        var ref = new Object() {
            int a = 5;
        };
        System.out.println("Hello World!");
        if (VERBOSE) System.out.println("pes");

        Thread t = new Thread(()-> {
            if (VERBOSE) System.out.println("pes");
            System.out.println(ref.a);
            if (VERBOSE) System.out.println("pes");
            ref.a = 6;
            if (VERBOSE) System.out.println("pes");
        });
        if (VERBOSE) System.out.println("pes");
        t.start();

        if (VERBOSE) System.out.println("pes");
        ref.a = 7;
        if (VERBOSE) System.out.println("pes");
        System.out.println(ref.a);
        if (VERBOSE) System.out.println("pes");
    }
}

///output of jdk-tsan with VERBOSE=false///

Hello World!
7
==================
WARNING: ThreadSanitizer: data race (pid=11124)
  Read of size 4 at 0x00066382ed8c by thread T15:
    #0 Main.lambda$main$0(LMain$1;)V Main.java:13
    #1 Main$$Lambda$38.run()V ??
    #2 java.lang.Thread.run()V Thread.java:835
    #3 (Generated Stub) <null>

  Previous write of size 4 at 0x00066382ed8c by thread T1:
    #0 Main.main([Ljava/lang/String;)V Main.java:22
    #1 (Generated Stub) <null>
    #2
jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;
NativeMethodAccessorImpl.java:62
    #3
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;
DelegatingMethodAccessorImpl.java:43
    #4
java.lang.reflect.Method.invoke(Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;
Method.java:567
    #5
com.intellij.rt.execution.application.AppMainV2.main([Ljava/lang/String;)V
AppMainV2.java:131
    #6 (Generated Stub) <null>

  Thread T15 (tid=11140, running) created by thread T1 at:
    #0 pthread_create <null> (libtsan.so.0+0x3055b)
    #1 os::create_thread(Thread*, os::ThreadType, unsigned long)
/home/jdanek/repos/jdk-tsan/src/hotspot/os/linux/os_linux.cpp:774
(libjvm.so+0xbd3345)
    #2 java.lang.Thread.start()V Thread.java:804
    #3 Main.main([Ljava/lang/String;)V Main.java:19
    #4 (Generated Stub) <null>
    #5
jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;
NativeMethodAccessorImpl.java:62
    #6
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;
DelegatingMethodAccessorImpl.java:43
    #7
java.lang.reflect.Method.invoke(Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;
Method.java:567
    #8
com.intellij.rt.execution.application.AppMainV2.main([Ljava/lang/String;)V
AppMainV2.java:131
    #9 (Generated Stub) <null>

  Thread T1 (tid=11126, running) created by main thread at:
    #0 pthread_create <null> (libtsan.so.0+0x3055b)
    #1 CallJavaMainInNewThread
/home/jdanek/repos/jdk-tsan/src/java.base/unix/native/libjli/java_md_solinux.c:769
(libjli.so+0xa3c8)

SUMMARY: ThreadSanitizer: data race Main.java:13 in
Main.lambda$main$0(LMain$1;)V
==================
7
ThreadSanitizer: reported 1 warnings
ThreadSanitizer: reported 1 warnings
-- 
Mit freundlichen Grüßen / Kind regards
Jiri Daněk