ThreadSanitizer triggers when calling fmt::print from multiple threads on at least `GCC 12.2` up to and including `GCC 14.3`

[jobpaardekooper]

ThreadSanitizer triggers when calling fmt::print from multiple threads on at least x86_64 GCC 12.2 up to and including GCC 14.3

Minimal reproducible example:

https://godbolt.org/z/bGGxEc1oh

On the left, there is GCC 15.1 where I have not seen it trigger yet. On the right is GCC 12.2 where ThreadSanitizer triggers with very high consistency.

If this is a false positive, would it be possible to solve this by adding annotations to FMT ?

Godbolt does not show the full ThreadSanitizer log so here is one that I have from GCC 12.2 my local compilation:

>>> TSAN_OPTIONS=halt_on_error=1 playground
==================
WARNING: ThreadSanitizer: data race (pid=53700)
  Read of size 8 at 0x7fae30207788 by thread T2:
    #0 fmt::v12::detail::glibc_file<_IO_FILE>::init_buffer() ../subprojects/fmt/include/fmt/format-inl.h:1528 (targets_playground+0x25d4b)
    #1 fmt::v12::detail::file_print_buffer<_IO_FILE, void>::file_print_buffer(_IO_FILE*) ../subprojects/fmt/include/fmt/format-inl.h:1681 (targets_playground+0x22798)
    #2 fmt::v12::vprint(_IO_FILE*, fmt::v12::basic_string_view<char>, fmt::v12::basic_format_args<fmt::v12::context>) ../subprojects/fmt/include/fmt/format-inl.h:1740 (targets_playground+0x15eb3)
    #3 fmt::v12::vprint(fmt::v12::basic_string_view<char>, fmt::v12::basic_format_args<fmt::v12::context>) ../subprojects/fmt/include/fmt/format-inl.h:1752 (targets_playground+0x16054)
    #4 void fmt::v12::print<>(fmt::v12::fstring<>::t) ../subprojects/fmt/include/fmt/base.h:2963 (targets_playground+0x1270f)
    #5 operator() ../source/targets/playground/main.cpp:16 (targets_playground+0x1270f)
    #6 __invoke_impl<void, main()::<lambda()> > /usr/include/c++/12/bits/invoke.h:61 (targets_playground+0x131a0)
    #7 __invoke<main()::<lambda()> > /usr/include/c++/12/bits/invoke.h:96 (targets_playground+0x1311b)
    #8 _M_invoke<0> /usr/include/c++/12/bits/std_thread.h:252 (targets_playground+0x13080)
    #9 operator() /usr/include/c++/12/bits/std_thread.h:259 (targets_playground+0x1302a)
    #10 _M_run /usr/include/c++/12/bits/std_thread.h:210 (targets_playground+0x12fe4)
    #11 <null> <null> (libstdc++.so.6+0xd44a2)

  Previous write of size 8 at 0x7fae30207788 by thread T1:
    #0 fmt::v12::detail::glibc_file<_IO_FILE>::init_buffer() ../subprojects/fmt/include/fmt/format-inl.h:1531 (targets_playground+0x25dca)
    #1 fmt::v12::detail::file_print_buffer<_IO_FILE, void>::file_print_buffer(_IO_FILE*) ../subprojects/fmt/include/fmt/format-inl.h:1681 (targets_playground+0x22798)
    #2 fmt::v12::vprint(_IO_FILE*, fmt::v12::basic_string_view<char>, fmt::v12::basic_format_args<fmt::v12::context>) ../subprojects/fmt/include/fmt/format-inl.h:1740 (targets_playground+0x15eb3)
    #3 fmt::v12::vprint(fmt::v12::basic_string_view<char>, fmt::v12::basic_format_args<fmt::v12::context>) ../subprojects/fmt/include/fmt/format-inl.h:1752 (targets_playground+0x16054)
    #4 void fmt::v12::print<>(fmt::v12::fstring<>::t) ../subprojects/fmt/include/fmt/base.h:2963 (targets_playground+0x1270f)
    #5 operator() ../source/targets/playground/main.cpp:16 (targets_playground+0x1270f)
    #6 __invoke_impl<void, main()::<lambda()> > /usr/include/c++/12/bits/invoke.h:61 (targets_playground+0x131a0)
    #7 __invoke<main()::<lambda()> > /usr/include/c++/12/bits/invoke.h:96 (targets_playground+0x1311b)
    #8 _M_invoke<0> /usr/include/c++/12/bits/std_thread.h:252 (targets_playground+0x13080)
    #9 operator() /usr/include/c++/12/bits/std_thread.h:259 (targets_playground+0x1302a)
    #10 _M_run /usr/include/c++/12/bits/std_thread.h:210 (targets_playground+0x12fe4)
    #11 <null> <null> (libstdc++.so.6+0xd44a2)

  Location is global '_IO_2_1_stdout_' of size 224 at 0x7fae30207760 (libc.so.6+0x1d4788)

  Thread T2 (tid=53703, running) created by main thread at:
    #0 pthread_create ../../../../src/libsanitizer/tsan/tsan_interceptors_posix.cpp:1001 (libtsan.so.2+0x5e686)
    #1 std::thread::_M_start_thread(std::unique_ptr<std::thread::_State, std::default_delete<std::thread::_State> >, void (*)()) <null> (libstdc++.so.6+0xd4578)
    #2 construct_at<std::thread, main()::<lambda()> > /usr/include/c++/12/bits/stl_construct.h:97 (targets_playground+0x12ce5)
    #3 construct<std::thread, main()::<lambda()> > /usr/include/c++/12/bits/alloc_traits.h:518 (targets_playground+0x129c4)
    #4 _M_realloc_insert<main()::<lambda()> > /usr/include/c++/12/bits/vector.tcc:462 (targets_playground+0x12ace)
    #5 emplace_back<main()::<lambda()> > /usr/include/c++/12/bits/vector.tcc:123 (targets_playground+0x12944)
    #6 main ../source/targets/playground/main.cpp:13 (targets_playground+0x1279e)

  Thread T1 (tid=53702, running) created by main thread at:
    #0 pthread_create ../../../../src/libsanitizer/tsan/tsan_interceptors_posix.cpp:1001 (libtsan.so.2+0x5e686)
    #1 std::thread::_M_start_thread(std::unique_ptr<std::thread::_State, std::default_delete<std::thread::_State> >, void (*)()) <null> (libstdc++.so.6+0xd4578)
    #2 construct_at<std::thread, main()::<lambda()> > /usr/include/c++/12/bits/stl_construct.h:97 (targets_playground+0x12ce5)
    #3 construct<std::thread, main()::<lambda()> > /usr/include/c++/12/bits/alloc_traits.h:518 (targets_playground+0x129c4)
    #4 _M_realloc_insert<main()::<lambda()> > /usr/include/c++/12/bits/vector.tcc:462 (targets_playground+0x12ace)
    #5 emplace_back<main()::<lambda()> > /usr/include/c++/12/bits/vector.tcc:123 (targets_playground+0x12944)
    #6 main ../source/targets/playground/main.cpp:13 (targets_playground+0x1279e)

SUMMARY: ThreadSanitizer: data race ../subprojects/fmt/include/fmt/format-inl.h:1528 in fmt::v12::detail::glibc_file<_IO_FILE>::init_buffer()

[jobpaardekooper]

There is probably some limitation with running thread sanitizer on Godbolt. So I don't think the example with it working on GCC 15.1 and not on GCC 12.2 in the link should be taken at face value. But, running that example on my machine does really trigger that full thread sanitizer log I pasted above.

In the Godbolt link, if you replace the line with fmt::print("a"); with std::cout << ("a");, you still see:

FATAL: ThreadSanitizer: unexpected memory mapping 0x7430f2c72000-0x7430f3100000

Which does not seem to be right. In my environment, running the original snippet does trigger thread sanitizer while the std::cout does not.

g++ --version
g++ (Debian 12.2.0-14+deb12u1) 12.2.0

Running on x86-64 with Debian 12

ldd --version
ldd (Debian GLIBC 2.36-9+deb12u13) 2.36

Using FMT v12.1.0

If you use the log line fmt::print(stdout, "[{}] {}\n", i, numMessages); in my example and silence the Thread Sanitizer trigger location above by using a suppression file with:

race:fmt::v12::detail::glibc_file

And you run again, you will see another trigger in fmt::v12::detail::buffer<char>::append. If you silence that also you will get a trigger in fmt::v12::detail::do_format_decimal. Could all be related but just adding for extra detail.

[soumik15630m]

Thanks @jobpaardekooper I will take a look into this and update in this thread

[vitaut]

Older gcc doesn't understand flockfile, fixed in 7f5f9c9.