search

MusicPlayerDaemon / MPD

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

Hang during database update on Debian (bullseye -- trixie) on Sheevaplug #2119

Open samer-- opened 5 days ago

samer-- commented 5 days ago

Bug report

Describe the bug

Since upgrading Sheevaplug to Debian Bullseye, MPD update thread hangs on startup. The music library contains only playlists. No music tracks are visible. Only the first directory appears in the music directory tree is visible, but is unpopulated.

Music files are fine, readble, and playable with other tools (mplayer, mpv etc). Music files are owned by root, in group audio and world readable. The first music filename appears in the log - see further diagnosis below.

After hang, MPD can only be killed with kill -9

Expected Behavior

Music library is populated with my music.

Actual Behavior

No tracks are added to music library.

Version

I tried this with the vanilla Debian mpd package in bullseye, then bookworm, then Trixie, all with the same result. I got the Debian source package and rebuilt it with debug symbols and many plugins disabled.

Music Player Daemon 0.23.15 (0.23.15)
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 udisks

Decoders plugins:
 [mad] mp3 mp2
 [mpg123] mp3
 [vorbis] ogg oga
 [oggflac] ogg oga
 [flac] flac
 [sndfile] wav aiff aif au snd paf iff svx sf voc w64 pvf xi htk caf sd2
 [dsdiff] dff
 [dsf] dsf
 [hybrid_dsd] m4a
 [faad] aac
 [mpcdec] mpc
 [adplug] amd d00 hsc laa rad raw sa2
 [pcm]

Filters:
 libsamplerate

Tag plugins:
 id3tag

Output plugins:
 null fifo sndio pipe alsa ao oss httpd snapcast recorder

Encoder plugins:
 null wave flac shine

Input plugins:
 file io_uring alsa

Playlist plugins:
 extm3u m3u pls flac cue embcue

Protocols:
 file:// alsa://

Other features:
 dbus udisks epoll iconv inotify ipv6 systemd tcp un

Configuration

music_directory         "/var/lib/mpd/music"
playlist_directory              "/var/lib/mpd/playlists"
state_file                      "/var/lib/mpd/state"
sticker_file                   "/var/lib/mpd/sticker.sql"

user                            "mpd"
group                           "audio"
bind_to_address         "any"
auto_update     "no"
follow_outside_symlinks "yes"
follow_inside_symlinks          "yes"
zeroconf_enabled                "no"

database {
       plugin "simple"
       path "/var/lib/mpd/tag_cache"
       cache_directory "/var/lib/mpd/cache"
}

decoder {
   plugin "ffmpeg"
   enabled "no"
}
decoder {
   plugin "mad"
   enabled "yes"
}
decoder {
   plugin "mpg123"
   enabled "no"
}
decoder {
   plugin "opus"
   enabled "no"
}
decoder {
   plugin "sndfile"
   enabled "yes"
}
decoder {
   plugin "flac"
   enabled "no"
}
decoder {
   plugin "oggflac"
   enabled "no"
}
decoder {
   plugin "vorbis"
   enabled "yes"
}
decoder {
        plugin                  "hybrid_dsd"
        enabled                 "no"
}
decoder {
        plugin        "fluidsynth"
        enabled       "no"
}
decoder {
        plugin        "wildmidi"
        enabled       "no"
}
audio_output {
        type            "alsa"
        name            "ALSA direct"
        buffer_time     "500000"
        period_time "20000"
}
audio_output {
        type            "alsa"
        name            "ALSA dmixer"
}
replaygain                      "auto"
filesystem_charset              "UTF-8"

Log

Running with gdb reveals hang on a mutex/lock/condition variable

[]# gdb ..../debsrc/mpd-0.23.15/debian/mpd/usr/bin/mpd
GNU gdb (Debian 15.1-1) 15.1
Copyright (C) 2024 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "arm-linux-gnueabi".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /home/samer/src/debsrc/mpd-0.23.15/debian/mpd/usr/bin/mpd...
(gdb) replaygain                      "auto"
Undefined command: "replaygain".  Try "help".
(gdb)
Undefined command: "replaygain".  Try "help".
(gdb) run --stderr --verbose --no-daemon
Starting program: /home/samer/src/debsrc/mpd-0.23.15/debian/mpd/usr/bin/mpd --stderr --verbose --no-daemon
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/arm-linux-gnueabi/libthread_db.so.1".
config_file: loading file /etc/mpd.conf
server_socket: bind to '0.0.0.0:6600' failed (continuing anyway, because binding to '[::]:6600' succeeded): Failed to bind socket: Address already in use
libsamplerate: libsamplerate converter 'Fastest Sinc Interpolator'
sndfile: libsndfile-1.2.2
adplug: adplug 2.3.3
simple_db: reading DB
exception: Database corrupted
[New Thread 0xb5dcc360 (LWP 15155)]
[New Thread 0xb55cb360 (LWP 15156)]
event: RTIOThread could not get realtime scheduling, continuing anyway: sched_setscheduler failed: Operation not permitted
[New Thread 0xb4dca360 (LWP 15157)]
update: spawned thread for update job id 1
state_file: Loading state file /var/lib/mpd/state
update: starting
update: reading Programmes/Bach Christmas.mp3

NB. program unresponsive to Ctrl-C at this point. Ctrl-Z returns control to gdb.

^Z
Thread 1 "mpd" received signal SIGTSTP, Stopped (user).
0xb65b5484 in epoll_wait () from /lib/arm-linux-gnueabi/libc.so.6
(gdb) thread find .*
Thread 1 has target name 'mpd'
Thread 1 has target id 'Thread 0xb62e3020 (LWP 15153)'
Thread 2 has target name 'io'
Thread 2 has target id 'Thread 0xb5dcc360 (LWP 15155)'
Thread 3 has target name 'rtio'
Thread 3 has target id 'Thread 0xb55cb360 (LWP 15156)'
Thread 4 has target name 'update'
Thread 4 has target id 'Thread 0xb4dca360 (LWP 15157)'
(gdb) thread 4
[Switching to thread 4 (Thread 0xb4dca360 (LWP 15157))]
#0  0xb6534b6c in ?? () from /lib/arm-linux-gnueabi/libc.so.6
(gdb) bt
#0  0xb6534b6c in ?? () from /lib/arm-linux-gnueabi/libc.so.6
#1  0xb6534cc4 in ?? () from /lib/arm-linux-gnueabi/libc.so.6
#2  0xb6537ebc in pthread_cond_wait () from /lib/arm-linux-gnueabi/libc.so.6
#3  0x0050d4a0 in AsyncInputStream::Read (this=0xb4210cd0, lock=..., ptr=0xb4dc97bc, read_size=32) at ../src/input/AsyncInputStream.cxx:200
#4  0x0050c5b4 in InputStream::ReadFull (this=0xb4210cd0, lock=..., _ptr=0xb4dc97bc, _size=32) at ../src/input/InputStream.cxx:130
#5  0x00526ca8 in tag_ape_scan (is=..., callback=...) at ../src/tag/ApeLoader.cxx:50
#6  0x005245b4 in tag_ape_scan2 (is=..., handler=...) at ../src/tag/ApeTag.cxx:82
#7  0x0052362c in ScanGenericTags (is=..., handler=...) at ../src/tag/Generic.cxx:35
#8  0x005236f4 in ScanGenericTags (path=..., handler=...) at ../src/tag/Generic.cxx:53
#9  0x004a8284 in ScanFileTagsWithGeneric (path=..., builder=..., audio_format=0xb4dc98cc) at ../src/TagFile.cxx:102
#10 0x004a0c20 in Song::UpdateFile (this=0xb4210b58, storage=...) at ../src/SongUpdate.cxx:90
#11 0x004a0964 in Song::LoadFile (storage=..., path_utf8=0xb4210ac8 "Bach Christmas.mp3", parent=...) at ../src/SongUpdate.cxx:59
#12 0x005ac274 in UpdateWalk::UpdateSongFile2 (this=0x674f88, directory=..., name=0xb4210ac8 "Bach Christmas.mp3", suffix="mp3", info=...) at ../src/db/update/UpdateSong.cxx:66
#13 0x005ac5c8 in UpdateWalk::UpdateSongFile (this=0x674f88, directory=..., name=0xb4210ac8 "Bach Christmas.mp3", suffix="mp3", info=...) at ../src/db/update/UpdateSong.cxx:108
#14 0x005a859c in UpdateWalk::UpdateRegularFile (this=0x674f88, directory=..., name=0xb4210ac8 "Bach Christmas.mp3", info=...) at ../src/db/update/Walk.cxx:195
#15 0x005a8708 in UpdateWalk::UpdateDirectoryChild (this=0x674f88, directory=..., exclude_list=..., name=0xb4210ac8 "Bach Christmas.mp3", info=...) at ../src/db/update/Walk.cxx:208
#16 0x005a9394 in UpdateWalk::UpdateDirectory (this=0x674f88, directory=..., exclude_list=..., info=...) at ../src/db/update/Walk.cxx:385
#17 0x005a87bc in UpdateWalk::UpdateDirectoryChild (this=0x674f88, directory=..., exclude_list=..., name=0xb4200644 "Programmes", info=...) at ../src/db/update/Walk.cxx:222
#18 0x005a9394 in UpdateWalk::UpdateDirectory (this=0x674f88, directory=..., exclude_list=..., info=...) at ../src/db/update/Walk.cxx:385
#19 0x005a9e48 in UpdateWalk::Walk (this=0x674f88, root=..., path=0x676484 "", discard=true) at ../src/db/update/Walk.cxx:529
#20 0x005a41a8 in UpdateService::Task (this=0x676430) at ../src/db/update/Service.cxx:122
#21 0x005a55bc in BindMethodDetail::WrapperGenerator<void (UpdateService::*)() noexcept, &UpdateService::Task>::Invoke(void*) (_instance=0x676430) at ../src/db/update/Service.cxx:49
#22 0x004e1ddc in BoundMethod<void () noexcept>::operator()() const (this=0x676458) at ../src/util/BindMethod.hxx:78
#23 0x004f2bb0 in Thread::Run (this=0x676458) at ../src/thread/Thread.cxx:63
#24 0x004f2be8 in Thread::ThreadProc (ctx=0x676458) at ../src/thread/Thread.cxx:92
#25 0xb6538b98 in ?? () from /lib/arm-linux-gnueabi/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
(gdb)

NB. Line 200 of AsyncInputStream.cxx is

cond_handler.cond.wait(lock);
MaxKellermann commented 5 days ago

This looks like MPD is using io_uring for file I/O, which is good; but there is a problem, because the read of the APE signature never finishes. From here, I cannot tell why that happens, because in the 4 years since io_uring support was added to MPD, this problem has never occurred.

If you want to debug this, the relevant functions are UringInputStream::SubmitRead() which sends read requests to io_uring and when it finishes, UringInputStream::OnRead() or UringInputStream::OnReadError() is invoked.

samer-- commented 5 days ago

Hi Max, thanks for your reply - I'll have a look into this.

MaxKellermann commented 5 days ago

Maybe you encountered a race that may have been fixed by commit b050e0132ed3a207f86545773eaecb8ff11c1b2b (though extremely unlikely that this race was reproducible). But it would be interesting to see if git master still has this problem for you.

samer-- commented 5 days ago

I'll try this when I have some time (compilation cycle very slow on Sheevaplug!). In the meantime, thanks to your pointing to io_uring, I was able to get my MPD working by disabling io_uring with -Dio_uring=disabled in the configuration phase.