Mpd crash consistently when about to play some certain songs in the queue

[hiecaq]

Bug report

Describe the bug

After upgrading to 0.21.9 from 0.21.8, my MPD starts to crash consistently when it's about to play some certain songs. This only happens if it's switched by mpd itself, i.e. it only happens when the previous playing song reach the end. I determined that the cause is the next song instead of the current playing song by switching the order of the songs in the playlist. Also, if I manually select to start playing these songs that cause the crash, they can be played normally. If I downgrade back to 0.21.8, mpd can autoplay these songs normally.

Version

Music Player Daemon 0.21.9 (0.21.9)
Copyright 2003-2007 Warren Dukes <warren.dukes@gmail.com>
Copyright 2008-2018 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 upnp

Storage plugins:
 local smbclient udisks nfs curl

Neighbor plugins:
 smbclient upnp udisks

Decoders plugins:
 [mad] mp3 mp2
 [mpg123] mp3
 [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
 [dsdiff] dff
 [dsf] dsf
 [hybrid_dsd] m4a
 [faad] aac
 [mpcdec] mpc
 [wavpack] wv
 [modplug] 669 amf ams dbm dfm dsm far it med mdl mod mtm mt2 okt s3m stm ult umx xm
 [mikmod] amf dsm far gdm imf it med mod mtm s3m stm stx ult uni xm
 [wildmidi] mid
 [fluidsynth] mid
 [ffmpeg] 16sv 3g2 3gp 4xm 8svx aa3 aac ac3 adx afc aif aifc aiff al alaw amr anim apc ape asf atrac au aud avi avm2 avs bap bfi c93 cak cin cmv cpk daud dct divx dts dv dvd dxa eac3 film flac flc fli fll flx flv g726 gsm gxf iss m1v m2v m2t m2ts m4a m4b m4v mad mj2 mjpeg mjpg mka mkv mlp mm mmf mov mp+ mp1 mp2 mp3 mp4 mpc mpeg mpg mpga mpp mpu mve mvi mxf nc nsv nut nuv oga ogm ogv ogx oma ogg omg opus psp pva qcp qt r3d ra ram rl2 rm rmvb roq rpl rvc shn smk snd sol son spx str swf tak tgi tgq tgv thp ts tsp tta xa xvid uv uv2 vb vid vob voc vp6 vmd wav webm wma wmv wsaud wsvga wv wve
 [gme] ay gbs gym hes kss nsf nsfe sap spc vgm vgz
 [pcm]

Filters:
 libsamplerate soxr

Tag plugins:
 id3tag

Output plugins:
 shout null fifo pipe alsa ao oss openal solaris pulse jack httpd recorder

Encoder plugins:
 null vorbis opus lame twolame wave flac

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

Input plugins:
 file archive alsa tidal qobuz curl ffmpeg smbclient nfs mms cdio_paranoia

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

Protocols:
 file:// alsa:// tidal:// qobuz:// http:// https:// gopher:// rtp:// rtsp:// rtmp:// rtmpt:// rtmps:// smb:// nfs:// mms:// mmsh:// mmst:// mmsu:// cdda://

Other features:
 avahi dbus udisks epoll icu inotify ipv6 systemd tcp un

Log

mpd.conf:

playlist_directory              "~/.local/share/mpd/playlists"
db_file                 "~/.local/share/mpd/database"
pid_file                        "/tmp/mpd_pid"
state_file                      "~/.local/share/mpd/state"
sticker_file                    "~/.local/share/mpd/sticker.sql"
auto_update     "yes"
input {
        plugin "curl"
}
audio_output {
        type            "pulse"
        name            "pulse audio"
}
audio_output {
    type                    "fifo"
    name                    "Visualizer feed"
    path                    "/tmp/mpd.fifo"
    format                  "44100:16:2"
}

For mpd --verbose, coredump and strace, see:

https://gist.github.com/quinoa42/f03c704b4f491dda3ba91b6f613a7830

EDIT: sorry that I forgot to enable DEBUG symbols, now the logs are fixed

[aidanharris]

This happened to me too, the exact same assertion failure in the logs:

mpd: ../mpd-0.21.9/src/player/Thread.cxx:1003: void Player::Run(): Assertion `dc.pipe == nullptr || dc.pipe == pipe' failed.

In my case mpd didn't leave a core dump though and since re-compiling it with debug symbols I've yet to reproduce the issue.

[geneticdrift]

mpd: ../mpd.upstream/src/player/Thread.cxx:1006: void Player::Run(): Assertion 'dc.pipe == nullptr || dc.pipe == pipe' failed.

Thread 5 "player" received signal SIGABRT, Aborted.
[Switching to Thread 0x7fffe2975700 (LWP 17738)]
__GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
50      ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0  0x00007ffff2025ed7 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007ffff2007535 in __GI_abort () at abort.c:79
#2  0x00007ffff200740f in __assert_fail_base
    (fmt=0x7ffff2195588 "%s%s%s:%u: %s%sAssertion '%s' failed.\n%n", assertion=0x555555674b60 "dc.pipe == nullptr || dc.pipe == pipe", file=0x555555674968 "../mpd.upstream/src/player/Thread.cxx", line=1006, function=) at assert.c:92
#3  0x00007ffff2017012 in __GI___assert_fail
    (assertion=assertion@entry=0x555555674b60 "dc.pipe == nullptr || dc.pipe == pipe", file=file@entry=0x555555674968 "../mpd.upstream/src/player/Thread.cxx", line=line@entry=1006, function=function@entry=0x555555675060  "void Player::Run()") at assert.c:101
#4  0x00005555555a815f in Player::Run() (this=this@entry=0x7fffe29744d0) at /usr/include/c++/8/bits/std_mutex.h:107
#5  0x00005555555a5de4 in do_play (buffer=..., dc=..., pc=...) at ../mpd.upstream/src/player/Thread.cxx:1126
#6  0x00005555555a5de4 in PlayerControl::RunThread() (this=0x5555557371c0) at ../mpd.upstream/src/player/Thread.cxx:1151
#7  0x00005555555d0c03 in BoundMethod::operator()() const (this=0x5555557371e8, this=0x5555557371e8) at ../mpd.upstream/src/util/BindMethod.hxx:76
#8  0x00005555555d0c03 in Thread::Run() (this=0x5555557371e8) at ../mpd.upstream/src/thread/Thread.cxx:63
#9  0x00005555555d0c03 in Thread::ThreadProc(void*) (ctx=0x5555557371e8) at ../mpd.upstream/src/thread/Thread.cxx:92
#10 0x00007ffff21d6182 in start_thread (arg=) at pthread_create.c:486
#11 0x00007ffff20ffb1f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Code from master branch 40a48cfba 2019-05-22

Strangely, this is consistently reproducible for me when the song duration is 1 second, but not with "normal" length songs.

I'm not familiar with the source code, but something looks suspicious with the second call to StartDecoder: it passes a new temp pipe pointer but the local pipe is not updated. Also StartDecoder std::moves the pipe to the controller. So I'm confused about the meaning of the assert.

[hiecaq]

As @geneticdrift said, I realized that all songs caused the crash are shorter than 10 seconds.

[mvdan]

When is the next bugfix release planned? I encounter this crash daily, so I am forced to downgrade manually.