GNU bug report logs - #44820
MPD fails after respawning too often

Previous Next

Package: guix;

Reported by: Simon <lists <at> netpanic.org>

Date: Mon, 23 Nov 2020 16:44:02 UTC

Severity: normal

Done: Ludovic Courtès <ludo <at> gnu.org>

Bug is archived. No further changes may be made.

To add a comment to this bug, you must first unarchive it, by sending
a message to control AT debbugs.gnu.org, with unarchive 44820 in the body.
You can then email your comments to 44820 AT debbugs.gnu.org in the normal way.

Toggle the display of automated, internal messages from the tracker.

View this report as an mbox folder, status mbox, maintainer mbox


Report forwarded to bug-guix <at> gnu.org:
bug#44820; Package guix. (Mon, 23 Nov 2020 16:44:02 GMT) Full text and rfc822 format available.

Acknowledgement sent to Simon <lists <at> netpanic.org>:
New bug report received and forwarded. Copy sent to bug-guix <at> gnu.org. (Mon, 23 Nov 2020 16:44:02 GMT) Full text and rfc822 format available.

Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Simon <lists <at> netpanic.org>
To: bug-guix <at> gnu.org
Subject: MPD fails after respawning too often
Date: Mon, 23 Nov 2020 14:24:54 +0100
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




Information forwarded to bug-guix <at> gnu.org:
bug#44820; Package guix. (Fri, 27 Nov 2020 10:32:01 GMT) Full text and rfc822 format available.

Message #8 received at 44820 <at> debbugs.gnu.org (full text, mbox):

From: Ludovic Courtès <ludo <at> gnu.org>
To: Simon <lists <at> netpanic.org>
Cc: 44820 <at> debbugs.gnu.org
Subject: Re: bug#44820: MPD fails after respawning too often
Date: Fri, 27 Nov 2020 11:31:35 +0100
Hi,

Simon <lists <at> netpanic.org> skribis:

> On a recent pull, MPD will not start any more.
>
> Herd status reports:
>
> 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.
>
>
> Reading my messages, I find:
>
> 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.)
>
>
> Unfortunately, there are no further messages as to why the service is
> disabled, or why the daemon is respawning too often.

Does /var/log/mpd/mpd.log or similar contain useful info?

Could you share your ‘mpd-configuration’?

There have been two changes recently, which fixed the mpd system test,
but perhaps they introduced other issues:

  https://git.savannah.gnu.org/cgit/guix.git/log?id=bb124f6e9c0af0a23736f233c2ea2c9c9b4a40a6

Thanks for reporting the issue,
Ludo’.




Information forwarded to bug-guix <at> gnu.org:
bug#44820; Package guix. (Fri, 27 Nov 2020 11:32:01 GMT) Full text and rfc822 format available.

Message #11 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Martin Becze <mjbecze <at> riseup.net>
To: bug-guix <at> gnu.org
Subject: Re: bug#44820: MPD fails after respawning too often
Date: Fri, 27 Nov 2020 05:31:29 -0600
I also ran into this problem. Here is the relevnat part of 
/var/run/mpd/<mpd-user>/log

> exception: Failed to create pid file "/var/run/mpd/<mpd-user>/pid": Permission denied

A quick dirty fix is just to chown the /var/run/mpd folder so that mpd 
can create its pid file.

On 11/27/20 4:31 AM, Ludovic Courtès wrote:
> Hi,
> 
> Simon <lists <at> netpanic.org> skribis:
> 
>> On a recent pull, MPD will not start any more.
>>
>> Herd status reports:
>>
>> 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.
>>
>>
>> Reading my messages, I find:
>>
>> 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.)
>>
>>
>> Unfortunately, there are no further messages as to why the service is
>> disabled, or why the daemon is respawning too often.
> 
> Does /var/log/mpd/mpd.log or similar contain useful info?
> 
> Could you share your ‘mpd-configuration’?
> 
> There have been two changes recently, which fixed the mpd system test,
> but perhaps they introduced other issues:
> 
>    https://git.savannah.gnu.org/cgit/guix.git/log?id=bb124f6e9c0af0a23736f233c2ea2c9c9b4a40a6
> 
> Thanks for reporting the issue,
> Ludo’.
> 
> 
> 




Information forwarded to bug-guix <at> gnu.org:
bug#44820; Package guix. (Fri, 27 Nov 2020 19:33:01 GMT) Full text and rfc822 format available.

Message #14 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Simon Streit <lists <at> netpanic.org>
To: bug-guix <at> gnu.org
Subject: Re: bug#44820: MPD fails after respawning too often
Date: Fri, 27 Nov 2020 20:29:19 +0100
Martin Becze writes:

> I also ran into this problem. Here is the relevnat part of
> /var/run/mpd/<mpd-user>/log
>
>> exception: Failed to create pid file "/var/run/mpd/<mpd-user>/pid": Permission denied
>
> A quick dirty fix is just to chown the /var/run/mpd folder so that mpd
> can create its pid file.

I have the the same error message in my log file too, and chowning
ownership of directories helps too.



>
> On 11/27/20 4:31 AM, Ludovic Courtès wrote:
>> Hi,
>> Simon <lists <at> netpanic.org> skribis:
>>
>>> On a recent pull, MPD will not start any more.
>>>
>>> Herd status reports:
>>>
>>> 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.
>>>
>>>
>>> Reading my messages, I find:
>>>
>>> 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.)
>>>
>>>
>>> Unfortunately, there are no further messages as to why the service is
>>> disabled, or why the daemon is respawning too often.
>> Does /var/log/mpd/mpd.log or similar contain useful info?
>> Could you share your ‘mpd-configuration’?
>> There have been two changes recently, which fixed the mpd system
>> test,
>> but perhaps they introduced other issues:
>>    https://git.savannah.gnu.org/cgit/guix.git/log?id=bb124f6e9c0af0a23736f233c2ea2c9c9b4a40a6
>> Thanks for reporting the issue,
>> Ludo’.


If I read it correctly in the changes made above, ownership of the
directory should be changed, but it is not.  I just deleted the
directory in /run/mpd and did a reboot.  The user directory is
recreated, and .mpd too, but only ownership is changed in .mpd.

Too bad that my knowledge in guile is too limited at the moment to
provide a solution.  But I'd really love too at the moment. :)

But I believe ownership of the parent directory should be changed
according to the user.

Sorry that I can't provide any better solution at the moment.


Cheers,
Simon




Information forwarded to bug-guix <at> gnu.org:
bug#44820; Package guix. (Thu, 03 Dec 2020 17:06:01 GMT) Full text and rfc822 format available.

Message #17 received at 44820 <at> debbugs.gnu.org (full text, mbox):

From: Ludovic Courtès <ludo <at> gnu.org>
To: Martin Becze <mjbecze <at> riseup.net>
Cc: 44820 <at> debbugs.gnu.org
Subject: Re: bug#44820: MPD fails after respawning too often
Date: Thu, 03 Dec 2020 18:05:26 +0100
Hi Martin,

Martin Becze <mjbecze <at> riseup.net> skribis:

> I also ran into this problem. Here is the relevnat part of
> /var/run/mpd/<mpd-user>/log
>
>> exception: Failed to create pid file "/var/run/mpd/<mpd-user>/pid": Permission denied
>
> A quick dirty fix is just to chown the /var/run/mpd folder so that mpd
> can create its pid file.

So was the ownership of /var/run/mpd/$USER wrong?

Thanks,
Ludo’.




Information forwarded to bug-guix <at> gnu.org:
bug#44820; Package guix. (Thu, 03 Dec 2020 21:35:01 GMT) Full text and rfc822 format available.

Message #20 received at 44820 <at> debbugs.gnu.org (full text, mbox):

From: Martin Becze <mjbecze <at> riseup.net>
To: Ludovic Courtès <ludo <at> gnu.org>
Cc: 44820 <at> debbugs.gnu.org
Subject: Re: bug#44820: MPD fails after respawning too often
Date: Thu, 3 Dec 2020 15:34:10 -0600
Yeah, owner gets set to root when it should be mpd-user.

On 12/3/20 11:05 AM, Ludovic Courtès wrote:
> So was the ownership of/var/run/mpd/$USER wrong?




Information forwarded to bug-guix <at> gnu.org:
bug#44820; Package guix. (Thu, 03 Dec 2020 21:40:02 GMT) Full text and rfc822 format available.

Message #23 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Simon Streit <lists <at> netpanic.org>
To: bug-guix <at> gnu.org
Subject: Re: bug#44820: MPD fails after respawning too often
Date: Thu, 03 Dec 2020 22:00:49 +0100
Ludovic Courtès writes:

> Hi Martin,
>
> Martin Becze <mjbecze <at> riseup.net> skribis:
>
>> I also ran into this problem. Here is the relevnat part of
>> /var/run/mpd/<mpd-user>/log
>>
>>> exception: Failed to create pid file "/var/run/mpd/<mpd-user>/pid": Permission denied
>>
>> A quick dirty fix is just to chown the /var/run/mpd folder so that mpd
>> can create its pid file.
>
> So was the ownership of /var/run/mpd/$USER wrong?

`/var/run/mpd' and subsequent user folders belong to root:root.  Only
`/var/run/mpd/mpd' belong to mpd:mpd.  They where recreated belonging to
root:root after deleting them.

>
> Thanks,
> Ludo’.




Reply sent to Ludovic Courtès <ludo <at> gnu.org>:
You have taken responsibility. (Mon, 07 Dec 2020 08:45:01 GMT) Full text and rfc822 format available.

Notification sent to Simon <lists <at> netpanic.org>:
bug acknowledged by developer. (Mon, 07 Dec 2020 08:45:01 GMT) Full text and rfc822 format available.

Message #28 received at 44820-done <at> debbugs.gnu.org (full text, mbox):

From: Ludovic Courtès <ludo <at> gnu.org>
To: Martin Becze <mjbecze <at> riseup.net>
Cc: 44820-done <at> debbugs.gnu.org
Subject: Re: bug#44820: MPD fails after respawning too often
Date: Mon, 07 Dec 2020 09:44:13 +0100
Hi!

I believe this is fixed by ce3b5e5a8d8566162201cb778c4586f94a626dfa.

Thanks,
Ludo’.




bug archived. Request was from Debbugs Internal Request <help-debbugs <at> gnu.org> to internal_control <at> debbugs.gnu.org. (Mon, 04 Jan 2021 12:24:05 GMT) Full text and rfc822 format available.

This bug report was last modified 3 years and 84 days ago.

Previous Next


GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.