Hello,
I’m new here. Hope this is the right way to get some hints on an issue I’m observing currently.
What am I doing:
I’m creating a Linux Firmware with Mopidy and Rygel on it for an old radio (the ones from the 1920s) using a raspberry pi zero w. The radio should be able to play internet radio and to play music from phones in the local wifi. So after some trials, I decided to use mopidy as player together with tunein for the radio and to connect it via mpris with rygel for the dlna playbacks.
What’s already working:
The basic functionality is working fine, internet radio and dlna playback. I’m now working on a safe shutdown using the persistent state functionality of mopidy.
What’s the problem:
In my environment (later some words to it), I cannot stop mopidy using SIGTERM properly. I analyzed it a bit and found that the main function of mopidy is actually left but the process seems to stay alive probably due to another thread not being stopped (just an assumption). This behaviour can be only observed when the http extension is active. So I guess this extension is not shutting down properly. I checked the “stop_remaining_actor()” function and found that this is left properly without any actor being still alive. Any idea?
To the environment:
I boot strapped a minimal raspian with just in it what is needed. Rygel and mopidy are connected via a session dbus created using systemd service files. Connman is used to create a wifi connection to my wifi router. Another network interface is configured with a network ip but it is not connected.
Would be nice to get some feedback on how to analyze further the issues.
Thx in advance,
Marko
Does a debug log help at all? Can you provide it?
I don’t really understand that log. Why is systemd timing out after only 2 seconds? Where is it hanging?
Hi,
I called systemctl stop to stop mopidy. This way, systemd sends SIGTERM and waits until this process exists. If it does not exit after a certain timeout, it sends SIGKILL to finally stop the process. The default timeout is set to 2min, I set it to 2secs for mopidy.
Marko
If you put it back to the default (90 seconds on my system), you don’t see anything more in the debug log?
Can you also provide the output of sudo mopidyctl deps.
Nope 
the last three error logs are added by me in the stop_… Function. If I got the code right, nothing happens after this function anymore despite a few returns so i assume the main function is left…
To mopidyctl: ok, i’m at work currently. I’ll captue the output this evening…
You could try running top -H -p $(pgrep mopidy) and then watch what happens when you send SIGTERM? Chances are it’ll just be one of the unnamed threads but worth a go.
Hi,
mopidyctl deps says:
Running “/usr/bin/mopidy --config /usr/share/mopidy/conf.d:/etc/mopidy/mopidy.conf deps” as user mopidy
Executable: /usr/bin/mopidy
Platform: Linux-4.14.49-v7±armv7l-with-debian-buster-sid
Python: CPython 2.7.15 from /usr/lib/python2.7
Mopidy: 2.1.0 from /usr/lib/python2.7/dist-packages
Mopidy-MPRIS: 1.4.0 from /usr/lib/python2.7/dist-packages
Mopidy-Mobile: 1.8.3 from /usr/local/lib/python2.7/dist-packages
setuptools: 39.2.0 from /usr/lib/python2.7/dist-packages
Mopidy>=0.19: 2.1.0 from /usr/lib/python2.7/dist-packages
Mopidy-TuneIn: 0.4.1 from /usr/lib/python2.7/dist-packages
GStreamer: 1.14.2.0 from /usr/lib/python2.7/dist-packages/gi
Detailed information:
Python wrapper: python-gi 3.28.3
Relevant elements:
Found:
uridecodebin
souphttpsrc
appsrc
alsasink
osssink
oss4sink
pulsesink
id3demux
id3v2mux
lamemp3enc
mpegaudioparse
mpg123audiodec
vorbisdec
vorbisenc
vorbisparse
oggdemux
oggmux
oggparse
flacdec
flacparse
shout2send
Not found:
flump3dec
mad
Marko
Hi again,
with top, one can observe that three threads remain after SIGTERM.
At runtime:
555 mopidy 20 0 143648 36512 13964 S 0.0 3.8 0:03.33 mopidy
562 mopidy 20 0 143648 36512 13964 S 0.0 3.8 0:00.00 gmain
563 mopidy 20 0 143648 36512 13964 S 0.0 3.8 0:00.01 mopidy
564 mopidy 20 0 143648 36512 13964 S 0.0 3.8 0:00.05 mopidy
565 mopidy 20 0 143648 36512 13964 S 0.0 3.8 0:00.00 mopidy
566 mopidy 20 0 143648 36512 13964 S 0.0 3.8 0:00.01 mopidy
567 mopidy 20 0 143648 36512 13964 S 0.0 3.8 0:00.00 mopidy
568 mopidy 20 0 143648 36512 13964 S 0.0 3.8 0:00.00 mopidy
569 mopidy 20 0 143648 36512 13964 S 0.0 3.8 0:00.01 mopidy
571 mopidy 20 0 143648 36512 13964 S 0.0 3.8 0:00.01 mopidy
After SIGTERM:
555 mopidy 20 0 102840 36688 13964 S 0.0 3.9 0:03.37 mopidy
562 mopidy 20 0 102840 36688 13964 S 0.0 3.9 0:00.00 gmain
572 mopidy 20 0 102840 36688 13964 S 0.0 3.9 0:00.01 mopidy
Interestingly, a thread is active that is not there during normal run (TID 572).
Marko
I’m experiencing this as well. Systemctl is only able to kill it after my 90 second (default) timeout. Killing it by hand with kill -9 of course works, but is a hassle.
Can you confirm that disabling the http frontend also fixes it?
YES! That brought it down to 9 seconds, which is workable. Thank you very much.
time systemctl stop mopidy
real 0m8.927s
user 0m0.005s
sys 0m0.005s
Can you provide the full output please, @MHoyer12345678. I want to know what Tornado version you have.
Which output do you need?
The mopidyctl deps output.
Hello,
the output I sent was the complete output I got from mopidyctl deps.
Anyway, following tornado version is installed in my system:
root@svens-radio:/home/joe# pip list | grep tornado
tornado (5.0.2)
Regards,
Marko
That’s very odd.
We don’t test with Tornado v5.0 so it’s possible there’s some problems with it. Could you try downgrading to something between v4.4 and v5?