Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Shoutcast output randomly crashes on switching or adding tracks to the playlist #622

Open
Nocifer opened this issue Aug 7, 2019 · 13 comments

Comments

@Nocifer
Copy link

commented Aug 7, 2019

Bug report

Describe the bug

When an audio_output block of type "shout" is enabled in mpd.conf (at least I've tested the exact same music tracks with e.g. "pulse" and I've not run into any problems at all), switching tracks or loading new tracks in the playlist randomly (but consistently, i.e. it usually doesn't take more than 5-10 track changes) results in a crash.

The thing is, following the exact same behavior pattern, so far I've gotten at least three seemingly different crashes:

  1. coredump 1
  2. coredump 2
  3. coredump 3

Version

Music Player Daemon 0.21.13 (0.21.13)

Logs (note that despite their similar numbering, they do not represent coredump1, coredump2 or coredump3 respectively)

Log 1

Aug 07 15:50 : decoder_thread: probing plugin mad
Aug 07 15:50 : client: [0] command returned 0
Aug 07 15:50 : playlist: queue song 1:"XYZ.mp3"
Aug 07 15:50 : decoder: audio_format=44100:24:2, seekable=true
malloc_consolidate(): invalid chunk size

Log 2

Aug 07 15:54 : decoder_thread: probing plugin mad
Aug 07 15:54 : decoder: audio_format=44100:24:2, seekable=true
Aug 07 15:54 : client: [0] command returned 0
Aug 07 15:54 : state_file: Saving state file /home/nocifer/.config/mpd/state
Aug 07 15:54 : playlist: queue song 3:"XYZ.mp3"
Aug 07 15:54 : client: [0] closed
Aug 07 15:54 : shout_output: error setting shout metadata
malloc(): invalid size (unsorted)

Log 3

Aug 07 15:58 : decoder_thread: probing plugin mad
Aug 07 15:58 : client: [3] command returned 0
Aug 07 15:58 : playlist: queue song 1:"XYZ.mp3"
Aug 07 15:58 : decoder: audio_format=44100:24:2, seekable=true
corrupted size vs. prev_size in fastbins

@MaxKellermann

This comment has been minimized.

Copy link
Member

commented Aug 7, 2019

This crash is caused by a heap corruption which must have happened earlier; without your binaries, I can't use those core dumps, but in any case they wouldn't show where the corruption happened, but only where it was noticed.
What would show the corruption is valgrind. i.e. run valgrind --log-file=/tmp/valgrind.log mpd --no-daemon ... to start MPD instead of how you usually do it, and then paste the log file here.

@Nocifer

This comment has been minimized.

Copy link
Author

commented Aug 7, 2019

Alright, I ran MPD with valgrind but for some reason this time I got no crashes at all, even though I kept at it for at least 5 mins changing and replacing tracks back and forth. I'm honestly baffled, but I'm also running out of free time atm, so I'll try with valgrind again later and report here if and when I'm able to reproduce the crash.

@MaxKellermann

This comment has been minimized.

Copy link
Member

commented Aug 7, 2019

Sometimes, it doesn't crash, but the error is still there and logged by valgrind.

@Nocifer

This comment has been minimized.

Copy link
Author

commented Aug 7, 2019

OK, I ran it again with valgrind, and no matter what I couldn't make it crash. I did get some errors though in valgrind.log:

valgrind.log

Lines 55-548 were produced by loading some FLAC files, but the shoutcast plugin is converting them to mp3 before it transmits them to the remote server, hence the shout_open_mp3 calls (I guess). These files have never produced any crashes for me when running without valgrind, so they're probably irrelevant/harmless.

Next up we have lines 549-578, which were produced by the mp3 files that made MPD crash back when it was running on its own, without valgrind. So if there is indeed an error occurring, but which as you said does not result in a crash when running MPD through valgrind, this should be it. Either that, or the error is really not occurring at all.

@MaxKellermann

This comment has been minimized.

Copy link
Member

commented Aug 9, 2019

This looks like a double free bug, but I can't see more because your MPD and libshout binaries are stripped. I need a log with unstripped binaries (with debug symbols).

@Nocifer

This comment has been minimized.

Copy link
Author

commented Aug 13, 2019

Here it is:

Log

I've included the whole thing for completeness's sake, but the interesting part (where MPD would crash without valgrind) begins at line 736.

@MaxKellermann

This comment has been minimized.

Copy link
Member

commented Aug 13, 2019

Your bug report says you're using MPD 0.21.13, but that's wrong. I'm pretty sure you're using 0.22~git, aren't you?

@Nocifer

This comment has been minimized.

Copy link
Author

commented Aug 13, 2019

You're right, the version is 0.22~git, which I acquired by cloning this repo in order to build MPD without stripping the debug symbols, as you requested (along with libshout, but that's another story). The bug report says 0.21.13 because that's the binary release I had originally been using through my distro's package manager when I reported the issue; for instance, the previous valgrind log was made with 0.21.13.

I could always build and test again specifically with 0.21.13, but the bug (if it's indeed a bug) was also present in 0.21.12, and is seemingly also present in 0.22~git.

@MaxKellermann

This comment has been minimized.

Copy link
Member

commented Aug 13, 2019

Your log with 0.22~git is ok, I was just wondering why your log doesn't match the version you previously used.
The problem is that the log doesn't appear to make sense. Yes, there obviously is a bug, but I don't (yet) understand how this can happen and where the cause of the bug is.

@hdak1945git

This comment has been minimized.

Copy link

commented Aug 14, 2019

I'd like to add my two cents, since I too am affected by this issue, perhaps
it'll offer some clues:

  • mpd crashes randomly with the "shout" audio plugin enabled.
  • mpd versions affected: 0.21.10, 0.21.13
  • Target for the shout plugin is a icecast server (latest tested 2.4.3).
  • The shout plugin is configured to use 'lame' as the encoder.
  • libshout version (latest tested 1:2.4.3)
  • Distribution: Arch Linux

The following steps can cause mpd to crash pretty consistently; though some of
the exact steps may vary.

  1. Connect with client (tested with Cantata, and ncmpcpp).
  2. Invoke Play (if not already playing).
  3. Invoke Next Track (about three times).
  4. Invoke Stop.
  5. Invoke Play.
  6. mpd will then crash (SIGABRT, SIGSEGV) or shortly thereafter upon the next
    track change.

I've managed to rebuild my distribution binaries with debugging information,
below are some gdb back traces:

https://gist.github.com/hdak1945git/d2c4b8af04d80acb15ca3257ec805dcd

Hope this helps!

@MaxKellermann

This comment has been minimized.

Copy link
Member

commented Aug 21, 2019

@hdak1945git backtraces don't help, as I already wrote. Your instructions also didn't help, unfortunately - because I can't reproduce the problem, no matter how hard I try. Sigh.
And the valgrind log from @Nocifer still doesn't make sense. This can't possibly happen, as far as I can tell. But it happens, so obviously I must be wrong.

What I need from you:

  • build MPD with assertions enabled (Meson option -Dn_debug=false and maybe --buildtype=debug to disable compiler optimizations)
  • your mpd.conf snippet with your Shout output configuration (without the password)
  • another valgrind log and MPD verbose log in one file, e.g.: valgrind /usr/local/bin/mpd --verbose --no-daemon --stdout 2>&1|tee /tmp/log

I hope this gives me a clue where to look.

@Nocifer

This comment has been minimized.

Copy link
Author

commented Aug 21, 2019

Alright, here's the new log you requested:

combined.log

And here's my shout output block:

audio_output {
	type		"shout"
	encoder		"lame"
	name		"Home Stream"
	host		"nocifer.com"
	port		"8093"
	mount		"/music320"
	password	---
	bitrate		"320"
	format		"44100:16:2"
	protocol	"icecast2"
}

I'm sure you can read that log better than I can, but here's what I did to produce the error:

  • I added some FLAC files to the playlist and started playback.
  • I replaced the playlist with an MP3 file. At this point that bunch of "Invalid read of size X" popped up, but as already mentioned these are normally harmless (i.e. they don't result in a crash when MPD is run without valgrind).
  • I stopped playback. At this point the "Invalid free() ..." error popped up (line 1224 in the log), which would normally result in a crash.
@hdak1945git

This comment has been minimized.

Copy link

commented Aug 22, 2019

Running mpd through valgrind produced some strange behavior: audio kept playing, albeit with
massive skipping (on the PulseAudio connection), and mpd stayed connected to the icecast
server despite valgrind spamming error messages.

valgrind log: https://gist.github.com/hdak1945git/c85dd7fafae81198ffa12e87a8c424f2

mpd configuration snippet:

audio_output {
  type        "shout"
  name        "3-icy-music"
  host        "127.0.0.1"
  port        "8000"
  protocol    "icecast2"
  mount       "/music"
  user        ---
  password    ---
  description "Alternative source of audio for mpd"
  url         ---
  public      "no"
  encoder     "lame"
  bitrate     "320"
  format      "48000:16:2"
}

I am using the Arch Build System (abs) to build my version of mpd (0.21.13) -- I wanted to keep it
similar as possible to their public release since this problem also occurs there. Unfortunately I couldn't
enable -Dn_debug=false, meson simply states WARNING: Unknown options: "n_debug", though I've already
had --buildtype=debug set.

If you need any more information please let me know.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
3 participants
You can’t perform that action at this time.