search

dhewm / dhewm3

dhewm 3 main repository
https://dhewm3.org/
GNU General Public License v3.0
1.78k stars 346 forks source link

Race conditions between main thread and SDL async timer thread #169

Open turol opened 7 years ago

turol commented 7 years ago

ThreadSanitizer report:

WARNING: ThreadSanitizer: data race (pid=25333)
  Read of size 4 at 0x000001ddbdf0 by main thread:
    #0 idSessionLocal::DrawWipeModel()                            neo/framework/Session.cpp:2220   (dhewm3+0x00000066b8e9)
    #1 idSessionLocal::Draw()                                     neo/framework/Session.cpp:2454   (dhewm3+0x00000066b8e9)
    #2 idSessionLocal::UpdateScreen(bool)                         neo/framework/Session.cpp:2497   (dhewm3+0x0000006742e9)
    #3 idSessionLocal::StartPlayingRenderDemo(idStr)              neo/framework/Session.cpp:937    (dhewm3+0x00000066ca4a)
    #4 idSessionLocal::TimeRenderDemo(char const*, bool)          neo/framework/Session.cpp:965    (dhewm3+0x00000066d178)
    #5 Session_TimeDemoQuit_f(idCmdArgs const&)                   neo/framework/Session.cpp:681    (dhewm3+0x000000676907)
    #6 idCmdSystemLocal::ExecuteTokenizedString(idCmdArgs const&) neo/framework/CmdSystem.cpp:498  (dhewm3+0x0000005f23d5)
    #7 idCmdSystemLocal::ExecuteCommandBuffer()                   neo/framework/CmdSystem.cpp:679  (dhewm3+0x0000005f2b0b)
    #8 idEventLoop::RunEventLoop(bool)                            neo/framework/EventLoop.cpp:184  (dhewm3+0x0000006442b7)
    #9 idCommonLocal::Frame()                                     neo/framework/Common.cpp:2384    (dhewm3+0x0000006004f0)
    #10 main                                                      neo/sys/linux/main.cpp:305       (dhewm3+0x0000007fdff1)

  Previous write of size 4 at 0x000001ddbdf0 by thread T1 (mutexes: write M104):
    #0 idCommonLocal::SingleAsyncTic()  neo/framework/Common.cpp:2497  (dhewm3+0x00000060096f)
    #1 idCommonLocal::Async()           neo/framework/Common.cpp:2540  (dhewm3+0x000000600ab4)
    #2 AsyncTimer(unsigned int, void*)  neo/framework/Common.cpp:2728  (dhewm3+0x00000060181f)
    #3 SDL_LogCritical                  <null>                         (libSDL2-2.0.so.0+0x0000000802bb)

  Location is global '<null>' at 0x000000000000 (dhewm3+0x000001ddbdf0)

  Mutex M104 (0x7d0c0000c180) created at:
    #0 pthread_mutex_init                <null>                         (dhewm3+0x00000044d58a)
    #1 SDL_LogCritical                   <null>                         (libSDL2-2.0.so.0+0x0000000cf9ac)
    #2 idCommonLocal::Init(int, char**)  neo/framework/Common.cpp:2762  (dhewm3+0x00000060127a)
    #3 main                              neo/sys/linux/main.cpp:301     (dhewm3+0x0000007fdfc3)

  Thread T1 'SDLTimer' (tid=25336, running) created by main thread at:
    #0 pthread_create   <null>                      (dhewm3+0x00000044d0c6)
    #1 SDL_LogCritical  <null>                      (libSDL2-2.0.so.0+0x0000000cf4a2)
    #2 main             neo/sys/linux/main.cpp:301  (dhewm3+0x0000007fdfc3)

SUMMARY: ThreadSanitizer: data race neo/framework/Session.cpp:2220 in idSessionLocal::DrawWipeModel()
==================
==================
WARNING: ThreadSanitizer: data race (pid=25333)
  Write of size 4 at 0x0000045a8628 by thread T1 (mutexes: write M104):
    #0 idSoundSystemLocal::AsyncUpdateWrite(int)  neo/sound/snd_system.cpp:710   (dhewm3+0x000000775e5d)
    #1 idCommonLocal::SingleAsyncTic()            neo/framework/Common.cpp:2491  (dhewm3+0x00000060095d)
    #2 idCommonLocal::Async()                     neo/framework/Common.cpp:2540  (dhewm3+0x000000600ab4)
    #3 AsyncTimer(unsigned int, void*)            neo/framework/Common.cpp:2728  (dhewm3+0x00000060181f)
    #4 SDL_LogCritical                            <null>                         (libSDL2-2.0.so.0+0x0000000802bb)

  Previous read of size 4 at 0x0000045a8628 by main thread:
    #0 idSoundSystemLocal::GetCurrent44kHzTime() const             neo/sound/snd_system.cpp:555     (dhewm3+0x00000077467b)
    #1 idSoundWorldLocal::UnPause()                                neo/sound/snd_world.cpp:1475     (dhewm3+0x000000781be2)
    #2 idSoundWorldLocal::ProcessDemoCommand(idDemoFile*)          neo/sound/snd_world.cpp:313      (dhewm3+0x00000077a4f2)
    #3 idSessionLocal::AdvanceRenderDemo(bool)                     neo/framework/Session.cpp:2281   (dhewm3+0x00000066cf71)
    #4 idSessionLocal::StartPlayingRenderDemo(idStr)               neo/framework/Session.cpp:946    (dhewm3+0x00000066cabd)
    #5 idSessionLocal::TimeRenderDemo(char const*, bool)           neo/framework/Session.cpp:965    (dhewm3+0x00000066d178)
    #6 Session_TimeDemoQuit_f(idCmdArgs const&)                    neo/framework/Session.cpp:681    (dhewm3+0x000000676907)
    #7 idCmdSystemLocal::ExecuteTokenizedString(idCmdArgs const&)  neo/framework/CmdSystem.cpp:498  (dhewm3+0x0000005f23d5)
    #8 idCmdSystemLocal::ExecuteCommandBuffer()                    neo/framework/CmdSystem.cpp:679  (dhewm3+0x0000005f2b0b)
    #9 idEventLoop::RunEventLoop(bool)                             neo/framework/EventLoop.cpp:184  (dhewm3+0x0000006442b7)
    #10 idCommonLocal::Frame()                                     neo/framework/Common.cpp:2384    (dhewm3+0x0000006004f0)
    #11 main                                                       neo/sys/linux/main.cpp:305       (dhewm3+0x0000007fdff1)

  Location is global '<null>' at 0x000000000000 (dhewm3+0x0000045a8628)

SUMMARY: ThreadSanitizer: data race neo/sound/snd_system.cpp:710 in idSoundSystemLocal::AsyncUpdateWrite(int)
==================
==================
WARNING: ThreadSanitizer: data race (pid=25333)
  Read of size 4 at 0x0000045e13b0 by main thread:
    #0 tty_Hide()                                                                 neo/sys/posix/posix_main.cpp:455       (dhewm3+0x0000007fc3cb)
    #1 Sys_Printf(char const*, ...)                                               neo/sys/posix/posix_main.cpp:789       (dhewm3+0x0000007fb560)
    #2 idCommonLocal::VPrintf(char const*, __va_list_tag*)                        neo/framework/Common.cpp:369           (dhewm3+0x0000005f4eb2)
    #3 idCommonLocal::Printf(char const*, ...)                                    neo/framework/Common.cpp:425           (dhewm3+0x0000005f4fec)
    #4 R_LoadARBProgram(int)                                                      neo/renderer/draw_arb2.cpp:356         (dhewm3+0x000000592baf)
    #5 R_FindARBProgram(unsigned int, char const*)                                neo/renderer/draw_arb2.cpp:477         (dhewm3+0x0000005932ad)
    #6 idMaterial::ParseStage(idLexer&, textureRepeat_t)                          neo/renderer/Material.cpp:1497         (dhewm3+0x0000005105bb)
    #7 idMaterial::ParseMaterial(idLexer&)                                        neo/renderer/Material.cpp:2059         (dhewm3+0x000000511c33)
    #8 idMaterial::Parse(char const*, int)                                        neo/renderer/Material.cpp:2141         (dhewm3+0x000000512d7d)
    #9 idDeclLocal::ParseLocal()                                                  neo/framework/DeclManager.cpp:2206     (dhewm3+0x00000062a839)
    #10 idDeclManagerLocal::FindType(declType_t, char const*, bool)               neo/framework/DeclManager.cpp:1145     (dhewm3+0x00000062d691)
    #11 idDeclManagerLocal::FindMaterial(char const*, bool)                       neo/framework/DeclManager.cpp:1539     (dhewm3+0x0000006301f2)
    #12 idRenderWorldLocal::ParseModel(idLexer*)                                  neo/renderer/RenderWorld_load.cpp:144  (dhewm3+0x0000005899b6)
    #13 idRenderWorldLocal::InitFromMap(char const*)                              neo/renderer/RenderWorld_load.cpp:547  (dhewm3+0x00000058b207)
    #14 idRenderWorldLocal::ProcessDemoCommand(idDemoFile*, renderView_s*, int*)  neo/renderer/RenderWorld_demo.cpp:127  (dhewm3+0x0000005846a3)
    #15 idSessionLocal::AdvanceRenderDemo(bool)                                   neo/framework/Session.cpp:2273         (dhewm3+0x00000066ceac)
    #16 idSessionLocal::StartPlayingRenderDemo(idStr)                             neo/framework/Session.cpp:946          (dhewm3+0x00000066cabd)
    #17 idSessionLocal::TimeRenderDemo(char const*, bool)                         neo/framework/Session.cpp:965          (dhewm3+0x00000066d178)
    #18 Session_TimeDemoQuit_f(idCmdArgs const&)                                  neo/framework/Session.cpp:681          (dhewm3+0x000000676907)
    #19 idCmdSystemLocal::ExecuteTokenizedString(idCmdArgs const&)                neo/framework/CmdSystem.cpp:498        (dhewm3+0x0000005f23d5)
    #20 idCmdSystemLocal::ExecuteCommandBuffer()                                  neo/framework/CmdSystem.cpp:679        (dhewm3+0x0000005f2b0b)
    #21 idEventLoop::RunEventLoop(bool)                                           neo/framework/EventLoop.cpp:184        (dhewm3+0x0000006442b7)
    #22 idCommonLocal::Frame()                                                    neo/framework/Common.cpp:2384          (dhewm3+0x0000006004f0)
    #23 main                                                                      neo/sys/linux/main.cpp:305             (dhewm3+0x0000007fdff1)

  Previous write of size 4 at 0x0000045e13b0 by thread T1 (mutexes: write M104):
    #0 tty_Hide()                                 neo/sys/posix/posix_main.cpp:470  (dhewm3+0x0000007fc4f9)
    #1 Sys_Printf(char const*, ...)               neo/sys/posix/posix_main.cpp:789  (dhewm3+0x0000007fb560)
    #2 idSoundSystemLocal::AsyncUpdateWrite(int)  neo/sound/snd_system.cpp:691      (dhewm3+0x000000775d7e)
    #3 idCommonLocal::SingleAsyncTic()            neo/framework/Common.cpp:2491     (dhewm3+0x00000060095d)
    #4 idCommonLocal::Async()                     neo/framework/Common.cpp:2540     (dhewm3+0x000000600ab4)
    #5 AsyncTimer(unsigned int, void*)            neo/framework/Common.cpp:2728     (dhewm3+0x00000060181f)
    #6 SDL_LogCritical                            <null>                            (libSDL2-2.0.so.0+0x0000000802bb)

  Location is global '<null>' at 0x000000000000 (dhewm3+0x0000045e13b0)

SUMMARY: ThreadSanitizer: data race neo/sys/posix/posix_main.cpp:455 in tty_Hide()
coreyoconnor commented 5 years ago

Looked at this for fun.

Started with tty_Hide. Easy enough. Clearly a race. Tho looks like it would only result in incorrect tty output. Still, how to solve?

I looked through the code for a mutex primitive. Only found Sys_EnterCriticalSection and Sys_LeaveCriticalSection. No idea what to provide for the critical section index. add a new one?

Attempt using CRITICAL_SECTION_TWO as it looked unused:

diff --git a/neo/sys/posix/posix_main.cpp b/neo/sys/posix/posix_main.cpp
index 80b7745..0e239df 100644
--- a/neo/sys/posix/posix_main.cpp
+++ b/neo/sys/posix/posix_main.cpp
@@ -560,8 +560,10 @@ void tty_Hide() {
        if ( !tty_enabled ) {
                return;
        }
+    Sys_EnterCriticalSection(CRITICAL_SECTION_TWO);
        if ( input_hide ) {
                input_hide++;
+        Sys_LeaveCriticalSection(CRITICAL_SECTION_TWO);
                return;
        }
        // clear after cursor
@@ -576,6 +578,7 @@ void tty_Hide() {
                buf_len--;
        }
        input_hide++;
+    Sys_LeaveCriticalSection(CRITICAL_SECTION_TWO);
 }

 // show the current line