1274479 - Crash in shutdownhang | stuck in winmm_stream_destroy and winmm_buffer_thread

Status: RESOLVED FIXED

(Core :: Audio/Video: cubeb, defect, P2)

Description

[Alastor Wu [:alwu]]

This bug was filed from the Socorro interface and is 
report bp-38b3fd81-44ff-4454-9a8e-1e1812160519.
=============================================================

Thread 43
- winmm_buffer_thread call WaitForSingleObject

Thread 54
- winmm_stream_destroy call WaitForSingleObject

Maybe the hang is because both two functions are calling WaitForSingleObject at same time.

Comment 1

[Alastor Wu [:alwu]]

These reports also have the same problem.

Thread 35, 63.
https://crash-stats.mozilla.com/report/index/48183375-0790-48e7-9115-a246a2160513#allthreads

Thread 43, 54, 55.
https://crash-stats.mozilla.com/report/index/b55eb09a-00a6-44f4-8d82-ca1932160516#allthreads

Comment 2

[Tzuhao Kuo [:kaku]]

Here are more related reports:

https://crash-stats.mozilla.com/report/index/d6e1011c-a1e7-4ed6-897c-b1daf2160526#allthreads 
Thread: 34, 44, 54, 56

https://crash-stats.mozilla.com/report/index/6d4ed256-e12f-46c4-a9b9-04bb22160526#allthreads
Thread: 36, 41

https://crash-stats.mozilla.com/report/index/e1e22c0e-bdd4-460e-b12d-fbdff2160525#allthreads
Thread: 28, 33

https://crash-stats.mozilla.com/report/index/a9832637-f10d-4c96-b453-842602160525
Thread: 30, 35

https://crash-stats.mozilla.com/report/index/adad1f9f-5d7d-43c6-9a7d-09e942160525#allthreads
Thread: 30, 39

https://crash-stats.mozilla.com/report/index/a4354d0a-0f71-4c52-b7a5-4d0832160525#allthreads
Thread: 40, 43

Comment 3

[Matthew Gregan [:kinetik]]

This is showing up on Windows 7, Windows 10, and Windows XP.  For Vista+, we prefer the WASAPI backend over WinMM and for XP WinMM is the only option.

So we need to explain why the hang happens on XP and also why Vista+ machines are ending up suck in the WinMM background.

My theory, which I've tested and used to reproduce this hang on Windows 10, is that this is related to the initial absence (on Vista+) and eventual removal of the last viable audio output device.

Steps to reproduce on Vista+:
- Disable all audio output devices in the Sound control panel
- Play some audio media
- Notice that there's no audio
- Attach an output device (e.g. plug in a headset)
- Reload media and enjoy audio

At this point, cubeb_init (which is only called once) has already failed to initialize WASAPI and fallen back to WinMM.  When the media is reloaded, cubeb_stream_init is using the WinMM backend to allocate a stream.

This explains how Vista+ machines can end up here, now the explanation that covers all Windows, including XP:

Steps to reproduce on XP (or Vista+ with above steps included):
- While media is playing or paused, remove/disable the last viable audio output device
  (if media was playing, playback will "hang" because the audio clock stops advancing)
- Close tab containing media (or any other action that triggers audio stream destruction, e.g. seeking)

At this point, winmm_stream_destroy request (via waveOutReset) and then wait on the (old, now invalidated) audio device to free the audio buffers on stm->event.  This event will never be signaled, because the device no longer exists to free the buffers.

Debugging notes:
- This fallback behaviour is undesirable on Vista+, we'd prefer to use WASAPI when we can, which should be possible once a device has been attached.
- The playback "hang" on device removal with WinMM is undesirable, ideally we'd detect the device was removed quickly and error/shutdown the audio stream.
- winmm_stream_stop called before winmm_stream_destroy will return an error because waveOutPause returns MMSYSERR_NODRIVER, but AudioStream::Shutdown ignores the result of cubeb_stream_stop because it's about to destroy the stream.
- winmm_stream_destroy doesn't check the result of waveOutReset (I think it has a valid reason for ignoring at least some error codes, but perhaps we can detect the absence of a valid device here).
- winmm_stream_destroy may also be able to use a timeout on the WaitForSingleObject to avoid hanging here.

Comment 4

[Matthew Gregan [:kinetik]]

(In reply to Matthew Gregan [:kinetik] from comment #3)
> - The playback "hang" on device removal with WinMM is undesirable, ideally
> we'd detect the device was removed quickly and error/shutdown the audio
> stream.

We can detect this, and cubeb is already returning an error, so the problem may be in one of the callers.  In this case, inside winmm_stream_get_position, waveOutGetPosition returns MMSYSERR_INVALHANDLE which results in returning CUBEB_ERROR which AudioStream::GetPosition turns into a return of -1.

Comment 5

[Matthew Gregan [:kinetik]]

Other stuff to do:
- change telemetry to track first-vs-subsequent cubeb_init attempts
  before all WASAPI failures turned into WinMM backends, now we can see real failures

(In reply to Matthew Gregan [:kinetik] from comment #3)
> - winmm_stream_destroy doesn't check the result of waveOutReset (I think it
> has a valid reason for ignoring at least some error codes, but perhaps we
> can detect the absence of a valid device here).

We used to simply assert(r == MMSYSERR_NOERROR) before bug 742154 (specifically changeset https://github.com/kinetiknz/cubeb/commit/1188ca3429acd752ca335ae0085c57354f55ec0b) started ignoring the result completely.

Despite waveOutReset having MMSYSERR_INVALHANDLE and MMSYSERR_NODRIVER as documented error returns, in the case of the current audio device being removed it returns MMSYSERROR_NOERROR, so we need a way to detect the device has disappeared on shutdown.  Possibly setting a flag when waveOutPause in winmm_stream_stop fails.

Comment 6

[Matthew Gregan [:kinetik]]

Attachment: wip

Comment 7

[Matthew Gregan [:kinetik]]

Attachment: wip

Comment 8

[Matthew Gregan [:kinetik]]

Attachment: fix v1

Comment 9

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/db9b0546e3d4
Update libcubeb.  r=padenot

Comment 10

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/db9b0546e3d4