MusicPlayerDaemon / MPD

Music Player Daemon
https://www.musicpd.org/
GNU General Public License v2.0
2.19k stars 350 forks source link

Disconnect Bluetooth headphone quits MPD #2079

Closed skidoo23 closed 4 months ago

skidoo23 commented 4 months ago

Bug report

Describe the bug

MPD quits when Bluetooth headphone turned off or loses connectivity.

Expected Behavior

Disable audio output and continue MPD operation.

Actual Behavior

See above

Version

bluez-alsa from git, MPD from git, Debian testing x64

Music Player Daemon 0.24 (v0.23.15-1430-gfe66cde61) Copyright 2003-2007 Warren Dukes warren.dukes@gmail.com Copyright 2008-2021 Max Kellermann max.kellermann@gmail.com This is free software; see the source for copying conditions. There is NO warranty; not even MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.

Database plugins: simple proxy

Storage plugins: local nfs

Decoder plugins: [mpg123] mp3 [mad] mp3 mp2 [vorbis] ogg oga [oggflac] ogg oga [flac] flac [opus] opus ogg oga [sndfile] wav aiff aif au snd paf iff svx sf voc w64 pvf xi htk caf sd2 [audiofile] wav au aiff aif [faad] aac [mpcdec] mpc [wavpack] wv [openmpt] mptm mod s3m xm it 669 amf ams c67 dbm digi dmf dsm dtm far imf ice j2b m15 mdl med mms mt2 mtm nst okt plm psm pt36 ptm sfx sfx2 st26 stk stm stp ult wow gdm mo3 oxm umx xpk ppm mmcmp [sidplay] sid mus str prg P00 [ffmpeg] 264 265 266 302 3g2 3gp 4xm 669 722 aa aa3 aac aax ac3 ac4 ace acm act adf adp ads adx aea afc aiff aix al alias_pix alp amf amr amrnb amrwb ams anm ans apc ape apl apm apng aptx aptxhd aqt argo_asf argo_brp argo_cvg art asc asf asf_o ass ast au avc avi avif avr avs avs2 avs3 bcstm bethsoftvid bfi bfstm bin bink binka bit bitpacked bmp_pipe bmv boa bonk brender_pix brstm c2 c93 caf cdata cdg cdxl cgi cif cine codec2raw concat cri_pipe dash dat data daud dav dbm dds_pipe dfa dff dfpwm dif digi dirac diz dmf dnxhd dpx_pipe dsf dsicin dsm dss dst dtk dtm dts dtshd dv dvbsub dvbtxt dxa ea eac3 ec3 evc exr_pipe f32be f32le f4v f64be f64le fap far ffmetadata film_cpk fits flac flic flm flv frm fsb fwse g722 g723_1 g726 g726le g729 gdm gdv gem_pipe genh gif gif_pipe gsm gxf h261 h263 h264 h265 h266 h26l hca hcom hdr_pipe hevc hls hnm ice ico idcin idf idx iff ifv ilbc image2 image2pipe imf imx ipmovie ipu ircam ism isma ismv iss it iv8 ivf ivr j2b j2k j2k_pipe jacosub jpeg_pipe jpegls_pipe jpegxl_pipe jv jxl kux kvag laf libgme lmlm4 loas lrc lvf lxf m15 m2a m4a m4b m4v mac mca mcc mdl med mgsts microdvd mj2 mjpeg mjpg mk3d mka mks mkv mlp mlv mm mmcmp mmf mms mo3 mod mods moflex mov mp2 mp3 mp4 mpa mpc mpc8 mpeg mpegts mpegtsraw mpegvideo mpl2 mpo mptm msbc msf msnwctcp msp mt2 mtaf mtm mtv musx mv mvi mxf mxg nfo nist nsp nst nsv nut nuv obu ogg okt oma omg osq paf pam_pipe pbm_pipe pcx_pipe pdv pfm_pipe pgm_pipe pgmyuv_pipe pgx_pipe phm_pipe photocd_pipe pictor_pipe pjs plm pmp png_pipe pp_bnk ppm ppm_pipe psd_pipe psm psp psxstr pt36 ptm pva pvf qcif qcp qdraw_pipe qoi_pipe r3d rco rcv rgb rka rl2 rm roq rpl rsd rso rt rtp rtsp s16be s24be s24le s32be s32le s337m s3m sami sap sb sbc sbg scc scd sdns sdp sdr2 sds sdx ser sf sfx sfx2 sga sgi_pipe shn sln smi smk smush sol son sox spdif sph srt ss2 st26 stk stl stm stp str sub sunrast_pipe sup svag svg_pipe svs sw swf tak tco tedcaptions thd thp tiertexseq tiff_pipe tmv tta txd txt ty ty+ u16be u24be u24le u32be u32le ub ul ult umx usm uw v v210 vag vb vbn_pipe vc1 vidc viv vividas vmd voc vpk vqe vqf vql vt vtt vvc w64 wa wav way wc3movie webm webm_dash_manifest webp_pipe wow wsaud wsd wsvqa wtv wv wve xa xbin xbm_pipe xl xm xmd xmv xpk xpm_pipe xvag xwd_pipe xwma y4m yop yuv yuv10 rtp:// rtsp:// rtsps:// [pcm]

Filters: libsamplerate soxr

Tag plugins: id3tag

Output plugins: null fifo pipe alsa httpd snapcast

Encoder plugins: null vorbis opus lame wave flac

Archive plugins: [bz2] bz2 [zzip] zip [iso] iso

Input plugins: file io_uring archive alsa curl ffmpeg nfs mms

Playlist plugins: extm3u m3u pls xspf asx rss flac cue embcue

Protocols: file:// alsa:// ftp:// ftps:// gopher:// hls+http:// hls+https:// http:// https:// mms:// mmsh:// mmst:// mmsu:// nfs:// rtmp:// rtmpe:// rtmps:// rtmpt:// rtmpte:// rtmpts:// rtp:// rtsp:// rtsps:// scp:// sftp:// smb:// srtp://

Other features: dbus epoll icu inotify systemd tcp un

Configuration

(...) audio_output { type "alsa" name "Sony WH-1000XM4" device "bluealsa:DEV=00:11:22:33:44:55,PROFILE=a2dp,CODEC=aac" mixer_type "hardware" mixer_device "bluealsa" mixer_control "WH-1000XM4 A2DP" }

Log

# mpd --stderr --no-daemon --verbose
config_file: loading file "/etc/mpd.conf"
soxr: soxr converter "high"
vorbis: Xiph.Org libVorbis 1.3.7
opus: libopus 1.5.2
sndfile: libsndfile-1.2.2
simple_db: reading DB
curl: version 8.8.0
curl: with GnuTLS/3.8.6
state_file: Loading state file /var/lib/mpd/state
event: RTIOThread could not get realtime scheduling, continuing anyway: sched_setscheduler failed: Operation not permitted
playlist: queue song 53:"sound.mp3"
decoder_thread: probing plugin mpg123
output: OutputThread could not get realtime scheduling, continuing anyway: sched_setscheduler failed: Operation not permitted
decoder: audio_format=44100:16:2, seekable=true
alsa_output: opened "bluealsa:DEV=00:11:22:33:44:55,PROFILE=a2dp,CODEC=aac" type=PLUG
alsa_output: buffer: size=882..481689 time=20000..10922654
alsa_output: period: size=441..240845 time=10000..5461334
alsa_output: default period_time = buffer_time/4 = 500000/4 = 125000
alsa_output: format=S16_LE (Signed 16 bit Little Endian)
alsa_output: buffer_size=22050 period_size=5512
output: opened "Sony WH-1000XM4" (alsa) audio_format=44100:16:2
(Sound plays normal. Now turn off headphone)
output: Failed to play on "Sony WH-1000XM4" (alsa): snd_pcm_poll_descriptors_revents() failed: No such device
output: closed "Sony WH-1000XM4" (alsa)
exception: Failed to open audio output
(Connect to MPD)
client: [0] opened from ?
client: [0] process command list
client: process command "tagtypes \"all\""
client: command returned 0
client: process command "tagtypes"
client: command returned 0
client: [0] process command list returned 0
client: [0] process command list
client: process command "tagtypes \"clear\""
client: command returned 0
client: process command "tagtypes enable Artist Album AlbumArtist Title Track Name Genre Date Composer Performer Disc Work Conductor"
client: command returned 0
client: [0] process command list returned 0
client: [0] process command "status"
mpd: simple.c:296: snd_mixer_selem_get_playback_dB_range: Assertion `(elem)->type == SND_MIXER_ELEM_SIMPLE' failed.
Abgebrochen
MaxKellermann commented 4 months ago

Need a backtrace

borine commented 4 months ago

mixer_type "hardware"

When a BlueALSA device disconnects, its ALSA control is removed from the BlueALSA mixer (in fact all controls are removed, then a new set added without the diconnected one). The MPD ALSA mixer plugin cannot handle this behaviour, and continues to use its (now invalid) control element handle. This triggers an assertion abort within libasound.

You could switch to mixer_type "software", especially as by default BlueALSA uses its own software volume control for A2DP streams anyway.

Or if you have enabled A2DP pass-through volume control in BlueALSA then you could try using the BlueALSA "Single Device" mixer mode with dynamic operation disabled. For example:

mixer_type "hardware"
mixer_device "bluealsa:DEV=00:11:22:33:44:55,DYN=no"
mixer_control "A2DP"

See the bluealsa-plugins manual page for details.

MaxKellermann commented 4 months ago

But there must be a way to use libasound without it crashing. @borine what you describe is a workaround, but not a fix for the bug. Right now, I'm not sure if it's a MPD bug or a libasound bug.

borine commented 4 months ago

not sure if it's a MPD bug or a libasound bug.

Well IMHO the fact that libasound uses assert() to catch invalid user data instead of simply returning EINVAL is a bug. However, others disagree, and you may form your own views on that.

As is often the case with libasound, the real problem is lack of detailed documentation. Within the function AlsaMixer::ElemCallback() MPD tests the event value against the mask SND_CTL_EVENT_MASK_VALUE without first testing it against SND_CTL_EVENT_MASK_REMOVE. So it does not know that the element has been removed and instead interprets the event as a value change. The alsa-lib API documentation for that is here https://www.alsa-project.org/alsa-doc/alsa-lib/group___control.html#ga2648d4242f8d5be01ecc6e36bc2cf335. Yes, really, so I think the (many) projects which miss that detail can be forgiven.

I've never come across a soundcard mixer that has removable elements, so this subtle requirement is very rarely encountered. Unfortunately the default BlueALSA mixer has controls for all connected Bluetooth devices, so has no option other than to make them removable. That is why the "Single Device" mode exists, and so I would not consider its use as a "workaround" in this case.

borine commented 4 months ago

Hmm, @skidoo23 I've just tried BlueALSA single device mode and there is a problem with playback such that mpc vol 60 for example correctly sets the mixer A2DP control to 60% but then playback immediately pauses with the error message:

output: Failed to play on "Bluetooth" (alsa): snd_pcm_poll_descriptors_revents() failed: No such device

even though the device is still connected and play can be continued simply with mpc play.

So it looks like mixer_type "software" is the only working option for BlueALSA at present. I'll add looking at that to my TODO list but can't guarantee that I will ever find time for it.

borine commented 4 months ago

@skidoo23 - I've just remembered the cause of this single device mode failure with mpd - its the values that mpd passes to snd_pcm_poll_descriptors_revents(). I have a patch for bluez-alsa that works around this, but I think it will never be accepted into bluez-alsa upstream. If you build BlueALSA yourself, then this patch, together with the use of single device mode DYN=no for the mixer, will enable hardware volume control.

diff --git a/src/asound/bluealsa-pcm.c b/src/asound/bluealsa-pcm.c
index 7e1ff70..64da952 100644
--- a/src/asound/bluealsa-pcm.c
+++ b/src/asound/bluealsa-pcm.c
@@ -1004,6 +1004,24 @@ static int bluealsa_poll_revents(snd_pcm_ioplug_t *io, struct pollfd *pfd,
    if (nfds < 1)
        return -EINVAL;

+   /* Prior to alsa-lib release 1.2.11, the snd_pcm_poll_revents() function
+    * was not properly documented, and as a result some applications do not
+    * pass the correct values for the pfd and nfds arguments (for example
+    * MPD).
+    * Rather than returning EINVAL in such cases, we tolerate such abuse by
+    * calling poll() ourselves. */
+   const unsigned int real_nfds = bluealsa_poll_descriptors_count(io);
+   if (pfd[0].fd != pcm->event_fd || nfds != real_nfds) {
+       struct pollfd *real_pfd = alloca(real_nfds * sizeof(struct pollfd));
+       bluealsa_poll_descriptors(io, real_pfd, real_nfds);
+       while ((ret = poll(real_pfd, real_nfds, 0)) < 0 && errno == EINTR)
+           continue;
+       if (ret < 1)
+           return ret;
+       pfd = real_pfd;
+       nfds = real_nfds;
+   }
+
    ba_dbus_connection_poll_dispatch(&pcm->dbus_ctx, &pfd[1], nfds - 1);
    while (dbus_connection_dispatch(pcm->dbus_ctx.conn) == DBUS_DISPATCH_DATA_REMAINS)
        continue;

The specific ALSA documentation refered to in the patch is: snd_pcm_poll_descriptors_revents()

skidoo23 commented 4 months ago

(gdb) bt

0 __pthread_kill_implementation

(threadid=<optimized out>, signo=signo@entry=6, no_tid=no_tid@entry=0)
at ./nptl/pthread_kill.c:44

1 0x00007ffff17c4b6f in __pthread_kill_internal

(signo=6, threadid=<optimized out>) at ./nptl/pthread_kill.c:78

2 0x00007ffff17764e2 in __GI_raise (sig=sig@entry=6)

at ../sysdeps/posix/raise.c:26

3 0x00007ffff175f4ed in __GI_abort () at ./stdlib/abort.c:79

4 0x00007ffff175f415 in __assert_fail_base

(fmt=0x7ffff18d5ba8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x7ffff4448920 "(elem)->type == SND_MIXER_ELEM_SIMPLE", file=file@entry=0x7ffff4444792 "simple.c", line=line@entry=296, function=function@entry=0x7ffff4450c80 "snd_mixer_selem_get_playback_dB_range") at ./assert/assert.c:92

5 0x00007ffff176f002 in __assert_fail

(assertion=0x7ffff4448920 "(elem)->type == SND_MIXER_ELEM_SIMPLE", file=0x7ffff4444792 "simple.c", line=296, function=0x7ffff4450c80 "snd_mixer_selem_get_playback_dB_range") at ./assert/assert.c:101

6 0x00007ffff43c9e61 in snd_mixer_selem_get_playback_dB_range ()

at /lib/x86_64-linux-gnu/libasound.so.2

7 0x00005555556baa47 in get_normalized_volume(snd_mixer_elem_t*, snd_mixer_selem_channel_id_t, ctl_dir)

(elem=0x5555590dfb70, channel=SND_MIXER_SCHN_FRONT_LEFT, ctl_dir=PLAYBACK)
at ../src/mixer/plugins/VolumeMapping.cxx:84

--Type for more, q to quit, c to continue without paging--c

8 0x00005555556bafb4 in get_normalized_playback_volume(_snd_mixer_elem*, _snd_mixer_selem_channel_id)

(elem=0x5555590dfb70, channel=SND_MIXER_SCHN_FRONT_LEFT)
at ../src/mixer/plugins/VolumeMapping.cxx:164

9 0x00005555556ba053 in AlsaMixer::GetNormalizedVolume() const

(this=0x55555621a4f0) at ../src/mixer/plugins/AlsaMixerPlugin.cxx:115

10 0x00005555556ba06e in AlsaMixer::GetPercentVolume() const

(this=0x55555621a4f0) at ../src/mixer/plugins/AlsaMixerPlugin.cxx:121

11 0x00005555556b9cdc in AlsaMixer::GetVolume() (this=0x55555621a4f0)

at ../src/mixer/plugins/AlsaMixerPlugin.cxx:312

12 0x00005555556bb326 in Mixer::LockGetVolume() (this=0x55555621a4f0)

at ../src/mixer/Mixer.cxx:66

13 0x00005555556bbeae in output_mixer_get_volume(AudioOutputControl const&)

(ao=...) at ../src/mixer/All.cxx:33

14 0x00005555556bbf82 in MultipleOutputs::GetVolume() const

(this=0x5555559e4c58) at ../src/mixer/All.cxx:49

15 0x00005555555fd73c in MixerMemento::GetVolume(MultipleOutputs const&)

(this=0x5555559e4ca0, outputs=...) at ../src/mixer/Memento.cxx:26

16 0x000055555558c76d in handle_status(Client&, Request, Response&)

(client=..., args=..., r=...) at ../src/command/PlayerCommands.cxx:119

17 0x0000555555589061 in command_process(Client&, unsigned int, char*)

(client=..., num=0, line=0x5555590dd700 "status")
at ../src/command/AllCommands.cxx:428

18 0x00005555555ac108 in Client::ProcessLine(char*)

(this=0x5555590dd6e0, line=0x5555590dd700 "status")
at ../src/client/Process.cxx:121

19 0x00005555555ad240 in Client::OnSocketInput(std::span<std::byte, 18446744073709551615ul>) (this=0x5555590dd6e0, src=std::span of length 7 = {...})

at ../src/client/Read.cxx:33

20 0x0000555555638450 in BufferedSocket::ResumeInput() (this=0x5555590dd6e8)

at ../src/event/BufferedSocket.cxx:59

21 0x0000555555638625 in BufferedSocket::OnSocketReady(unsigned int)

(this=0x5555590dd6e8, flags=1) at ../src/event/BufferedSocket.cxx:96

22 0x0000555555639043 in FullyBufferedSocket::OnSocketReady(unsigned int)

(this=0x5555590dd6e8, flags=1) at ../src/event/FullyBufferedSocket.cxx:89

23 0x00005555555abb1b in BindMethodDetail::WrapperGenerator<void (BufferedSocket::)(unsigned int) noexcept, &BufferedSocket::OnSocketReady>::Invoke(void, unsigned int) (_instance=0x5555590dd6e8, args#0=1)

at ../src/util/BindMethod.hxx:102

24 0x0000555555637ee6 in BoundMethod<void (unsigned int) noexcept>::operator()(unsigned int) const (this=0x5555590df718, args#0=1)

at ../src/util/BindMethod.hxx:52

25 0x0000555555638257 in SocketEvent::Dispatch() (this=0x5555590df700)

at ../src/event/SocketEvent.cxx:105

26 0x000055555563d65d in EventLoop::Run() (this=0x7fffffffccc8)

at ../src/event/Loop.cxx:365

27 0x0000555555580613 in MainConfigured(CommandLineOptions const&, ConfigData const&) (options=..., raw_config=...) at ../src/Main.cxx:512

28 0x0000555555580881 in MainOrThrow(int, char**)

(argc=4, argv=0x7fffffffeca8) at ../src/Main.cxx:663

29 0x00005555555808d5 in mpd_main(int, char**) (argc=4, argv=0x7fffffffeca8)

at ../src/Main.cxx:669

30 0x0000555555580928 in main(int, char**) (argc=4, argv=0x7fffffffeca8)

at ../src/Main.cxx:681
skidoo23 commented 4 months ago

@skidoo23 - I've just remembered the cause of this single device mode failure with mpd - its the values that mpd passes to snd_pcm_poll_descriptors_revents(). I have a patch for bluez-alsa that works around this, but I think it will never be accepted into bluez-alsa upstream. If you build BlueALSA yourself, then this patch, together with the use of single device mode DYN=no for the mixer, will enable hardware volume control.

No more crashes :) thx!

MaxKellermann commented 4 months ago

Try again with latest MPD master

skidoo23 commented 4 months ago

With recent bluez-alsa master (without any modifiations) and MPD master crashes are gone. For immediate and smooth volume changes I use the audio_output below

audio_output {
        type            "alsa"
        name            "Sony WH-1000XM4"
        device          "bluealsa:DEV=00:11:22:33:44:55,PROFILE=a2dp,CODEC=aac"
        mixer_type      "hardware"
        mixer_device    "bluealsa:DEV=00:11:22:33:44:55,DYN=no"
        mixer_control   "A2DP"
}

Kudos to @borine and @MaxKellermann

MaxKellermann commented 4 months ago

Then this was fixed by 90dfa437e024a0967557e31ccc4ff452a15cf691 which implements the semantic libasound ABI change from https://github.com/alsa-project/alsa-lib/commit/cd04da2bcfe147b08b8db2930b2294aead0a8968