Mopidy crashes PI after raspbian upgrade

General
1

Hello

My PI 4 has been working great for months on mopidy … until I had to update the PI OS to install snapcast client & server.
The new PI OS works fine until I start mopidy. After a few seconds, the PI mouse / keyboard stops moving and the monitor desktop freezes and the ssh stops. Turning off the PI is the only way to restart it. I have since rebuilt the OS twice from scratch, but get the result .
Is anyone else seeing this ?

PRETTY_NAME=“Raspbian GNU/Linux 10 (buster)”
NAME=“Raspbian GNU/Linux”
VERSION_ID=“10”
VERSION=“10 (buster)”
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL=“http://www.raspbian.org/”
SUPPORT_URL=“http://www.raspbian.org/RaspbianForums”
BUG_REPORT_URL=“http://www.raspbian.org/RaspbianBugs”

mopidy 3.0.2-1

2

A little precision. The PI crashes when the first track is played over http.

3

If you can show this happens with a regular local-only audio output setup then I can help look into that. If this is only a problem when using Mopidy with snapcast then I’ll have to leave that to someone else.

4

Below are pi logs that I was able to extract but I cannot see what they reveal.
I have rolled back to a PI OS backup I made 6 months and all is working fine again.
If no one else has the issue, I’ll put it down to bad luck.
Thank you for all that you are doing for mopidy. Mopidy is a real bringer of joy during these lockdown weeks.

Syslog

Nov 16 21:37:33 pimusic kernel: [ 1878.116799] v3d fec00000.v3d: MMU error from client L2T (0) at 0x2601000, pte invalid

Nov 16 21:39:58 pimusic systemd[1]: Starting Mopidy music server…

Nov 16 21:39:58 pimusic systemd[1]: Started Mopidy music server.

Nov 16 21:40:01 pimusic mopidy[2322]: INFO [MainThread] mopidy.main Enabled extensions: stream, mobile, alsamixer, m3u, file, softwaremixer, scrobbler, http, local, mpd, iris

Nov 16 21:40:01 pimusic mopidy[2322]: INFO [MainThread] mopidy.main Disabled extensions: spotify

Nov 16 21:40:02 pimusic mopidy[2322]: INFO [MainThread] mopidy.commands Starting Mopidy mixer: SoftwareMixer

Nov 16 21:40:02 pimusic mopidy[2322]: INFO [MainThread] mopidy.commands Starting Mopidy audio

Nov 16 21:40:02 pimusic mopidy[2322]: INFO [MainThread] mopidy.commands Starting Mopidy backends: FileBackend, M3UBackend, StreamBackend, LocalBackend

Nov 16 21:40:02 pimusic mopidy[2322]: INFO [MainThread] mopidy.commands Starting Mopidy core

Nov 16 21:40:02 pimusic mopidy[2322]: INFO [Core-7] mopidy.core.actor Loading state from /var/lib/mopidy/core/state.json.gz

Nov 16 21:40:02 pimusic mopidy[2322]: INFO [Audio-2] mopidy.audio.actor Audio output set to "tee name=t ! queue ! audioresample ! autoaudiosink t. ! queue ! lamemp3enc ! shout2send async=false mount=mopidy ip=192.168.0.105 port=8000 $

Nov 16 21:40:02 pimusic mopidy[2322]: INFO [Core-7] mopidy.internal.storage File does not exist: /var/lib/mopidy/core/state.json.gz

Nov 16 21:40:02 pimusic mopidy[2322]: INFO [Core-7] mopidy.core.actor Failed to delete /var/lib/mopidy/core/state.json.gz

Nov 16 21:40:02 pimusic mopidy[2322]: INFO [MainThread] mopidy.commands Starting Mopidy frontends: HttpFrontend, MpdFrontend, ScrobblerFrontend, IrisFrontend

Nov 16 21:40:02 pimusic mopidy[2322]: INFO [HttpFrontend-9] mopidy.http.actor HTTP server running at [::ffff:192.168.0.105]:6680

Nov 16 21:40:02 pimusic mopidy[2322]: ERROR [MainThread] mopidy.commands Frontend (MpdFrontend) initialization error: MPD server startup failed: [Errno 98] Address already in use

Nov 16 21:40:02 pimusic mopidy[2322]: INFO [IrisFrontend-11] mopidy_iris.core Starting Iris 3.52.4

Nov 16 21:40:02 pimusic mopidy[2322]: INFO [MainThread] mopidy.commands Starting GLib mainloop

Nov 16 21:40:02 pimusic mopidy[2322]: ERROR [ScrobblerFrontend-10] mopidy_scrobbler.frontend Error during Last.fm setup: Authentication Failed - You do not have permissions to access the service

^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^$

Nov 16 21:40:32 pimusic fake-hwclock[113]: Mon 16 Nov 20:17:01 UTC 2020

Nov 16 21:40:32 pimusic systemd-fsck[131]: e2fsck 1.44.5 (15-Dec-2018)

Nov 16 21:40:33 pimusic systemd-fsck[131]: root: clean, 214717/1785856 files, 3022447/7138432 blocks

Kern.log

Nov 16 20:41:49 pimusic kernel: [ 27.158710] fuse: init (API version 7.31)

Nov 16 21:37:33 pimusic kernel: [ 1878.116799] v3d fec00000.v3d: MMU error from client L2T (0) at 0x2601000, pte invalid

^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^$

Nov 16 21:40:33 pimusic kernel: [ 0.000000] Linux version 5.4.72-v7l+ (dom@buildbot) (gcc version 9.3.0 (Ubuntu 9.3.0-17ubuntu1~20.04)) #1356 SMP Thu Oct 22 13:57:51 BST 2020

Nov 16 21:40:33 pimusic kernel: [ 0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d

Nov 16 21:40:33 pimusic kernel: [ 0.000000] CPU: div instructions available: patching division code

Messages

Nov 16 21:34:45 pimusic vncserver-x11[647,root]: Connections: rejecting blacklisted connection: 165.22.159.240

^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^$

Nov 16 21:40:33 pimusic kernel: [ 0.000000] Linux version 5.4.72-v7l+ (dom@buildbot) (gcc version 9.3.0 (Ubuntu 9.3.0-17ubuntu1~20.04)) #1356 SMP Thu Oct 22 13:57:51 BST 2020

Mopidy start after PI restart

  • mopidy.service - Mopidy music server
    Loaded: loaded (/lib/systemd/system/mopidy.service; disabled; vendor preset: enabled)
    Active: active (running) since Mon 2020-11-16 22:27:07 CET; 54s ago
    Process: 3272 ExecStartPre=/bin/mkdir -p /var/cache/mopidy (code=exited, status=0/SUCCESS)
    Process: 3273 ExecStartPre=/bin/chown mopidy:audio /var/cache/mopidy (code=exited, status=0/SUCCESS)
    Main PID: 3274 (mopidy)
    Tasks: 12 (limit: 4915)
    CGroup: /system.slice/mopidy.service
    `-3274 /usr/bin/python3 /usr/bin/mopidy --config /usr/share/mopidy/conf.d:/etc/mopidy/mopidy.conf

Nov 16 22:27:11 pimusic mopidy[3274]: INFO [MainThread] mopidy.commands Starting Mopidy core
Nov 16 22:27:11 pimusic mopidy[3274]: INFO [Core-7] mopidy.core.actor Loading state from /var/lib/mopidy/core/state.json.gz
Nov 16 22:27:11 pimusic mopidy[3274]: INFO [Core-7] mopidy.internal.storage File does not exist: /var/lib/mopidy/core/state.json.gz
Nov 16 22:27:11 pimusic mopidy[3274]: INFO [Core-7] mopidy.core.actor Failed to delete /var/lib/mopidy/core/state.json.gz
Nov 16 22:27:11 pimusic mopidy[3274]: INFO [MainThread] mopidy.commands Starting Mopidy frontends: HttpFrontend, MpdFrontend, ScrobblerFrontend, IrisFrontend
Nov 16 22:27:11 pimusic mopidy[3274]: INFO [HttpFrontend-9] mopidy.http.actor HTTP server running at [::ffff:192.168.0.105]:6680
Nov 16 22:27:11 pimusic mopidy[3274]: ERROR [MainThread] mopidy.commands Frontend (MpdFrontend) initialization error: MPD server startup failed: [Errno 98] Address already in use
Nov 16 22:27:11 pimusic mopidy[3274]: INFO [IrisFrontend-11] mopidy_iris.core Starting Iris 3.52.4
Nov 16 22:27:11 pimusic mopidy[3274]: INFO [MainThread] mopidy.commands Starting GLib mainloop
Nov 16 22:27:11 pimusic mopidy[3274]: ERROR [ScrobblerFrontend-10] mopidy_scrobbler.frontend Error during Last.fm setup: Authentication Failed - You do not have permissions to access the service

Mopidy status after a searchwith Iris test function on

  • mopidy.service - Mopidy music server
    Loaded: loaded (/lib/systemd/system/mopidy.service; disabled; vendor preset: enabled)
    Active: active (running) since Mon 2020-11-16 22:27:07 CET; 8min ago
    Process: 3272 ExecStartPre=/bin/mkdir -p /var/cache/mopidy (code=exited, status=0/SUCCESS)
    Process: 3273 ExecStartPre=/bin/chown mopidy:audio /var/cache/mopidy (code=exited, status=0/SUCCESS)
    Main PID: 3274 (mopidy)
    Tasks: 36 (limit: 4915)
    CGroup: /system.slice/mopidy.service
    `-3274 /usr/bin/python3 /usr/bin/mopidy --config /usr/share/mopidy/conf.d:/etc/mopidy/mopidy.conf

Nov 16 22:27:11 pimusic mopidy[3274]: INFO [MainThread] mopidy.commands Starting GLib mainloop
Nov 16 22:27:11 pimusic mopidy[3274]: ERROR [ScrobblerFrontend-10] mopidy_scrobbler.frontend Error during Last.fm setup: Authentication Failed - You do not have permissions to access the service
Nov 16 22:29:34 pimusic mopidy[3274]: INFO [HttpServer] mopidy_iris.system Running system action ‘test’
Nov 16 22:29:34 pimusic sudo[3384]: mopidy : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/local/lib/python3.7/dist-packages/mopidy_iris/system.sh check
Nov 16 22:29:34 pimusic sudo[3384]: pam_unix(sudo:session): session opened for user root by (uid=0)
Nov 16 22:29:34 pimusic sudo[3384]: pam_unix(sudo:session): session closed for user root
Nov 16 22:29:34 pimusic sudo[3386]: mopidy : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/local/lib/python3.7/dist-packages/mopidy_iris/system.sh test
Nov 16 22:29:34 pimusic sudo[3386]: pam_unix(sudo:session): session opened for user root by (uid=0)
Nov 16 22:29:37 pimusic sudo[3386]: pam_unix(sudo:session): session closed for user root
Nov 16 22:29:37 pimusic mopidy[3274]: INFO [HttpServer] mopidy_iris.system Hello, this is your bash speaking. I was sleeping for 3 seconds. Is running a container: false

5

Yeh, you are right, there’s really noting useful there. But the service is running - it has not crashed so I don’t understand what this is showing. You can increase the log verbosity in the config (see ours docs) and you can display the full log using journalctl (see our docs).