sf::err() is not thread-safe

[eXpl0it3r]

Description

So basically, sf::Err is not thread-safe. thread_local (or SFML's C++98 sf::ThreadLocalPtr equivalent) will make sure there's no race on the DefaultErrStreamBuf itself, but not on the underlying stderr object.

If I'm not mistaken, C++11 guarantees thread safety for stdout, stderr, etc. in the sense that no corruption will occur due to multi-threaded access. However, it's still possible that unbuffered characters are interleaved from two places. In C++98, there was no threading model, so I guess no guarantees (might still work in practice).

I referenced a PR which is still incomplete, let's continue the discussion there. Unfortunately, pre-C++11 we cannot use thread_local.

This was original discussed and reported in #1711
Draft PR: #1724

Steps to reproduce

#include <SFML/Graphics/Image.hpp>
#include <thread>

const int num_images = 3;
static std::string image_paths[3] = { "working-image.png", "non-existing-image.png", "main.cpp" };

int main()
{
    const int num_threads = 4;
    std::thread threads[num_threads];

    for(int i = 0; i < num_threads; ++i) {
        threads[i] = std::thread([]() {
            while(true) {
                for(int i = 0; i < num_images; ++i) {
                    sf::Image image;
                    image.loadFromFile(image_paths[i]);
                }
            }
        });
    }

    std::this_thread::sleep_for(std::chrono::seconds(10000000));
}

Expected behavior

Application runs through without issues

Actual behavior

You can run into crashes:

[1] from 0x00007ffff7e629a1 in std::char_traits<char>::copy(char*, char const*, unsigned long)+25 at /build/gcc/src/gcc-build/x86_64-pc-linux-gnu/libstdc++-v3/include/bits/char_traits.h:395
[2] from 0x00007ffff7e629a1 in std::basic_streambuf<char, std::char_traits<char> >::xsputn(char const*, long)+81 at /build/gcc/src/gcc-build/x86_64-pc-linux-gnu/libstdc++-v3/include/bits/streambuf.tcc:90
[3] from 0x00007ffff7e53da4 in std::basic_streambuf<char, std::char_traits<char> >::sputn(char const*, long)+13 at /build/gcc/src/gcc-build/x86_64-pc-linux-gnu/libstdc++-v3/include/streambuf:457
[4] from 0x00007ffff7e53da4 in std::__ostream_write<char, std::char_traits<char> >(std::basic_ostream<char, std::char_traits<char> >&, char const*, long)+20 at /build/gcc/src/gcc-build/x86_64-pc-linux-gnu/libstdc++-v3/include/bits/ostream_insert.h:50
[5] from 0x00007ffff7e53da4 in std::__ostream_insert<char, std::char_traits<char> >(std::basic_ostream<char, std::char_traits<char> >&, char const*, long)+340 at /build/gcc/src/gcc-build/x86_64-pc-linux-gnu/libstdc++-v3/include/bits/ostream_insert.h:101
[6] from 0x00007ffff7e5415e in std::operator<< <std::char_traits<char> >(std::basic_ostream<char, std::char_traits<char> >&, char const*)+46 at /build/gcc/src/gcc-build/x86_64-pc-linux-gnu/libstdc++-v3/include/bits/char_traits.h:357
[7] from 0x00007ffff7f7c470 in sf::priv::ImageLoader::loadImageFromFile(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::vector<unsigned char, std::allocator<unsigned char> >&, sf::Vector2<unsigned int>&)+288 at /home/dec05eba/git/SFML/src/SFML/Graphics/ImageLoader.cpp:127
[8] from 0x00007ffff7f5ab4a in sf::Image::loadFromFile(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)+54 at /home/dec05eba/git/SFML/src/SFML/Graphics/Image.cpp:125

Valgrid report:

 189 ==923743== Possible data race during read of size 8 at 0x4ED5D40 by thread #3
 190 ==923743== Locks held: none
 191 ==923743==    at 0x4A40D9E: sputn (streambuf:458)
 192 ==923743==    by 0x4A40D9E: __ostream_write<char, std::char_traits<char> > (ostream_insert.h:50)
 193 ==923743==    by 0x4A40D9E: std::basic_ostream<char, std::char_traits<char> >& std::__ostream_insert<char, std::char_traits<char> >(std::basic_ostream<char, std::char_traits<char> >&, char const*, long) (ostream_insert.h:101)
 194 ==923743==    by 0x4A4115D: std::basic_ostream<char, std::char_traits<char> >& std::operator<< <std::char_traits<char> >(std::basic_ostream<char, std::char_traits<char> >&, char const*) (ostream:611)
 195 ==923743==    by 0x48C746F: sf::priv::ImageLoader::loadImageFromFile(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::vector<unsigned char, std::allocator<unsigned char> >&, sf::Vector2<unsigned int>&) (ImageLoader.cpp:127)
 196 ==923743==    by 0x48A5B49: sf::Image::loadFromFile(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) (Image.cpp:125)
 197 ==923743==    by 0x109293: main::{lambda()#1}::operator()() const (in /home/dec05eba/sfml-crash/test-sfml-crash)
 198 ==923743==    by 0x1098FB: void std::__invoke_impl<void, main::{lambda()#1}>(std::__invoke_other, main::{lambda()#1}&&) (in /home/dec05eba/sfml-crash/test-sfml-crash)
 199 ==923743==    by 0x1098B0: std::__invoke_result<main::{lambda()#1}>::type std::__invoke<main::{lambda()#1}>(std::__invoke_result&&, (main::{lambda()#1}&&)...) (in /home/dec05eba/sfml-crash/test-sfml-crash)
 200 ==923743==    by 0x10985D: void std::thread::_Invoker<std::tuple<main::{lambda()#1}> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) (in /home/dec05eba/sfml-crash/test-sfml-crash)
 201 ==923743==    by 0x109831: std::thread::_Invoker<std::tuple<main::{lambda()#1}> >::operator()() (in /home/dec05eba/sfml-crash/test-sfml-crash)
 202 ==923743==    by 0x109815: std::thread::_State_impl<std::thread::_Invoker<std::tuple<main::{lambda()#1}> > >::_M_run() (in /home/dec05eba/sfml-crash/test-sfml-crash)
 203 ==923743==    by 0x49E2C23: execute_native_thread_routine (thread.cc:80)
 204 ==923743==    by 0x4841886: mythread_wrapper (hg_intercepts.c:387)
 205 ==923743==
 206 ==923743== This conflicts with a previous write of size 8 by thread #2
 207 ==923743== Locks held: none
 208 ==923743==    at 0x4A500FB: std::basic_streambuf<char, std::char_traits<char> >::basic_streambuf() (streambuf:473)
 209 ==923743==    by 0x4EC5BA8: (anonymous namespace)::DefaultErrStreamBuf::DefaultErrStreamBuf() (Err.cpp:42)
 210 ==923743==    by 0x4EC5E39: sf::err() (Err.cpp:103)
 211 ==923743==    by 0x48C7460: sf::priv::ImageLoader::loadImageFromFile(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::vector<unsigned char, std::allocator<unsigned char> >&, sf::Vector2<unsigned int>&) (ImageLoader.cpp:127)
 212 ==923743==    by 0x48A5B49: sf::Image::loadFromFile(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) (Image.cpp:125)
 213 ==923743==    by 0x109293: main::{lambda()#1}::operator()() const (in /home/dec05eba/sfml-crash/test-sfml-crash)
 214 ==923743==    by 0x1098FB: void std::__invoke_impl<void, main::{lambda()#1}>(std::__invoke_other, main::{lambda()#1}&&) (in /home/dec05eba/sfml-crash/test-sfml-crash)
 215 ==923743==    by 0x1098B0: std::__invoke_result<main::{lambda()#1}>::type std::__invoke<main::{lambda()#1}>(std::__invoke_result&&, (main::{lambda()#1}&&)...) (in /home/dec05eba/sfml-crash/test-sfml-crash)
 216 ==923743==  Address 0x4ed5d40 is 0 bytes inside data symbol "_ZZN2sf3errEvE6buffer"

[vittorioromeo]

sf::err() and streams in general suck, to be honest. This could be a good opportunity to replace the err API with a format-like one:

sf::priv::printErrLn("Something bad happened at {} because of {}", a, b);

It would also be trivial to stick a mutex inside printErrLn to avoid data races.

[vittorioromeo]

So basically, sf::Err is not thread-safe. thread_local (or SFML's C++98 sf::ThreadLocalPtr equivalent) will make sure there's no race on the DefaultErrStreamBuf itself, but not on the underlying stderr object.

If I'm not mistaken, C++11 guarantees thread safety for stdout, stderr, etc. in the sense that no corruption will occur due to multi-threaded access. However, it's still possible that unbuffered characters are interleaved from two places.

BTW, I think it's an acceptable fix to have interleaving error streams without any data race.