-- Logs begin at Sun 2025-05-25 09:40:48 CEST, end at Sun 2025-05-25 09:44:07 CEST. -- May 25 09:43:03 volumio ntpd[938]: Soliciting pool server 151.22.209.90 May 25 09:43:03 volumio ntpd[938]: Soliciting pool server 89.46.74.148 May 25 09:43:04 volumio ntpd[938]: Soliciting pool server 93.94.88.51 May 25 09:43:08 volumio ntpd[938]: Soliciting pool server 162.159.200.1 May 25 09:43:08 volumio volumio[1098]: info: Adding plugin smart_inputs to MyMusic Plugins May 25 09:43:08 volumio ntpd[938]: Soliciting pool server 95.110.254.234 May 25 09:43:08 volumio ntpd[938]: Soliciting pool server 129.152.16.145 May 25 09:43:08 volumio ntpd[938]: Soliciting pool server 212.45.144.88 May 25 09:43:08 volumio ntpd[938]: Soliciting pool server 80.211.133.9 May 25 09:43:09 volumio ntpd[938]: Soliciting pool server 37.247.53.178 May 25 09:43:09 volumio ntpd[938]: Soliciting pool server 162.159.200.123 May 25 09:43:09 volumio ntpd[938]: Soliciting pool server 85.199.214.99 May 25 09:43:10 volumio ntpd[938]: Soliciting pool server 80.211.238.32 May 25 09:43:10 volumio volumio[1098]: info: Adding plugin tidalconnect to MyMusic Plugins May 25 09:43:10 volumio volumio[1098]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... May 25 09:43:10 volumio ntpd[938]: Soliciting pool server 95.110.135.141 May 25 09:43:10 volumio ntpd[938]: Soliciting pool server 212.45.144.206 May 25 09:43:11 volumio ntpd[938]: Soliciting pool server 93.94.88.50 May 25 09:43:12 volumio ntpd[938]: Soliciting pool server 31.14.133.122 May 25 09:43:12 volumio volumio-remote-updater[743]: [2025-05-25 09:43:12] [connect] Successful connection May 25 09:43:12 volumio ntpd[938]: Soliciting pool server 2a00:6d41:200:2::11 May 25 09:43:19 volumio ntpd[938]: receive: Unexpected origin timestamp 0xebdd4890.f6322e6d does not match aorg 0000000000.00000000 from server@151.22.209.90 xmt 0xebdd4897.63cf0be9 May 25 09:43:19 volumio ntpd[938]: receive: Unexpected origin timestamp 0xebdd4890.f623d445 does not match aorg 0000000000.00000000 from server@93.94.88.50 xmt 0xebdd4897.64701426 May 25 09:43:19 volumio ntpd[938]: receive: Unexpected origin timestamp 0xebdd4890.f62e427c does not match aorg 0000000000.00000000 from server@93.94.88.51 xmt 0xebdd4897.64ac2fc5 May 25 09:43:19 volumio go-librespot[1539]: time="2025-05-25T09:43:19+02:00" level=trace msg="sent dealer ping" May 25 09:43:19 volumio go-librespot[1539]: time="2025-05-25T09:43:19+02:00" level=trace msg="received dealer pong" May 25 09:43:25 volumio volumio[1679]: Traceback (most recent call last): May 25 09:43:25 volumio volumio[1679]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in May 25 09:43:25 volumio volumio[1679]: from aiohttp import web May 25 09:43:25 volumio volumio[1679]: ModuleNotFoundError: No module named 'aiohttp' May 25 09:43:25 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE May 25 09:43:25 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. May 25 09:43:27 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. May 25 09:43:27 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 1. May 25 09:43:27 volumio systemd[1]: Stopped FusionDsp Daemon. May 25 09:43:27 volumio systemd[1]: Started FusionDsp Daemon. May 25 09:43:28 volumio volumio[1974]: Traceback (most recent call last): May 25 09:43:28 volumio volumio[1974]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in May 25 09:43:28 volumio volumio[1974]: from aiohttp import web May 25 09:43:28 volumio volumio[1974]: ModuleNotFoundError: No module named 'aiohttp' May 25 09:43:28 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE May 25 09:43:28 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. May 25 09:43:31 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. May 25 09:43:31 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 2. May 25 09:43:31 volumio systemd[1]: Stopped FusionDsp Daemon. May 25 09:43:31 volumio systemd[1]: Started FusionDsp Daemon. May 25 09:43:34 volumio volumio-remote-updater[743]: [2025-05-25 09:43:34] [connect] Successful connection May 25 09:43:39 volumio volumio[1975]: Traceback (most recent call last): May 25 09:43:39 volumio volumio[1975]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in May 25 09:43:39 volumio volumio[1975]: from aiohttp import web May 25 09:43:39 volumio volumio[1975]: ModuleNotFoundError: No module named 'aiohttp' May 25 09:43:39 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE May 25 09:43:39 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. May 25 09:43:41 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. May 25 09:43:41 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 3. May 25 09:43:41 volumio systemd[1]: Stopped FusionDsp Daemon. May 25 09:43:41 volumio systemd[1]: Started FusionDsp Daemon. May 25 09:43:41 volumio volumio[1998]: Traceback (most recent call last): May 25 09:43:41 volumio volumio[1998]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in May 25 09:43:41 volumio volumio[1998]: from aiohttp import web May 25 09:43:41 volumio volumio[1998]: ModuleNotFoundError: No module named 'aiohttp' May 25 09:43:41 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE May 25 09:43:41 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. May 25 09:43:44 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. May 25 09:43:44 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 4. May 25 09:43:44 volumio systemd[1]: Stopped FusionDsp Daemon. May 25 09:43:44 volumio systemd[1]: Started FusionDsp Daemon. May 25 09:43:44 volumio volumio[1999]: Traceback (most recent call last): May 25 09:43:44 volumio volumio[1999]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in May 25 09:43:44 volumio volumio[1999]: from aiohttp import web May 25 09:43:44 volumio volumio[1999]: ModuleNotFoundError: No module named 'aiohttp' May 25 09:43:44 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE May 25 09:43:44 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. May 25 09:43:46 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. May 25 09:43:46 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 5. May 25 09:43:46 volumio systemd[1]: Stopped FusionDsp Daemon. May 25 09:43:46 volumio systemd[1]: Started FusionDsp Daemon. May 25 09:43:49 volumio volumio-remote-updater[743]: [2025-05-25 09:43:49] [connect] Successful connection May 25 09:43:49 volumio volumio[2015]: Traceback (most recent call last): May 25 09:43:49 volumio volumio[2015]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in May 25 09:43:49 volumio volumio[2015]: from aiohttp import web May 25 09:43:49 volumio volumio[2015]: ModuleNotFoundError: No module named 'aiohttp' May 25 09:43:49 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE May 25 09:43:49 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. May 25 09:43:49 volumio go-librespot[1539]: time="2025-05-25T09:43:49+02:00" level=trace msg="sent dealer ping" May 25 09:43:49 volumio go-librespot[1539]: time="2025-05-25T09:43:49+02:00" level=trace msg="received dealer pong" May 25 09:43:51 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. May 25 09:43:51 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 6. May 25 09:43:51 volumio systemd[1]: Stopped FusionDsp Daemon. May 25 09:43:51 volumio systemd[1]: Started FusionDsp Daemon. May 25 09:43:52 volumio go-librespot[1539]: time="2025-05-25T09:43:52+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 250" May 25 09:43:52 volumio go-librespot[1539]: time="2025-05-25T09:43:52+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 25 09:43:52 volumio volumio[2060]: Traceback (most recent call last): May 25 09:43:52 volumio volumio[2060]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in May 25 09:43:52 volumio volumio[2060]: from aiohttp import web May 25 09:43:52 volumio volumio[2060]: ModuleNotFoundError: No module named 'aiohttp' May 25 09:43:52 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE May 25 09:43:52 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. May 25 09:43:54 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. May 25 09:43:54 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 7. May 25 09:43:54 volumio systemd[1]: Stopped FusionDsp Daemon. May 25 09:43:54 volumio systemd[1]: Started FusionDsp Daemon. May 25 09:43:57 volumio volumio[2061]: Traceback (most recent call last): May 25 09:43:57 volumio volumio[2061]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in May 25 09:43:57 volumio volumio[2061]: from aiohttp import web May 25 09:43:57 volumio volumio[2061]: ModuleNotFoundError: No module named 'aiohttp' May 25 09:43:57 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE May 25 09:43:57 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. May 25 09:43:59 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. May 25 09:43:59 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 8. May 25 09:43:59 volumio systemd[1]: Stopped FusionDsp Daemon. May 25 09:43:59 volumio systemd[1]: Started FusionDsp Daemon. May 25 09:44:00 volumio volumio[2079]: Traceback (most recent call last): May 25 09:44:00 volumio volumio[2079]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in May 25 09:44:00 volumio volumio[2079]: from aiohttp import web May 25 09:44:00 volumio volumio[2079]: ModuleNotFoundError: No module named 'aiohttp' May 25 09:44:00 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE May 25 09:44:00 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. May 25 09:44:02 volumio go-librespot[1539]: time="2025-05-25T09:44:02+02:00" level=debug msg="handling transfer player command from de0e298ae6db048f861552dbdbd3840544b81413" May 25 09:44:02 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. May 25 09:44:02 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 9. May 25 09:44:02 volumio systemd[1]: Stopped FusionDsp Daemon. May 25 09:44:02 volumio systemd[1]: Started FusionDsp Daemon. May 25 09:44:02 volumio go-librespot[1539]: time="2025-05-25T09:44:02+02:00" level=debug msg="resolved context of track" uri="spotify:station:track:5UuikgHTxSRFRnC0zXx10i" May 25 09:44:02 volumio go-librespot[1539]: time="2025-05-25T09:44:02+02:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" uri="spotify:station:track:5UuikgHTxSRFRnC0zXx10i" May 25 09:44:02 volumio go-librespot[1539]: time="2025-05-25T09:44:02+02:00" level=debug msg="loading track (paused: false, position: 104230ms)" uri="spotify:track:6fnachl7fIn5dqIjakfJ57" May 25 09:44:02 volumio go-librespot[1539]: time="2025-05-25T09:44:02+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 25 09:44:02 volumio go-librespot[1539]: time="2025-05-25T09:44:02+02:00" level=trace msg="emitting websocket event: will_play" May 25 09:44:02 volumio go-librespot[1539]: time="2025-05-25T09:44:02+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" May 25 09:44:02 volumio go-librespot[1539]: time="2025-05-25T09:44:02+02:00" level=debug msg="selected format OGG_VORBIS_320 (d5eff7c28b8b5cb1bb586b2b3751c07fee5ad451)" uri="spotify:track:6fnachl7fIn5dqIjakfJ57" May 25 09:44:02 volumio go-librespot[1539]: time="2025-05-25T09:44:02+02:00" level=debug msg="requested aes key for file d5eff7c28b8b5cb1bb586b2b3751c07fee5ad451, gid: 6fnachl7fIn5dqIjakfJ57" May 25 09:44:02 volumio go-librespot[1539]: time="2025-05-25T09:44:02+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 3204" May 25 09:44:03 volumio go-librespot[1539]: time="2025-05-25T09:44:03+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2046" May 25 09:44:03 volumio volumio[2080]: Traceback (most recent call last): May 25 09:44:03 volumio volumio[2080]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in May 25 09:44:03 volumio volumio[2080]: from aiohttp import web May 25 09:44:03 volumio volumio[2080]: ModuleNotFoundError: No module named 'aiohttp' May 25 09:44:03 volumio volumio[1098]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded May 25 09:44:03 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE May 25 09:44:03 volumio volumio[1098]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio May 25 09:44:03 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. May 25 09:44:03 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 25 09:44:03 volumio volumio[1098]: info: Starting MyVolumio Remote Streaming Endpoints May 25 09:44:03 volumio volumio[1098]: info: MyVolumio login type: Token May 25 09:44:03 volumio volumio[1098]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started May 25 09:44:03 volumio volumio[1098]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... May 25 09:44:03 volumio go-librespot[1539]: time="2025-05-25T09:44:03+02:00" level=debug msg="fetched first chunk of 27, total size is 13668356 bytes" uri="spotify:track:6fnachl7fIn5dqIjakfJ57" May 25 09:44:04 volumio volumio-remote-updater[743]: [2025-05-25 09:44:04] [connect] Successful connection May 25 09:44:04 volumio go-librespot[1539]: time="2025-05-25T09:44:04+02:00" level=debug msg="fetched chunk 1/26, size: 524288" uri="spotify:track:6fnachl7fIn5dqIjakfJ57" May 25 09:44:05 volumio systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. May 25 09:44:05 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 10. May 25 09:44:05 volumio systemd[1]: Stopped FusionDsp Daemon. May 25 09:44:05 volumio systemd[1]: Started FusionDsp Daemon. May 25 09:44:05 volumio volumio[2082]: Traceback (most recent call last): May 25 09:44:05 volumio volumio[2082]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in May 25 09:44:05 volumio volumio[2082]: from aiohttp import web May 25 09:44:05 volumio volumio[2082]: ModuleNotFoundError: No module named 'aiohttp' May 25 09:44:05 volumio go-librespot[1539]: time="2025-05-25T09:44:05+02:00" level=debug msg="fetched chunk 10/26, size: 524288" uri="spotify:track:6fnachl7fIn5dqIjakfJ57" May 25 09:44:05 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE May 25 09:44:05 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. May 25 09:44:05 volumio go-librespot[1539]: time="2025-05-25T09:44:05+02:00" level=debug msg="fetched chunk 7/26, size: 524288" uri="spotify:track:6fnachl7fIn5dqIjakfJ57" May 25 09:44:05 volumio go-librespot[1539]: time="2025-05-25T09:44:05+02:00" level=trace msg="seek to 104230ms (diff: 238ms, samples: 4596543, bytes: 3701314)" uri="spotify:track:6fnachl7fIn5dqIjakfJ57" May 25 09:44:05 volumio go-librespot[1539]: time="2025-05-25T09:44:05+02:00" level=debug msg="created new output device" May 25 09:44:05 volumio go-librespot[1539]: time="2025-05-25T09:44:05+02:00" level=debug msg="fetched chunk 2/26, size: 524288" uri="spotify:track:6fnachl7fIn5dqIjakfJ57" May 25 09:44:05 volumio go-librespot[1539]: time="2025-05-25T09:44:05+02:00" level=debug msg="fetched chunk 3/26, size: 524288" uri="spotify:track:6fnachl7fIn5dqIjakfJ57" May 25 09:44:05 volumio go-librespot[1539]: time="2025-05-25T09:44:05+02:00" level=debug msg="fetched chunk 8/26, size: 524288" uri="spotify:track:6fnachl7fIn5dqIjakfJ57" May 25 09:44:05 volumio go-librespot[1539]: time="2025-05-25T09:44:05+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" May 25 09:44:05 volumio go-librespot[1539]: time="2025-05-25T09:44:05+02:00" level=info msg="loaded track \"School\" (paused: false, position: 104230ms, duration: 335286ms, prefetched: false)" uri="spotify:track:6fnachl7fIn5dqIjakfJ57" May 25 09:44:05 volumio go-librespot[1539]: time="2025-05-25T09:44:05+02:00" level=debug msg="fetched chunk 9/26, size: 524288" uri="spotify:track:6fnachl7fIn5dqIjakfJ57" May 25 09:44:05 volumio go-librespot[1539]: time="2025-05-25T09:44:05+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 25 09:44:05 volumio go-librespot[1539]: time="2025-05-25T09:44:05+02:00" level=trace msg="scheduling prefetch in 201s" May 25 09:44:05 volumio go-librespot[1539]: time="2025-05-25T09:44:05+02:00" level=trace msg="emitting websocket event: metadata" May 25 09:44:05 volumio go-librespot[1539]: time="2025-05-25T09:44:05+02:00" level=trace msg="emitting websocket event: active" May 25 09:44:05 volumio go-librespot[1539]: time="2025-05-25T09:44:05+02:00" level=debug msg="sending successful reply for dealer request" May 25 09:44:05 volumio go-librespot[1539]: time="2025-05-25T09:44:05+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 25 09:44:05 volumio go-librespot[1539]: time="2025-05-25T09:44:05+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 25 09:44:06 volumio volumio[1098]: info: Starting Streaming Service Transparent Proxy May 25 09:44:06 volumio volumio[1098]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded May 25 09:44:06 volumio volumio[1098]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services May 25 09:44:06 volumio volumio[1098]: info: Streaming services startup May 25 09:44:06 volumio volumio[1098]: info: Starting Streaming Daemon May 25 09:44:06 volumio sudo[2091]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 25 09:44:06 volumio sudo[2091]: pam_unix(sudo:session): session opened for user root by (uid=0) May 25 09:44:06 volumio go-librespot[1539]: time="2025-05-25T09:44:06+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 25 09:44:06 volumio go-librespot[1539]: time="2025-05-25T09:44:06+02:00" level=trace msg="emitting websocket event: playing" May 25 09:44:06 volumio sudo[2091]: pam_unix(sudo:session): session closed for user root May 25 09:44:06 volumio volumio[1098]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started May 25 09:44:06 volumio volumio[1098]: info: Shairport-Sync Started May 25 09:44:06 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd May 25 09:44:06 volumio sudo[2099]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 25 09:44:06 volumio sudo[2099]: pam_unix(sudo:session): session opened for user root by (uid=0) May 25 09:44:06 volumio volumio[1098]: info: Getting Spotify volume May 25 09:44:06 volumio systemd[1]: Stopping Music Player Daemon... May 25 09:44:06 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 25 09:44:06 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 25 09:44:06 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 25 09:44:06 volumio systemd[1]: mpd.service: Succeeded. May 25 09:44:06 volumio systemd[1]: Stopped Music Player Daemon. May 25 09:44:06 volumio systemd[1]: Starting Music Player Daemon... May 25 09:44:06 volumio sudo[2116]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 25 09:44:06 volumio sudo[2116]: pam_unix(sudo:session): session opened for user root by (uid=0) May 25 09:44:06 volumio sudo[2116]: pam_unix(sudo:session): session closed for user root May 25 09:44:06 volumio volumio[1098]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6fnachl7fIn5dqIjakfJ57","play_origin":""}} May 25 09:44:06 volumio volumio[1098]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6fnachl7fIn5dqIjakfJ57","name":"School","artist_names":["Supertramp"],"album_name":"Crime Of The Century (Remastered)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0289d7032603b62e9aedb03fa2","position":104230,"duration":335286,"release_date":"year:1974 month:9 day:1","track_number":1,"disc_number":1}} May 25 09:44:06 volumio volumio[1098]: SPOTIFY: received: {"type":"active","data":null} May 25 09:44:06 volumio volumio[1098]: info: Aligning Spotify Volume to Volumio Volume May 25 09:44:06 volumio volumio[1098]: info: CoreCommandRouter::volumioGetState May 25 09:44:06 volumio volumio[1098]: info: CorePlayQueue::getTrack 0 May 25 09:44:06 volumio volumio[1098]: info: Setting Spotify Volume from Volumio: 78 May 25 09:44:06 volumio volumio[1098]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6fnachl7fIn5dqIjakfJ57","play_origin":""}} May 25 09:44:06 volumio volumio[1098]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 25 09:44:06 volumio volumio[1098]: TypeError: Cannot read property 'service' of undefined May 25 09:44:06 volumio volumio[1098]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:340:50) May 25 09:44:06 volumio volumio[1098]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:266:18) May 25 09:44:06 volumio volumio[1098]: at WebSocket.message (/data/plugins/music_service/spop/index.js:193:14) May 25 09:44:06 volumio volumio[1098]: at WebSocket.emit (events.js:400:28) May 25 09:44:06 volumio volumio[1098]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) May 25 09:44:06 volumio volumio[1098]: at Receiver.emit (events.js:400:28) May 25 09:44:06 volumio volumio[1098]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) May 25 09:44:06 volumio volumio[1098]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) May 25 09:44:06 volumio volumio[1098]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) May 25 09:44:06 volumio volumio[1098]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) May 25 09:44:06 volumio volumio[1098]: at writeOrBuffer (internal/streams/writable.js:358:12) May 25 09:44:06 volumio volumio[1098]: at Receiver.Writable.write (internal/streams/writable.js:303:10) May 25 09:44:06 volumio volumio[1098]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) May 25 09:44:06 volumio volumio[1098]: at Socket.emit (events.js:400:28) May 25 09:44:06 volumio volumio[1098]: at addChunk (internal/streams/readable.js:293:12) May 25 09:44:06 volumio volumio[1098]: at readableAddChunk (internal/streams/readable.js:267:9) May 25 09:44:06 volumio volumio[1098]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 25 09:44:07 volumio mpd[2119]: May 25 09:44 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 25 09:44:07 volumio systemd[1]: Started Music Player Daemon. May 25 09:44:07 volumio sudo[2099]: pam_unix(sudo:session): session closed for user root May 25 09:44:07 volumio sudo[2131]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-25 09:43 May 25 09:44:07 volumio sudo[2131]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 07:27:48 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="4bc1ecb08f34ad14b420d6678a2aef1b"