search

MusicPlayerDaemon / MPD

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

Assertion error in `DecoderBridge::Read` #935

Closed naglis closed 4 years ago

naglis commented 4 years ago

Bug report

Describe the bug

This assertion fails when playing an MP3 file from a ZIP archive from a mounted USB stick (using udisks neighbor).

This happens on a Raspberry Pi (armv6h). Not sure if that is significant, but I was unable to reproduce it on x86_64 with the same files/MPD configuration.

I couldn't extract the backtrace using gdb after the assertion failure:

#0  0x761d8290 in raise () from /usr/lib/libc.so.6
#1  0x761c1784 in abort () from /usr/lib/libc.so.6
#2  0x00000000 in ?? ()

I've no experience with gdb so I've replaced the assertion with a manual breakpoint if the assertion condition is false (thus there is line number discrepancy in Bridge.cxx in the backtrace) to get the backtrace.

Please let me know if there is more information I could provide in order to help debug it.

Expected Behavior

MPD does not crash.

Actual Behavior

MPD crashes.

Version

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

Storage plugins:
 local udisks

Neighbor plugins:
 udisks

Decoders plugins:
 [mad] mp3 mp2
 [mpg123] mp3
 [vorbis] ogg oga
 [oggflac] ogg oga
 [flac] flac
 [opus] opus ogg oga
 [faad] aac
 [pcm]

Filters:
 libsamplerate

Tag plugins:

Output plugins:
 null alsa

Archive plugins:
 [bz2] bz2
 [zzip] zip

Input plugins:
 file archive alsa

Playlist plugins:
 extm3u m3u pls flac

Protocols:
 file:// alsa://

Other features:
 dbus udisks epoll icu systemd un

Log

Aug 04 17:22 : client: [18] opened from local
Aug 04 17:22 : client: [18] process command "play "52""
Aug 04 17:22 : playlist: play 52:"ausis:27aa486/Audiobooks/Ted Koppel - Lights Out.zip/Lights Out/Lights Out - Chapter 53.mp3"
Aug 04 17:22 : client: [18] command returned 0
Aug 04 17:22 : playlist: queue song 53:"ausis:27aa486/Audiobooks/Ted Koppel - Lights Out.zip/Lights Out/Lights Out - Chapter 54.mp3"
Aug 04 17:22 : client: [18] process command list
Aug 04 17:22 : client: process command "status"
Aug 04 17:22 : client: command returned 0
Aug 04 17:22 : client: process command "currentsong"
Aug 04 17:22 : client: command returned 0
Aug 04 17:22 : client: [18] process command list returned 0
Aug 04 17:22 : decoder_thread: probing plugin mad
Aug 04 17:22 : mad: detected LAME version 3.99 ("LAME3.99r")
Aug 04 17:22 : mad: LAME peak found: 0.000000
Aug 04 17:22 : mad: encoder delay is 576, encoder padding is 576
Aug 04 17:22 : decoder: audio_format=44100:24:1, seekable=true
Aug 04 17:22 : exception: OutputThread could not get realtime scheduling, continuing anyway: sched_setscheduler failed: Operation not permitted
Aug 04 17:22 : client: [18] closed
Aug 04 17:22 : alsa_output: opened default type=PLUG
Aug 04 17:22 : alsa_output: buffer: size=512..65536 time=11609..1486078
Aug 04 17:22 : alsa_output: period: size=512..65536 time=11609..1486078
Aug 04 17:22 : alsa_output: default period_time = buffer_time/4 = 500000/4 = 125000
Aug 04 17:22 : alsa_output: format=S24_LE (Signed 24 bit Little Endian)
Aug 04 17:22 : alsa_output: buffer_size=22050 period_size=5512
Aug 04 17:22 : output: opened "ALSA output" (alsa) audio_format=44100:24:1
Aug 04 17:22 : client: [19] opened from local
Aug 04 17:22 : client: [19] process command "seekcur "5""
Aug 04 17:22 : playlist: queue song 53:"ausis:27aa486/Audiobooks/Ted Koppel - Lights Out.zip/Lights Out/Lights Out - Chapter 54.mp3"
Aug 04 17:22 : client: [19] command returned 0
Aug 04 17:22 : client: [19] process command list
Aug 04 17:22 : client: process command "status"
Aug 04 17:22 : client: command returned 0
Aug 04 17:22 : client: process command "currentsong"
Aug 04 17:22 : client: command returned 0
Aug 04 17:22 : client: [19] process command list returned 0
Aug 04 17:22 : client: [19] closed
Aug 04 17:23 : client: [20] opened from local
Aug 04 17:23 : client: [20] process command list
Aug 04 17:23 : client: process command "status"
Aug 04 17:23 : client: command returned 0
Aug 04 17:23 : client: process command "currentsong"
Aug 04 17:23 : client: command returned 0
Aug 04 17:23 : client: [20] process command list returned 0
Aug 04 17:23 : client: [20] closed

Backtrace

bt full ``` #0 0x7630d05c in raise () from /usr/lib/libpthread.so.0 No symbol table info available. #1 0x0042de84 in DecoderBridge::Read (this=0x728fdc70, is=..., buffer=0x728f16a8, length=40952) at ../../src/decoder/Bridge.cxx:415 lock = {_M_device = @0x5e6288} nbytes = 0 __PRETTY_FUNCTION__ = "virtual size_t DecoderBridge::Read(InputStream&, void*, size_t)" #2 0x0050dddc in decoder_read (client=0x728fdc70, is=..., buffer=0x728f16a8, length=40952) at ../../src/decoder/DecoderAPI.cxx:35 __PRETTY_FUNCTION__ = "size_t decoder_read(DecoderClient*, InputStream&, void*, size_t)" #3 0x00508ad0 in MadDecoder::FillBuffer (this=0x728ebe18) at ../../src/decoder/plugins/MadDecoderPlugin.cxx:263 rest_size = 8 max_read_size = 40952 dest = 0x728f16a8 "\231Y\246=\003QP\234\251\344\363\r8R\260\035E\234M\204\003\343*\272\326wK\252\344\264\357\372B\023\200\202\323\370Q\031U\b\274.\002b\212\064\200Q\373\270\360\362\004\233\253\032\\dx\340\370u\310gI\224\236\224\337\370\330\321\203q\221\352\264\177\275\247\365xJ\030\031\025(\004\231Q\265\215\061\201\v\031\332Q\342\237u*\224\320\003\216\247v\232\366*G\232weP\001" nbytes = 1921957400 #4 0x0050795c in MadDecoder::DecodeNextFrame (this=0x728ebe18) at ../../src/decoder/plugins/MadDecoderPlugin.cxx:444 No locals. #5 0x005099c8 in MadDecoder::LoadNextFrame (this=0x728ebe18) at ../../src/decoder/plugins/MadDecoderPlugin.cxx:982 ret = MadDecoderAction::CONT skip = true #6 0x00509a7c in MadDecoder::Read (this=0x728ebe18) at ../../src/decoder/plugins/MadDecoderPlugin.cxx:997 No locals. #7 0x00509ca8 in MadDecoder::RunDecoder (this=0x728ebe18) at ../../src/decoder/plugins/MadDecoderPlugin.cxx:1024 __PRETTY_FUNCTION__ = "void MadDecoder::RunDecoder()" tag = {duration = { >> = {__r = -1}, }, has_playlist = false, num_items = 0, items = 0x0} #8 0x005086b0 in mad_decode (client=..., input_stream=...) at ../../src/decoder/plugins/MadDecoderPlugin.cxx:1031 data = #9 0x004276c0 in DecoderPlugin::StreamDecode (this=0x5ca02c , client=..., is=...) at ../../src/decoder/DecoderPlugin.hxx:127 No locals. #10 0x00424df4 in decoder_stream_decode (plugin=..., bridge=..., input_stream=...) at ../../src/decoder/Thread.cxx:124 unlock = {mutex = @0x5e6288} __PRETTY_FUNCTION__ = "bool decoder_stream_decode(const DecoderPlugin&, DecoderBridge&, InputStream&)" #11 0x00425bf4 in TryDecoderFile (bridge=..., path_fs=..., suffix=0x620133 "mp3", input_stream=..., plugin=...) at ../../src/decoder/Thread.cxx:328 protect = {_M_device = @0x5e6288} dc = @0x730fec50: { = {_vptr.InputStreamHandler = 0x5c9668 }, thread = {f = {instance_ = 0x730fec50, function = 0x42bf04 ::Invoke(void*)>}, handle = 1922032576, inside_handle = 1922032576}, mutex = @0x5e6288, cond = { = {cond = {__data = {{__wseq = 171, __wseq32 = {__low = 171, __high = 0}}, { __g1_start = 169, __g1_start32 = {__low = 169, __high = 0}}, __g_refs = {0, 0}, __g_size = {0, 0}, __g1_orig_size = 4, __wrefs = 0, __g_signals = {0, 0}}, __size = "\253\000\000\000\000\000\000\000\251", '\000' , "\004", '\000' , __align = 171}}, }, client_cond = @0x5e62a0, state = DecoderState::DECODE, command = DecoderCommand::NONE, error = {_M_exception_object = 0x0}, quit = false, client_is_waiting = false, seek_error = false, seekable = true, initial_seek_essential = true, seek_time = { >> = {__r = 5000}, }, configured_audio_format = { sample_rate = 0, format = SampleFormat::UNDEFINED, channels = 0 '\000'}, in_audio_format = {sample_rate = 44100, format = SampleFormat::S24_P32, channels = 1 '\001'}, out_audio_format = {sample_rate = 44100, format = SampleFormat::S24_P32, channels = 1 '\001'}, song = std::unique_ptr = {get() = 0x620018}, start_time = { >> = {__r = 0}, }, end_time = { >> = { __r = 0}, }, total_time = { >> = {__r = 427284}, }, buffer = 0x730fec24, pipe = std::shared_ptr (use count 2, weak count 0) = {get() = 0x61ffe4}, replay_gain_config = {static DEFAULT_LIMIT = true, preamp = 1, missing_preamp = 1, limit = true}, replay_gain_mode = ReplayGainMode::OFF, replay_gain_db = 0, replay_gain_prev_db = 0, mix_ramp = {start = "", end = ""}, previous_mix_ramp = {start = "", end = ""}} --Type for more, q to quit, c to continue without paging--c #12 0x00425f08 in ::operator()(const DecoderPlugin &) const (__closure=0x728fdb88, plugin=...) at ../../src/decoder/Thread.cxx:404 is = @0x7310eef0: {_vptr.InputStream = 0x5cbda8 , uri = "Lights Out/Lights Out - Chapter 53.mp3", mutex = @0x5e6288, handler = 0x0, ready = true, seekable = true, static UNKNOWN_SIZE = 18446744073709551615, size = 3447916, offset = 8291192919049935980, mime = ""} suffix = 0x620133 "mp3" path_fs = {> = {static SENTINEL = , value = 0x73102700 "/run/media/mpd/ADATA UFD/Audiobooks/Ted Koppel - Lights Out.zip/Lights Out/Lights Out - Chapter 53.mp3"}, } bridge = @0x728fdc70: { = {_vptr.DecoderClient = 0x5c9678 }, dc = @0x730fec50, convert = 0x0, timestamp = {__r = 400.28489795911366}, absolute_frame = 17652564, initial_seek_pending = false, initial_seek_essential = true, initial_seek_running = false, seeking = false, song_tag = std::unique_ptr = {get() = 0x0}, stream_tag = std::unique_ptr = {get() = 0x73102770}, decoder_tag = std::unique_ptr = {get() = 0x0}, current_chunk = std::unique_ptr = {get() = 0x71f0e000}, replay_gain_info = {track = {gain = 1.14025255e+31, peak = 6.5944265e-39}, album = {gain = 1.14209253e+31, peak = 5.69898753e+30}}, replay_gain_serial = 0, error = {_M_exception_object = 0x0}} #13 0x00426da4 in decoder_plugins_try >() (f=...) at ../../src/decoder/DecoderList.hxx:72 i = 0 #14 0x0042606c in decoder_run_file (bridge=..., uri_utf8=0x6200d0 "/run/media/mpd/ADATA UFD/Audiobooks/Ted Koppel - Lights Out.zip/Lights Out/Lights Out - Chapter 53.mp3", path_fs=...) at ../../src/decoder/Thread.cxx:402 suffix = 0x620133 "mp3" input_stream = std::unique_ptr = {get() = 0x7310eef0} __PRETTY_FUNCTION__ = "bool decoder_run_file(DecoderBridge&, const char*, Path)" is = @0x7310eef0: {_vptr.InputStream = 0x5cbda8 , uri = "Lights Out/Lights Out - Chapter 53.mp3", mutex = @0x5e6288, handler = 0x0, ready = true, seekable = true, static UNKNOWN_SIZE = 18446744073709551615, size = 3447916, offset = 8291192919049935980, mime = ""} #15 0x004261cc in DecoderUnlockedRunUri (bridge=..., real_uri=0x6200d0 "/run/media/mpd/ADATA UFD/Audiobooks/Ted Koppel - Lights Out.zip/Lights Out/Lights Out - Chapter 53.mp3", path_fs=...) at ../../src/decoder/Thread.cxx:422 No locals. #16 0x00426524 in decoder_run_song (dc=..., song=..., uri=0x6200d0 "/run/media/mpd/ADATA UFD/Audiobooks/Ted Koppel - Lights Out.zip/Lights Out/Lights Out - Chapter 53.mp3", path_fs=...) at ../../src/decoder/Thread.cxx:485 unlock = {mutex = @0x5e6288} at_scope_exit_479 = {<> = {__bridge = @0x728fdc70}, enabled = true} bridge = { = {_vptr.DecoderClient = 0x5c9678 }, dc = @0x730fec50, convert = 0x0, timestamp = {__r = 400.28489795911366}, absolute_frame = 17652564, initial_seek_pending = false, initial_seek_essential = true, initial_seek_running = false, seeking = false, song_tag = std::unique_ptr = {get() = 0x0}, stream_tag = std::unique_ptr = {get() = 0x73102770}, decoder_tag = std::unique_ptr = {get() = 0x0}, current_chunk = std::unique_ptr = {get() = 0x71f0e000}, replay_gain_info = {track = {gain = 1.14025255e+31, peak = 6.5944265e-39}, album = {gain = 1.14209253e+31, peak = 5.69898753e+30}}, replay_gain_serial = 0, error = {_M_exception_object = 0x0}} success = false #17 0x00426810 in decoder_run (dc=...) at ../../src/decoder/Thread.cxx:528 song = @0x620018: {uri = "ausis:27aa486/Audiobooks/Ted Koppel - Lights Out.zip/Lights Out/Lights Out - Chapter 53.mp3", real_uri = "/run/media/mpd/ADATA UFD/Audiobooks/Ted Koppel - Lights Out.zip/Lights Out/Lights Out - Chapter 53.mp3", tag = {duration = { >> = {__r = 427284}, }, has_playlist = false, num_items = 0, items = 0x0}, mtime = {__d = {__r = -9223372036854775808}}, start_time = { >> = {__r = 0}, }, end_time = { >> = {__r = 0}, }} uri_utf8 = 0x6200d0 "/run/media/mpd/ADATA UFD/Audiobooks/Ted Koppel - Lights Out.zip/Lights Out/Lights Out - Chapter 53.mp3" path_fs = {> = {static SENTINEL = , value = 0x73102700 "/run/media/mpd/ADATA UFD/Audiobooks/Ted Koppel - Lights Out.zip/Lights Out/Lights Out - Chapter 53.mp3"}, } path_buffer = {value = "/run/media/mpd/ADATA UFD/Audiobooks/Ted Koppel - Lights Out.zip/Lights Out/Lights Out - Chapter 53.mp3"} __PRETTY_FUNCTION__ = "void decoder_run(DecoderControl&)" #18 0x004269c4 in DecoderControl::RunThread (this=0x730fec50) at ../../src/decoder/Thread.cxx:553 protect = {_M_device = @0x5e6288} __PRETTY_FUNCTION__ = "void DecoderControl::RunThread()" #19 0x0042bf24 in BindMethodDetail::BindMethodWrapperGenerator2::Invoke (_instance=0x730fec50) at ../../src/util/BindMethod.hxx:147 t = @0x730fec50: { = {_vptr.InputStreamHandler = 0x5c9668 }, thread = {f = {instance_ = 0x730fec50, function = 0x42bf04 ::Invoke(void*)>}, handle = 1922032576, inside_handle = 1922032576}, mutex = @0x5e6288, cond = { = {cond = {__data = {{__wseq = 171, __wseq32 = {__low = 171, __high = 0}}, {__g1_start = 169, __g1_start32 = {__low = 169, __high = 0}}, __g_refs = {0, 0}, __g_size = {0, 0}, __g1_orig_size = 4, __wrefs = 0, __g_signals = {0, 0}}, __size = "\253\000\000\000\000\000\000\000\251", '\000' , "\004", '\000' , __align = 171}}, }, client_cond = @0x5e62a0, state = DecoderState::DECODE, command = DecoderCommand::NONE, error = {_M_exception_object = 0x0}, quit = false, client_is_waiting = false, seek_error = false, seekable = true, initial_seek_essential = true, seek_time = { >> = {__r = 5000}, }, configured_audio_format = {sample_rate = 0, format = SampleFormat::UNDEFINED, channels = 0 '\000'}, in_audio_format = {sample_rate = 44100, format = SampleFormat::S24_P32, channels = 1 '\001'}, out_audio_format = {sample_rate = 44100, format = SampleFormat::S24_P32, channels = 1 '\001'}, song = std::unique_ptr = {get() = 0x620018}, start_time = { >> = {__r = 0}, }, end_time = { >> = {__r = 0}, }, total_time = { >> = {__r = 427284}, }, buffer = 0x730fec24, pipe = std::shared_ptr (use count 2, weak count 0) = {get() = 0x61ffe4}, replay_gain_config = {static DEFAULT_LIMIT = true, preamp = 1, missing_preamp = 1, limit = true}, replay_gain_mode = ReplayGainMode::OFF, replay_gain_db = 0, replay_gain_prev_db = 0, mix_ramp = {start = "", end = ""}, previous_mix_ramp = {start = "", end = ""}} #20 0x00494e94 in BoundMethod::operator()() const (this=0x730fec54) at ../../src/util/BindMethod.hxx:77 No locals. #21 0x004a2310 in Thread::Run (this=0x730fec54) at ../../src/thread/Thread.cxx:63 No locals. #22 0x004a22e4 in Thread::ThreadProc (ctx=0x730fec54) at ../../src/thread/Thread.cxx:92 thread = @0x730fec54: {f = {instance_ = 0x730fec50, function = 0x42bf04 ::Invoke(void*)>}, handle = 1922032576, inside_handle = 1922032576} #23 0x762ff2fc in start_thread () from /usr/lib/libpthread.so.0 No symbol table info available. #24 0x76284d58 in ?? () from /usr/lib/libc.so.6 No symbol table info available. Backtrace stopped: previous frame identical to this frame (corrupt stack?) ``` 
#0  0x7630d05c in raise () from /usr/lib/libpthread.so.0
#1  0x0042de84 in DecoderBridge::Read (this=0x728fdc70, is=..., buffer=0x728f16a8, length=40952) at ../../src/decoder/Bridge.cxx:415
#2  0x0050dddc in decoder_read (client=0x728fdc70, is=..., buffer=0x728f16a8, length=40952) at ../../src/decoder/DecoderAPI.cxx:35
#3  0x00508ad0 in MadDecoder::FillBuffer (this=0x728ebe18) at ../../src/decoder/plugins/MadDecoderPlugin.cxx:263
#4  0x0050795c in MadDecoder::DecodeNextFrame (this=0x728ebe18) at ../../src/decoder/plugins/MadDecoderPlugin.cxx:444
#5  0x005099c8 in MadDecoder::LoadNextFrame (this=0x728ebe18) at ../../src/decoder/plugins/MadDecoderPlugin.cxx:982
#6  0x00509a7c in MadDecoder::Read (this=0x728ebe18) at ../../src/decoder/plugins/MadDecoderPlugin.cxx:997
#7  0x00509ca8 in MadDecoder::RunDecoder (this=0x728ebe18) at ../../src/decoder/plugins/MadDecoderPlugin.cxx:1024
#8  0x005086b0 in mad_decode (client=..., input_stream=...) at ../../src/decoder/plugins/MadDecoderPlugin.cxx:1031
#9  0x004276c0 in DecoderPlugin::StreamDecode (this=0x5ca02c <mad_decoder_plugin>, client=..., is=...) at ../../src/decoder/DecoderPlugin.hxx:127
#10 0x00424df4 in decoder_stream_decode (plugin=..., bridge=..., input_stream=...) at ../../src/decoder/Thread.cxx:124
#11 0x00425bf4 in TryDecoderFile (bridge=..., path_fs=..., suffix=0x620133 "mp3", input_stream=..., plugin=...) at ../../src/decoder/Thread.cxx:328
#12 0x00425f08 in <lambda(const DecoderPlugin&)>::operator()(const DecoderPlugin &) const (__closure=0x728fdb88, plugin=...) at ../../src/decoder/Thread.cxx:404
#13 0x00426da4 in decoder_plugins_try<decoder_run_file(DecoderBridge&, char const*, Path)::<lambda(const DecoderPlugin&)> >(<lambda(const DecoderPlugin&)>) (f=...)
    at ../../src/decoder/DecoderList.hxx:72
#14 0x0042606c in decoder_run_file (bridge=..., uri_utf8=0x6200d0 "/run/media/mpd/ADATA UFD/Audiobooks/Ted Koppel - Lights Out.zip/Lights Out/Lights Out - Chapter 53.mp3", path_fs=...)
    at ../../src/decoder/Thread.cxx:402
#15 0x004261cc in DecoderUnlockedRunUri (bridge=..., real_uri=0x6200d0 "/run/media/mpd/ADATA UFD/Audiobooks/Ted Koppel - Lights Out.zip/Lights Out/Lights Out - Chapter 53.mp3", path_fs=...)
    at ../../src/decoder/Thread.cxx:422
#16 0x00426524 in decoder_run_song (dc=..., song=..., uri=0x6200d0 "/run/media/mpd/ADATA UFD/Audiobooks/Ted Koppel - Lights Out.zip/Lights Out/Lights Out - Chapter 53.mp3", path_fs=...)
    at ../../src/decoder/Thread.cxx:485
#17 0x00426810 in decoder_run (dc=...) at ../../src/decoder/Thread.cxx:528
#18 0x004269c4 in DecoderControl::RunThread (this=0x730fec50) at ../../src/decoder/Thread.cxx:553
#19 0x0042bf24 in BindMethodDetail::BindMethodWrapperGenerator2<DecoderControl, void (DecoderControl::*)(), &DecoderControl::RunThread, void>::Invoke (_instance=0x730fec50)
    at ../../src/util/BindMethod.hxx:147
#20 0x00494e94 in BoundMethod<void ()>::operator()() const (this=0x730fec54) at ../../src/util/BindMethod.hxx:77
#21 0x004a2310 in Thread::Run (this=0x730fec54) at ../../src/thread/Thread.cxx:63
#22 0x004a22e4 in Thread::ThreadProc (ctx=0x730fec54) at ../../src/thread/Thread.cxx:92
#23 0x762ff2fc in start_thread () from /usr/lib/libpthread.so.0
#24 0x76284d58 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
MaxKellermann commented 4 years ago

This sounds like zziplib returns bogus data, maybe because your ZIP file is corrupt or maybe because there's a bug in zziplib. I'll add a runtime check for this condition, so MPD errors out, but doesn't crash.