Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

SDL_CloseAudioDevice hangs when closing a stream initialized with a very low audio rate. (SDL2, PulseAudio) #9829

Open
AliceLR opened this issue May 18, 2024 · 9 comments
Assignees
Milestone

Comments

@AliceLR
Copy link
Contributor

AliceLR commented May 18, 2024

Operating system: Fedora KDE Plasma Desktop 40
Device: ASUS X555LA
Branch: SDL2
Release: 2.30.3
Release: 2.30.2
Release: 2.30.1 (repository)

Operating system: Fedora KDE Plasma Desktop 39
Device: Acer Aspire E 15 E5-575G-53VG
Release: 2.28.5 (repository)

After initializing an audio device with a very low audio rate (10Hz used in the example), SDL_CloseAudioDevice temporarily hangs when attempting to close it. The amount of time it hangs seems inversely proportional to the audio rate requested; it takes a couple of seconds to close a device with 1024Hz, several minutes for 10Hz, and up to an hour for 1Hz. This only happens with the PulseAudio driver.

Expected behavior: SDL_CloseAudioDevice should not take this long to close an opened device and/or SDL_OpenAudioDevice should fail for rates where this bug is noticeable.

Example: compile with gcc -g $(sdl2-config --cflags --libs) and run with gdb. SDL_OpenAudioDevice will succeed, and then SDL_CloseAudioDevice will wait on its mutex for a very long time:

#include <SDL.h>
#include <stdio.h>
#include <string.h>

static void sdl_audio_callback(void *userdata, Uint8 *stream, int len)
{
  memset(stream, 0, len);
}

int main(int argc, char *argv[])
{
  SDL_AudioDeviceID audio_device;
  SDL_AudioSpec audio_settings;
  SDL_AudioSpec desired_spec =
  {
    /* rate     */ 10,
    /* format   */ AUDIO_S16SYS,
    /* channels */ 2,
    /* silence  */ 0,
    /* frames   */ 1024,
    /* padding  */ 0,
    /* size     */ 0,
    /* callback */ sdl_audio_callback,
    /* userdata */ NULL
  };

  if(SDL_Init(SDL_INIT_AUDIO) < 0)
  {
    fprintf(stderr, "failed to init SDL: %s\n", SDL_GetError());
    return 1;
  }

  audio_device = SDL_OpenAudioDevice(NULL, 0, &desired_spec, &audio_settings, 0);
  if(!audio_device)
  {
    fprintf(stderr, "failed to init SDL audio device: %s\n", SDL_GetError());
    return 1;
  }

  // hang SDL
  SDL_CloseAudioDevice(audio_device);
  SDL_Quit();
  return 0;
}

(Sorry if this is a duplicate report; I saw similar closed reports for past releases and for SDL3 but none specifically associated with PulseAudio and the requested audio rate.)

@sezero
Copy link
Contributor

sezero commented May 18, 2024

Reproduces on centos 6.10 i686 too. And happens with SDL_AUDIODRIVER even set to disk, so pulseaudio or alsa, etc are irrelevant. Gets stuck in SDL_WaitThread() waiting on pthread_join(). The lower the sample rate, longer the wait. With 256Hz it takes about 10s to exit, for e.g.

10 Hz, really?

$ SDL_AUDIODRIVER=disk gdb --args ./a.out
[ ... ]
(gdb) r
Starting program: /tmp/a.out 
[Thread debugging using libthread_db enabled]
CRITICAL: You are using the SDL disk i/o audio driver!
CRITICAL:  Writing to file [sdlaudio.raw].
[New Thread 0xb7fe2b70 (LWP 12288)]
^C
Program received signal SIGINT, Interrupt.
0x001fd424 in __kernel_vsyscall ()
Missing separate debuginfos, use: debuginfo-install dbus-libs-1.2.24-11.el6_10.i686
(gdb) bt
#0  0x001fd424 in __kernel_vsyscall ()
#1  0x00a9a28d in pthread_join (threadid=3086887792, thread_return=0x0) at pthread_join.c:89
#2  0x0038c461 in SDL_SYS_WaitThread (thread=0x80509c8) at /tmp/SDL2/src/thread/pthread/SDL_systhread.c:290
#3  0x002b727c in SDL_WaitThread_REAL (thread=0x80509c8, status=0x0) at /tmp/SDL2/src/thread/SDL_thread.c:442
#4  0x002172f8 in close_audio_device (device=0x804e788) at /tmp/SDL2/src/audio/SDL_audio.c:1206
#5  0x002182d8 in SDL_CloseAudioDevice_REAL (devid=2) at /tmp/SDL2/src/audio/SDL_audio.c:1677
#6  0x002317d0 in SDL_CloseAudioDevice (a=2) at /tmp/SDL2/src/dynapi/SDL_dynapi_procs.h:131
#7  0x0804871f in main (argc=1, argv=0xbffff3e4) at 1.c:41

@sezero
Copy link
Contributor

sezero commented May 18, 2024

Forgot to add that it does complete and exit, just expects a wee bit of patience:

$ time ./a.out

real	3m24.920s
user	0m0.051s
sys	0m0.080s

$ SDL_AUDIODRIVER=disk time ./a.out
CRITICAL: You are using the SDL disk i/o audio driver!
CRITICAL:  Writing to file [sdlaudio.raw].
0.00user 0.00system 5:07.21elapsed 0%CPU (0avgtext+0avgdata 1328maxresident)k
0inputs+8outputs (0major+386minor)pagefaults 0swaps

@AliceLR
Copy link
Contributor Author

AliceLR commented May 18, 2024

And happens with SDL_AUDIODRIVER even set to disk, so pulseaudio or alsa, etc are irrelevant.

I was not able to reproduce it with PipeWire as the selected driver, FWIW.

10 Hz, really?

It is a user-configurable setting and I was trying junk values during testing... 😅

@sezero
Copy link
Contributor

sezero commented May 18, 2024

I was not able to reproduce it with PipeWire as the selected driver, FWIW.

Huh

@sezero
Copy link
Contributor

sezero commented May 18, 2024

@icculus: What do you make of this?

@sezero
Copy link
Contributor

sezero commented May 18, 2024

Well, for what it's worth, those drain-waits-upon-close are the problem:
If I do the below change, it just exits instantly for me:

diff --git a/src/audio/SDL_audio.c b/src/audio/SDL_audio.c
index 96586fe..2996b37 100644
--- a/src/audio/SDL_audio.c
+++ b/src/audio/SDL_audio.c
@@ -791,7 +791,7 @@ static int SDLCALL SDL_RunAudio(void *userdata)
     }
 
     /* Wait for the audio to drain. */
-    SDL_Delay(((device->spec.samples * 1000) / device->spec.freq) * 2);
+//    SDL_Delay(((device->spec.samples * 1000) / device->spec.freq) * 2);
 
     current_audio.impl.ThreadDeinit(device);
 
diff --git a/src/audio/alsa/SDL_alsa_audio.c b/src/audio/alsa/SDL_alsa_audio.c
index 3ed66f2..b57fe66 100644
--- a/src/audio/alsa/SDL_alsa_audio.c
+++ b/src/audio/alsa/SDL_alsa_audio.c
@@ -454,12 +454,12 @@ static void ALSA_FlushCapture(_THIS)
 static void ALSA_CloseDevice(_THIS)
 {
     if (this->hidden->pcm_handle) {
-        /* Wait for the submitted audio to drain
-           ALSA_snd_pcm_drop() can hang, so don't use that.
-         */
-        Uint32 delay = ((this->spec.samples * 1000) / this->spec.freq) * 2;
-        SDL_Delay(delay);
-
+//        /* Wait for the submitted audio to drain
+//           ALSA_snd_pcm_drop() can hang, so don't use that.
+//         */
+//        Uint32 delay = ((this->spec.samples * 1000) / this->spec.freq) * 2;
+//        SDL_Delay(delay);
+//
         ALSA_snd_pcm_close(this->hidden->pcm_handle);
     }
     SDL_free(this->hidden->mixbuf);

You don't see the issue with pipewire because (i) it doesn't go through SDL_RunAudio, and (ii) its CloseDevice doesn't try to wait. Alsa is affected the worst because it's hit by waits in both SDL_RunAudio and ALSA_CloseDevice. PulseAudio and Disk are waited through SDL_RunAudio. Haven't looked at other backends.

Well, if I say 'shutdown', it means shutdown dam'mit and that I don't care if any buffer is left to play because I did say 'shutdown". (We were hitting a slow shutdown issues in pulseaudio in SDL-1.2 but a patch was rejected because users might expect any left-over buffers to play, i.e. libsdl-org/SDL-1.2#673. I hope we don't do that here this time.)

@slouken slouken added this to the 2.32.0 milestone May 18, 2024
@icculus
Copy link
Collaborator

icculus commented May 20, 2024

Yeah, the waits are because you don't want it to drop the end of playback (you might have said "shutdown dammit," but you also said "play this buffer, dammit," and if you have a media player app it might mean the end of the song cuts off, etc).

The problem isn't the wait, it's the wait taking a long long time. There's no reason this should take minutes to quit, so there's probably a bug in the delay calculation. I'll take a look.

@AliceLR
Copy link
Contributor Author

AliceLR commented May 20, 2024

I think the delay calculation—at least in the snippet sezero pasted—is technically correct. At 1Hz with a 1024 frame buffer size, it will take up to 2048 seconds to clear both buffers, or ~34 minutes (consistent with the wait times I saw).

@sezero
Copy link
Contributor

sezero commented May 21, 2024

Yeah, the waits are because you don't want it to drop the end of playback (you might have said "shutdown dammit," but you also said "play this buffer, dammit," and if you have a media player app it might mean the end of the song cuts off, etc).

Well, I said "shutdown dammit" after I said "play this buffer dammit", so that should be considered as an overrule. And if a user hits ^shutdown' in his media player app, then it means he doesn't want to hear anything more.

I won't argue further though, let's just fix the issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants