TOUCHE: Audio mixer crash when quitting the demo in mid-sentence

[dwatteau]

Current Git HEAD (or current branch-2-9).

I'm observing a crash with the Touché demo (<​https://downloads.scummvm.org/frs/demos/touche/touche-dos-demo-en.zip>).

Steps to reproduce:

1. Have a debug build (with assert() turned on)
2. Start the Touché demo, in windowed mode
3. Press ESC when the "US Gold" screen appears
4. When the main character appears and says "This is Rouen", click on the quit button of your window manager, to exit the ScummVM app
5. The game sometimes crash (around 1 time out of 4 here, it seems that the "sweet spot" is when you can hear the character pronounce the "is" word, roughly)

(FWIW, I use gui_return_to_launcher_at_exit=true, but it shouldn't matter.)

Then, I observe the following in GDB:

scummvm: common/file.cpp:141: virtual uint32 Common::File::read(void*, uint32): Assertion `_handle' failed.

Program received signal SIGABRT, Aborted.
[Switching to Thread 0xb22603d0 (LWP 1190)]
0x0f36bbe8 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
56      ../nptl/sysdeps/unix/sysv/linux/raise.c: No such file or directory.

(gdb) bt
#0  0x0f36bbe8 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#1  0x0f36d7d0 in __GI_abort () at abort.c:89
#2  0x0f363108 in __assert_fail_base (fmt=0xf491738 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n",
    assertion=assertion@entry=0x15cf5df0 "_handle", file=file@entry=0x15cf5d34 "common/file.cpp",
    line=line@entry=141,
    function=function@entry=0x15cf6044 <Common::File::read(void*, unsigned int)::__PRETTY_FUNCTION__> "virtual uint32 Common::File::read(void*, uint32)") at assert.c:92
#3  0x0f3631d4 in __GI___assert_fail (assertion=0x15cf5df0 "_handle",
    file=0x15cf5d34 "common/file.cpp", line=141,
    function=0x15cf6044 <Common::File::read(void*, unsigned int)::__PRETTY_FUNCTION__> "virtual uint32 Common::File::read(void*, uint32)") at assert.c:101
#4  0x14a67b3c in Common::File::read (this=0x16b087e0, ptr=0x16f9d42c, len=512)
    at common/file.cpp:141
#5  0x149e67dc in Audio::VocStream::fillBuffer (this=0x16f9d3f8, maxSamples=512)
    at audio/decoders/voc.cpp:160
#6  0x149e6348 in Audio::VocStream::readBuffer (this=0x16f9d3f8, buffer=0x16fa719c, numSamples=512)
    at audio/decoders/voc.cpp:91
#7  0x149cf358 in Audio::RateConverter_Impl<false, true, false>::interpolateConvert (
    this=0x16fa7190, input=..., outBuffer=0x16c57ed0, numSamples=512, volL=192, volR=192)
    at audio/rate.cpp:218
#8  0x149cdd90 in Audio::RateConverter_Impl<false, true, false>::convert (this=0x16fa7190,
    input=..., outBuffer=0x16c57ed0, numSamples=512, volL=192, volR=192) at audio/rate.cpp:295
#9  0x149c841c in Audio::Channel::mix (this=0x16c670c0, data=0x16c57ed0, len=512)
    at audio/mixer.cpp:719
#10 0x149c5c28 in Audio::MixerImpl::mixCallback (this=0x16c5a480, samples=0x16c57ed0 "", len=512)
    at audio/mixer.cpp:331
#11 0x141534a4 in SdlMixerManager::callbackHandler (this=0x16c56120, samples=0x16c57ed0 "",
    len=2048) at backends/mixer/sdl/sdl-mixer.cpp:203
#12 0x14153538 in SdlMixerManager::sdlCallback (this_=0x16c56120, samples=0x16c57ed0 "", len=2048)
    at backends/mixer/sdl/sdl-mixer.cpp:210

[...]

Thread 1 (Thread 0xb7fb1230 (LWP 1164)):
#0  0x0f74ebb8 in __lll_lock_wait (futex=futex@entry=0x16c5a540, private=0)
    at ../nptl/sysdeps/unix/sysv/linux/lowlevellock.c:46
#1  0x0f74863c in __GI___pthread_mutex_lock (mutex=0x16c5a540) at pthread_mutex_lock.c:114
#2  0x0ff7e9cc in SDL_mutexP () from /usr/lib/powerpc-linux-gnu/libSDL-1.2.so.0
#3  0x14153c7c in SdlMutexInternal::lock (this=0x16a68958) at backends/mutex/sdl/sdl-mutex.cpp:37
#4  0x14a763c0 in Common::StackLock::lock (this=0xbfffd3fc) at common/mutex.cpp:67
#5  0x14a762f8 in Common::StackLock::StackLock (this=0xbfffd3fc, mutex=..., mutexName=0x0)
    at common/mutex.cpp:56
#6  0x149c5cc0 in Audio::MixerImpl::stopAll (this=0x16c5a480) at audio/mixer.cpp:342
#7  0x1401e218 in Engine::~Engine (this=0x16b03780, __in_chrg=<optimized out>)
    at engines/engine.cpp:211
#8  0x136caa44 in Touche::ToucheEngine::~ToucheEngine (this=0x16b03780, __in_chrg=<optimized out>)
    at engines/touche/touche.cpp:185
#9  0x136caa94 in Touche::ToucheEngine::~ToucheEngine (this=0x16b03780, __in_chrg=<optimized out>)
    at engines/touche/touche.cpp:188
#10 0x106b95e0 in AdvancedMetaEngine<ADGameDescription>::deleteInstance (this=<optimized out>,
    engine=<optimized out>, gameDescriptor=..., meDescriptor=0x16c01998)
    at ./engines/advancedDetector.h:722
#11 0x10040478 in runGame (enginePlugin=0x16994058, system=..., game=..., meDescriptor=0x16c01998)
    at base/main.cpp:324
#12 0x10042604 in scummvm_main (argc=1, argv=0xbffff444) at base/main.cpp:796
#13 0x1003d37c in main (argc=1, argv=0xbffff444) at backends/platform/sdl/posix/posix-main.cpp:44

Full GDB log with info for all threads attached below.

It looks like I also got a similar crash to happen on iOS, but only once, last August. lman saw it in the TestFlight dumps, but there wasn't enough debug information, as I recall (screenshot attached below, though).

It may look a bit like a mutex issue regarding audio in this engine?

[dwatteau]

Full GDB log when the crash happens

[dwatteau]

iOS TestFlight screenshot when I reproduced a similar (?) issue on iOS back in August

[dwatteau]

Also, maybe ASAN/TSAN/Valgrind would catch something there, but I haven't had the time to look into that yet.

[dwatteau]

ThreadSanitizer (--enable-tsan) output when just starting the demo on macOS/aarch64

[dwatteau]

LLDB output when the ThreadSanitizer crash happens

[dwatteau]

Raising the priority to High, since the engine crash happens in the demo and the full game.

Still happening in ScummVM 3.0.0git; attaching an LLDB backtrace when the crash happens in the full game. I'm pressing 'Esc' when the other person (off-screen, green text) is replying to the main character noise in the first scene.

[dwatteau]

LLDB backtrace when the engine crashes (full French game, 3.0.0git)

[Filippos Karapetis <bluegr@…>]

In 0a4b2f9a:

TOUCHE: stop any pending speech before closing the underlying streams

Fixes bug #15515

[Filippos Karapetis <bluegr@…>]

In c192f74e:

TOUCHE: stop any pending speech before closing the underlying streams

Fixes bug #15515