search

ziglang / zig

General-purpose programming language and toolchain for maintaining robust, optimal, and reusable software.
https://ziglang.org
MIT License
32.09k stars 2.34k forks source link

`zig test -fsanitize-thread` reports data race warning in std.Progress #20477

Open EspeuteClement opened 3 days ago

EspeuteClement commented 3 days ago

Zig Version

0.14.0-dev.130+cb308ba3a

Steps to Reproduce and Observed Behavior

Tested with ubuntu in WSL

run the following code using zig test -fsanitize-thread test.zig

const std = @import("std");
test "1" {
    std.time.sleep(1 * std.time.ns_per_s);
}

test "2" {
    std.time.sleep(2 * std.time.ns_per_s);
}

test "3" {
    std.time.sleep(3 * std.time.ns_per_s);
}

test "4" {
    std.time.sleep(4 * std.time.ns_per_s);
}

Observe the ThreadSanitizer reporting data races.

run output : 

WARNING: ThreadSanitizer: data race (pid=1182)
  Write of size 4 at 0x55ff091d30dc by main thread:
    #0 Progress.Node.init /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Progress.zig:288:9 (test+0xf6617)
    #1 Progress.Node.start /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Progress.zig:193:28 (test+0xdd3ec)
    #2 test_runner.mainTerminal /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/compiler/test_runner.zig:151:42 (test+0x9cd41)
    #3 test_runner.main /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/compiler/test_runner.zig:35:28 (test+0x91e04)
    #4 start.callMain /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/start.zig:505:22 (test+0x916db)
    #5 start.callMainWithArgs /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/start.zig:473:20 (test+0x916db)
    #6 main /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/start.zig:488:75 (test+0x916db)

  Previous atomic read of size 4 at 0x55ff091d30dc by thread T1:
    #0 Progress.serialize /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Progress.zig:770:73 (test+0x155452)
    #1 Progress.computeRedraw /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Progress.zig:1052:33 (test+0x15637f)
    #2 Progress.updateThreadRun /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Progress.zig:465:40 (test+0x145aef)
    #3 Thread.callFn__anon_10006 /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Thread.zig:408:13 (test+0x129350)
    #4 Thread.PosixThreadImpl.spawn__anon_9767.Instance.entryFn /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Thread.zig:677:30 (test+0x107235)

  As if synchronized via sleep:
    #0 nanosleep /home/valden/zig/master/files/lib/tsan/tsan_interceptors_posix.cpp:395:3 (test+0x170e97)
    #1 posix.nanosleep /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/posix.zig:5434:39 (test+0x91fd9)
    #2 time.sleep /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/time.zig:53:20 (test+0x912c7)
    #3 no_sanitize_thread.test.1 /mnt/c/Users/Valden/Documents/Documents/DEV/zig/zigsandbox/no_sanitize_thread.zig:3:19 (test+0x91276)
    #4 test_runner.mainTerminal /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/compiler/test_runner.zig:155:25 (test+0x9cd79)
    #5 test_runner.main /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/compiler/test_runner.zig:35:28 (test+0x91e04)
    #6 start.callMain /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/start.zig:505:22 (test+0x916db)
    #7 start.callMainWithArgs /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/start.zig:473:20 (test+0x916db)
    #8 main /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/start.zig:488:75 (test+0x916db)

  Location is global 'Progress.node_storage_buffer' of size 3984 at 0x55ff091d30ac (test+0x2630dc)

  Thread T1 (tid=1184, running) created by main thread at:
    #0 pthread_create /home/valden/zig/master/files/lib/tsan/tsan_interceptors_posix.cpp:1020:3 (test+0x172cff)
    #1 Thread.PosixThreadImpl.spawn__anon_9767 /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Thread.zig:695:33 (test+0x106f33)
    #2 Thread.spawn__anon_9599 /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Thread.zig:341:32 (test+0xf6ca1)
    #3 Progress.start /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Progress.zig:407:55 (test+0xdd04f)
    #4 test_runner.mainTerminal /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/compiler/test_runner.zig:130:41 (test+0x9cb19)
    #5 test_runner.main /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/compiler/test_runner.zig:35:28 (test+0x91e04)
    #6 start.callMain /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/start.zig:505:22 (test+0x916db)
    #7 start.callMainWithArgs /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/start.zig:473:20 (test+0x916db)
    #8 main /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/start.zig:488:75 (test+0x916db)

SUMMARY: ThreadSanitizer: data race /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Progress.zig:288:9 in Progress.Node.init
==================
==================
WARNING: ThreadSanitizer: data race (pid=1182)
  Write of size 4 at 0x55ff091d30e0 by main thread:
    #0 Progress.Node.init /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Progress.zig:290:56 (test+0xf664d)
    #1 Progress.Node.start /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Progress.zig:193:28 (test+0xdd3ec)
    #2 test_runner.mainTerminal /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/compiler/test_runner.zig:151:42 (test+0x9cd41)
    #3 test_runner.main /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/compiler/test_runner.zig:35:28 (test+0x91e04)
    #4 start.callMain /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/start.zig:505:22 (test+0x916db)
    #5 start.callMainWithArgs /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/start.zig:473:20 (test+0x916db)
    #6 main /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/start.zig:488:75 (test+0x916db)

  Previous atomic read of size 4 at 0x55ff091d30e0 by thread T1:
    #0 Progress.serialize /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Progress.zig:769:79 (test+0x155407)
    #1 Progress.computeRedraw /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Progress.zig:1052:33 (test+0x15637f)
    #2 Progress.updateThreadRun /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Progress.zig:465:40 (test+0x145aef)
    #3 Thread.callFn__anon_10006 /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Thread.zig:408:13 (test+0x129350)
    #4 Thread.PosixThreadImpl.spawn__anon_9767.Instance.entryFn /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Thread.zig:677:30 (test+0x107235)

  As if synchronized via sleep:
    #0 nanosleep /home/valden/zig/master/files/lib/tsan/tsan_interceptors_posix.cpp:395:3 (test+0x170e97)
    #1 posix.nanosleep /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/posix.zig:5434:39 (test+0x91fd9)
    #2 time.sleep /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/time.zig:53:20 (test+0x912c7)
    #3 no_sanitize_thread.test.1 /mnt/c/Users/Valden/Documents/Documents/DEV/zig/zigsandbox/no_sanitize_thread.zig:3:19 (test+0x91276)
    #4 test_runner.mainTerminal /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/compiler/test_runner.zig:155:25 (test+0x9cd79)
    #5 test_runner.main /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/compiler/test_runner.zig:35:28 (test+0x91e04)
    #6 start.callMain /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/start.zig:505:22 (test+0x916db)
    #7 start.callMainWithArgs /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/start.zig:473:20 (test+0x916db)
    #8 main /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/start.zig:488:75 (test+0x916db)

  Location is global 'Progress.node_storage_buffer' of size 3984 at 0x55ff091d30ac (test+0x2630e0)

  Thread T1 (tid=1184, running) created by main thread at:
    #0 pthread_create /home/valden/zig/master/files/lib/tsan/tsan_interceptors_posix.cpp:1020:3 (test+0x172cff)
    #1 Thread.PosixThreadImpl.spawn__anon_9767 /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Thread.zig:695:33 (test+0x106f33)
    #2 Thread.spawn__anon_9599 /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Thread.zig:341:32 (test+0xf6ca1)
    #3 Progress.start /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Progress.zig:407:55 (test+0xdd04f)
    #4 test_runner.mainTerminal /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/compiler/test_runner.zig:130:41 (test+0x9cb19)
    #5 test_runner.main /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/compiler/test_runner.zig:35:28 (test+0x91e04)
    #6 start.callMain /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/start.zig:505:22 (test+0x916db)
    #7 start.callMainWithArgs /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/start.zig:473:20 (test+0x916db)
    #8 main /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/start.zig:488:75 (test+0x916db)

SUMMARY: ThreadSanitizer: data race /home/valden/zig/0.14.0-dev.130+cb308ba3a/files/lib/std/Progress.zig:290:56 in Progress.Node.init

Expected Behavior

no warnings emitted from -fsanitize-threads

andrewrk commented 3 days ago

Nice find. Looks like this can be solved simply by making those writes atomic.

Edit: Hmm, actually, I think this may be a false positive from TSAN. Are false positives possible from TSAN? :thinking:

Either way, I think triggering TSAN is sufficient for bug status.