Subject: MPD fails after respawning too often
From: Simon <[email-masked]>
To: [email-masked]
Date: Mon, 23 Nov 2020 14:24:54 +0100
List-Id: <debbugs-submit.debbugs.gnu.org>

On a recent pull, MPD will not start any more.

Herd status reports:
--8<---------------cut here---------------start------------->8---
Status of mpd:
  It is stopped.
  It is disabled.
  Provides (mpd).
  Requires (user-processes).
  Conflicts with ().
  Will be respawned.
  Last respawned on Mon Nov 23 10:22:07+0100 2020.
--8<---------------cut here---------------end--------------->8---

Reading my messages, I find:
--8<---------------cut here---------------start------------->8---
Nov 23 10:22:07 localhost shepherd[1]: Respawning mpd.
Nov 23 10:22:07 localhost shepherd[1]: Service mpd has been started.
Nov 23 10:22:07 localhost shepherd[1]: Respawning mpd.
Nov 23 10:22:07 localhost shepherd[1]: Service mpd has been started.
Nov 23 10:22:07 localhost shepherd[1]: Respawning mpd.
Nov 23 10:22:07 localhost shepherd[1]: Service mpd has been started.
Nov 23 10:22:07 localhost shepherd[1]: Respawning mpd.
Nov 23 10:22:07 localhost shepherd[1]: Service mpd has been started.
Nov 23 10:22:07 localhost shepherd[1]: Respawning mpd.
Nov 23 10:22:07 localhost shepherd[1]: Service mpd has been started.
Nov 23 10:22:07 localhost shepherd[1]: Respawning mpd.
Nov 23 10:22:07 localhost shepherd[1]: Service mpd has been started.
Nov 23 10:22:07 localhost shepherd[1]: Service mpd has been disabled.
Nov 23 10:22:07 localhost shepherd[1]:   (Respawning too fast.)
--8<---------------cut here---------------end--------------->8---

Unfortunately, there are no further messages as to why the service is
disabled, or why the daemon is respawning too often.

If I manually call the daemon with `$ ./mpd --no-daemon --stdout
--verbose' from the store, I get:
--8<---------------cut here---------------start------------->8---
config_file: loading file /home/user/.config/mpd/mpd.conf
libsamplerate: libsamplerate converter 'Fastest Sinc Interpolator'
vorbis: Xiph.Org libVorbis 1.3.6
opus: libopus 1.3.1
sndfile: libsndfile-1.0.30
hybrid_dsd: The Hybrid DSD decoder is disabled because it was not explicitly enabled
simple_db: reading DB
curl: version 7.71.0
curl: with GnuTLS/3.6.14
state_file: Loading state file /home/user/.mpd/state
exception: RTIOThread could not get realtime scheduling, continuing anyway: sched_setscheduler failed: Operation not permitted
playlist: queue song 7:"Can/CAN/08 Can Be.mp3"
decoder_thread: probing plugin ffmpeg
exception: OutputThread could not get realtime scheduling, continuing anyway: sched_setscheduler failed: Operation not permitted
ffmpeg/mp3: Format mp3 probed with size=65536 and score=51
ffmpeg/mp3: pad 576 1788
ffmpeg/mp3: Skipping 0 bytes of junk at 37617.
ffmpeg: detected input format 'mp3' (MP2/3 (MPEG audio layer 2/3))
ffmpeg/mp3: Before avformat_find_stream_info() pos: 37617 bytes read:65536 seeks:0 nb_streams:2
ffmpeg/mjpeg: marker=d8 avail_size_in_buf=34312
ffmpeg/mjpeg: marker parser used 0 bytes (0 bits)
ffmpeg/mjpeg: marker=e0 avail_size_in_buf=34310
ffmpeg/mjpeg: marker parser used 16 bytes (128 bits)
ffmpeg/mjpeg: marker=db avail_size_in_buf=34292
ffmpeg/mjpeg: index=0
ffmpeg/mjpeg: qscale[0]: 2
ffmpeg/mjpeg: marker parser used 67 bytes (536 bits)
ffmpeg/mjpeg: marker=db avail_size_in_buf=34223
ffmpeg/mjpeg: index=1
ffmpeg/mjpeg: qscale[1]: 5
ffmpeg/mjpeg: marker parser used 67 bytes (536 bits)
ffmpeg/mjpeg: marker=c0 avail_size_in_buf=34154
ffmpeg/mjpeg: Changing bps from 0 to 8
ffmpeg/mjpeg: sof0: picture: 622x622
ffmpeg/mjpeg: component 0 2:2 id: 0 quant:0
ffmpeg/mjpeg: component 1 1:1 id: 1 quant:1
ffmpeg/mjpeg: component 2 1:1 id: 2 quant:1
ffmpeg/mjpeg: pix fmt id 22111100
ffmpeg/mjpeg: Format yuvj420p chosen by get_format().
ffmpeg/mjpeg: marker parser used 17 bytes (136 bits)
ffmpeg/mjpeg: marker=c4 avail_size_in_buf=34135
ffmpeg/mjpeg: marker parser used 0 bytes (0 bits)
ffmpeg/mjpeg: marker=c4 avail_size_in_buf=34102
ffmpeg/mjpeg: marker parser used 0 bytes (0 bits)
ffmpeg/mjpeg: marker=c4 avail_size_in_buf=33919
ffmpeg/mjpeg: marker parser used 0 bytes (0 bits)
ffmpeg/mjpeg: marker=c4 avail_size_in_buf=33886
ffmpeg/mjpeg: marker parser used 0 bytes (0 bits)
ffmpeg/mjpeg: escaping removed 102 bytes
ffmpeg/mjpeg: marker=da avail_size_in_buf=33703
ffmpeg/mjpeg: marker parser used 33601 bytes (268808 bits)
ffmpeg/mjpeg: marker=d9 avail_size_in_buf=0
ffmpeg/mjpeg: decode frame unused 0 bytes
ffmpeg/mp3: demuxer injecting skip 1105 / discard 0
ffmpeg/mp3float: skip 1105 / discard 0 samples due to side data
ffmpeg/mp3float: skip 1105/1152 samples
ffmpeg/mp3: All info found
ffmpeg/mp3: stream 0: start_time: 0.0250567 duration: 22.3869
ffmpeg/mp3: stream 1: start_time: 0.0250556 duration: 22.3869
ffmpeg/mp3: format: start_time: 0.025056 duration: 22.3869 (estimate from stream) bitrate=333 kb/s
ffmpeg/mp3: After avformat_find_stream_info() pos: 90865 bytes read:98304 seeks:0 frames:51
ffmpeg: codec 'mp3'
decoder: audio_format=44100:f:2, seekable=true
ffmpeg/mp3: demuxer injecting skip 1105 / discard 0
client: [0] opened from 127.0.0.1:40210
client: [0] process command "status"
client: [0] command returned 0
client: [0] process command "plchanges "0""
client: [0] command returned 0
client: [0] process command "decoders"
client: [0] command returned 0
client: [0] process command "idle"
client: [0] command returned 1
^Cstate_file: Saving state file /home/user/.mpd/state
player: played "Can/CAN/07 Ping Pong.mp3"
fifo_output: Removing FIFO "/tmp/mpd.fifo"
--8<---------------cut here---------------end--------------->8---

Hence the daemon will run it manually from the store, but there are no
hints as to why it fails at boot time.

Any help is appreciated.

Cheers,
Simon