[raudio] Crash encountered with mod(.xm) playback

[computermouth]

I have been testing this very very frequently, and so far have only seen this crash once, across several computers

=================================================================
==2300==ERROR: AddressSanitizer: heap-buffer-overflow on address 0x62a000011de0 at pc 0x7ff503a4814b bp 0x7ff4cef7a8a0 sp 0x7ff4cef7a050
READ of size 2352 at 0x62a000011de0 thread T9
    #0 0x7ff503a4814a in __interceptor_memcpy ../../../../src/libsanitizer/sanitizer_common/sanitizer_common_interceptors.inc:827
    #1 0x563470788b22 in OnSendAudioDataToDevice (/home/computermouth/projects/astro-aegis/src/astro-aegis+0x184b22)
    #2 0x563470755943 in ma_device__on_data_inner (/home/computermouth/projects/astro-aegis/src/astro-aegis+0x151943)
    #3 0x5634707574b7 in ma_device__on_data (/home/computermouth/projects/astro-aegis/src/astro-aegis+0x1534b7)
    #4 0x5634707576be in ma_device__handle_data_callback (/home/computermouth/projects/astro-aegis/src/astro-aegis+0x1536be)
    #5 0x56347075bdac in ma_device__read_frames_from_client (/home/computermouth/projects/astro-aegis/src/astro-aegis+0x157dac)
    #6 0x56347075c8a8 in ma_device_handle_backend_data_callback (/home/computermouth/projects/astro-aegis/src/astro-aegis+0x1588a8)
    #7 0x56347075ca7b in ma_device_write_to_stream__pulse (/home/computermouth/projects/astro-aegis/src/astro-aegis+0x158a7b)
    #8 0x56347075cbc7 in ma_device_on_write__pulse (/home/computermouth/projects/astro-aegis/src/astro-aegis+0x158bc7)
    #9 0x7ff500c4ad95  (/lib/x86_64-linux-gnu/libpulse.so+0x2dd95)
    #10 0x7ff4fe1bd392 in pa_pdispatch_run (/usr/lib/x86_64-linux-gnu/pulseaudio/libpulsecommon-16.1.so+0x43392)
    #11 0x7ff500c2dced  (/lib/x86_64-linux-gnu/libpulse.so+0x10ced)
    #12 0x7ff4fe1bfd12  (/usr/lib/x86_64-linux-gnu/pulseaudio/libpulsecommon-16.1.so+0x45d12)
    #13 0x7ff4fe1c2ab7  (/usr/lib/x86_64-linux-gnu/pulseaudio/libpulsecommon-16.1.so+0x48ab7)
    #14 0x7ff4fe1c2e75  (/usr/lib/x86_64-linux-gnu/pulseaudio/libpulsecommon-16.1.so+0x48e75)
    #15 0x7ff4fe1c36b9  (/usr/lib/x86_64-linux-gnu/pulseaudio/libpulsecommon-16.1.so+0x496b9)
    #16 0x7ff500c43307 in pa_mainloop_dispatch (/lib/x86_64-linux-gnu/libpulse.so+0x26307)
    #17 0x7ff500c43613 in pa_mainloop_iterate (/lib/x86_64-linux-gnu/libpulse.so+0x26613)
    #18 0x56347074110b in ma_device_data_loop__pulse (/home/computermouth/projects/astro-aegis/src/astro-aegis+0x13d10b)
    #19 0x56347075c392 in ma_worker_thread (/home/computermouth/projects/astro-aegis/src/astro-aegis+0x158392)
    #20 0x56347074fe48 in ma_thread_entry_proxy (/home/computermouth/projects/astro-aegis/src/astro-aegis+0x14be48)
    #21 0x7ff502ea8043 in start_thread nptl/pthread_create.c:442
    #22 0x7ff502f2861b in clone3 ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

0x62a000011de0 is located 0 bytes to the right of 23520-byte region [0x62a00000c200,0x62a000011de0)
allocated by thread T0 here:
    #0 0x7ff503ab83b7 in __interceptor_calloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:77
    #1 0x563470789161 in LoadAudioBuffer (/home/computermouth/projects/astro-aegis/src/astro-aegis+0x185161)

Thread T9 created by T0 here:
    #0 0x7ff503a49726 in __interceptor_pthread_create ../../../../src/libsanitizer/asan/asan_interceptors.cpp:207
    #1 0x56347074f9ab in ma_thread_create (/home/computermouth/projects/astro-aegis/src/astro-aegis+0x14b9ab)

SUMMARY: AddressSanitizer: heap-buffer-overflow ../../../../src/libsanitizer/sanitizer_common/sanitizer_common_interceptors.inc:827 in __interceptor_memcpy
Shadow bytes around the buggy address:
  0x0c547fffa360: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c547fffa370: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c547fffa380: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c547fffa390: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c547fffa3a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
=>0x0c547fffa3b0: 00 00 00 00 00 00 00 00 00 00 00 00[fa]fa fa fa
  0x0c547fffa3c0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c547fffa3d0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c547fffa3e0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c547fffa3f0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c547fffa400: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable:           00
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
  Left alloca redzone:     ca
  Right alloca redzone:    cb
==2300==ABORTING

Issue description

Briefly describe the issue you are experiencing (or the feature you want to see added to raylib). Tell us what you were trying to do and what happened instead. Remember, this is not the best place to ask questions. For questions, go to raylib Discord server.

My audio playback code is very simple, I play one mod, and later switch to playing another mod. This crash occurred in the middle of the playback of the second mod.

Environment

• Debian 12
• Raylib @ 5.0 (tag)

INFO: Initializing raylib 5.0
INFO: Platform backend: DESKTOP (GLFW)
INFO: Supported raylib modules:
INFO:     > rcore:..... loaded (mandatory)
INFO:     > rlgl:...... loaded (mandatory)
INFO:     > rshapes:... loaded (optional)
INFO:     > rtextures:. loaded (optional)
INFO:     > rtext:..... loaded (optional)
INFO:     > rmodels:... loaded (optional)
INFO:     > raudio:.... loaded (optional)
INFO: DISPLAY: Device initialized successfully
INFO:     > Display size: 1920 x 1080
INFO:     > Screen size:  1280 x 720
INFO:     > Render size:  1280 x 720
INFO:     > Viewport offsets: 0, 0
INFO: GLAD: OpenGL extensions loaded successfully
INFO: GL: Supported extensions count: 226
INFO: GL: OpenGL device information:
INFO:     > Vendor:   Intel
INFO:     > Renderer: Mesa Intel(R) UHD Graphics 620 (WHL GT2)
INFO:     > Version:  4.6 (Core Profile) Mesa 22.3.6
INFO:     > GLSL:     4.60
INFO: GL: VAO extension detected, VAO functions loaded successfully
INFO: GL: NPOT textures extension detected, full NPOT textures supported
INFO: GL: DXT compressed textures supported
INFO: GL: ETC2/EAC compressed textures supported
INFO: PLATFORM: DESKTOP (GLFW): Initialized successfully
INFO: TEXTURE: [ID 1] Texture loaded successfully (1x1 | R8G8B8A8 | 1 mipmaps)
INFO: TEXTURE: [ID 1] Default texture loaded successfully
INFO: SHADER: [ID 1] Vertex shader compiled successfully
INFO: SHADER: [ID 2] Fragment shader compiled successfully
INFO: SHADER: [ID 3] Program shader loaded successfully
INFO: SHADER: [ID 3] Default shader loaded successfully
INFO: RLGL: Render batch vertex buffers loaded successfully in RAM (CPU)
INFO: RLGL: Render batch vertex buffers loaded successfully in VRAM (GPU)
INFO: RLGL: Default OpenGL state initialized successfully
INFO: TEXTURE: [ID 2] Texture loaded successfully (128x128 | GRAY_ALPHA | 1 mipmaps)
INFO: FONT: Default font loaded successfully (224 glyphs)
INFO: AUDIO: Device initialized successfully
INFO:     > Backend:       miniaudio / PulseAudio
INFO:     > Format:        32-bit IEEE Floating Point -> 16-bit Signed Integer
INFO:     > Channels:      2 -> 2
INFO:     > Sample rate:   44100 -> 44100
INFO:     > Periods size:  3304
[...]
INFO: STREAM: Initialized successfully (44100 Hz, 32 bit, Stereo)
INFO: FILEIO: Music data loaded successfully
INFO:     > Sample rate:   44100 Hz
INFO:     > Sample size:   32 bits
INFO:     > Channels:      2 (Stereo)
INFO:     > Total frames:  367965
INFO: STREAM: Initialized successfully (44100 Hz, 32 bit, Stereo)
INFO: FILEIO: Music data loaded successfully
INFO:     > Sample rate:   44100 Hz
INFO:     > Sample size:   32 bits
INFO:     > Channels:      2 (Stereo)
INFO:     > Total frames:  2423520

Code Example

If I can reproduce this in a smaller code sample, I will update the issue. Just wanted to dump these logs here for now. Starting and switching between the songs is here: https://github.com/computermouth/astro-aegis/blob/master/src/game.c#L90-L103

Files loaded and playing are here: https://github.com/computermouth/astro-aegis/tree/master/src/xxd_resources/mus

[raysan5]

@computermouth It seems the issue goes down to PulseAudio backend... I'm afraid more precise information is required to properly address this issue...

[dertseha]

Hi all, I did some tinkering and could reproduce the issue (rather: force the problem to happen more often) on both MS Windows and WSL.

Short: It is a threading issue in raudio, more specifically, a data race.

The rAudioBuffer member frameCursorPos is not securely synchronized between the user thread, which calls methods like UpdateMusicStream(), and the miniaudio callback thread that calls OnSendAudioDataToDevice().

Long: OnSendAudioDataToDevice uses this member through ReadAudioBufferFramesInInternalFormat() to read from the internal buffer. The member indicates the start read position for the next memcpy. This is the instruction that ASAN trips on. (Code of v5.0 here)

UpdateMusicStream() uses this member for a hack through PlayMusicStream(), which reads the member and then writes to this member twice - without synchronization. (Code of v5.0 here)

I could force the issue to happen by adding printf debugging before the final write in PlayMusicStream() (to see what the value is that is written) and then printf debugging in ReadAudioBufferFramesInInternalFormat() right before memcpy (to see what this thread reads). And thanks to printf taking quite long before writing back in the user method so that the callback thread can update/change it on its own in parallel, the check in the callback trips within seconds of the example audio_music_stream.

If I use AUDIO.System.lock and lock/unlock it for UpdateMusicStream() like it is for the callback, the issue does not appear.

Further: I have the gut feeling that more (all?) user-side methods need a proper lock that they currently don't have, as I suspect more rAudioBuffer members being accessed without a lock. Members like isSubBufferProcessed, playing, or paused are also both read and written in the user functions without locks.

I've pushed my recreating code to this branch: https://github.com/dertseha/raylib/tree/reproduce-3664-crash-in-raudio Look for // TODO 3664 and the printf statements in raudio.c. Running example audio_music_stream reproduces the issue quite well. (Note: I may delete this branch eventually; If the reproducer code should be kept in this thread, please tell)

[raysan5]

@dertseha Excuse the late response, I completely missed your answer. Thank you very much for the further investigation and the detailed report with the findings.

If I use AUDIO.System.lock and lock/unlock it for UpdateMusicStream() like it is for the callback, the issue does not appear.

Please, could you send a PR with this fix? I imagine some other functions will require similar solutions to avoid this issue in the future...

[dertseha]

Thank you for the response. Clarifying that such locks are OK in a game engine helps me. A PR may take a while (few weeks) as my calendar is a bit full currently.

edit 2024-04-09: This week I'm on it.

[dertseha]

OK, I finally had time to work on this. As it turned out, while there was the need for mutex locks in several functions, the original issue was solved differently. Pull request inbound.

While adding mutex locks, I also had to make sure that there is no re-entrant case, as the mutex is not set up that way. For this I needed to split some functions (see pull request). For the UpdateMusicStream() I would have had to do quite a lot, so I looked into inlining the statement of if (IsMusicStreamPlaying(music)) PlayMusicStream(music); - however, I realized that this is essentially a no-op:

Inlining of the above statement:

if (music.stream.buffer->playing && !music.stream.buffer->paused)  // inlining of IsMusicStreamPlaying()
{
  frameCursorPos = music.stream.buffer->frameCursorPos;  // storing of current position as per old PlayMusicStream()
  {  // inline of block for PlayAudioStream()
     music.stream.buffer->playing = true;
     music.stream.buffer->paused = false;
     music.stream.buffer->frameCursorPos = 0;
  }
  music.stream.buffer->frameCursorPos = frameCursorPos; // restoring of current position as per old PlayMusicStream()
}

The goal was to keep the current frame cursor position, so assuming a function that doesn't touch it, we're left with

if (music.stream.buffer->playing && !music.stream.buffer->paused)
{
   music.stream.buffer->playing = true;
   music.stream.buffer->paused = false;
}

Which reads as: "Only if playing=true and paused=false, set playing to true and paused to false." o.O

To me this hack seems like a leftover from other code/behaviour that no longer exists. Even the comment that this is for resuming playback after restoring a minimized window doesn't fit. Even with the removed hack, music stops when minimized, and still continues when the window gets restored.