-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Mon 2025-06-09 19:11:49 CEST. -- Jun 09 19:11:33 volumio ntpd[666]: receive: Unexpected origin timestamp 0xeb97cd86.dcc11e8b does not match aorg 0000000000.00000000 from server@89.161.47.136 xmt 0xebf19445.860774ba Jun 09 19:11:33 volumio systemd[1]: Starting Daily man-db regeneration... Jun 09 19:11:33 volumio systemd[1]: Starting Daily apt download activities... Jun 09 19:11:33 volumio volumio[842]: info: Discovery: A device disappeared from network Jun 09 19:11:33 volumio volumio[842]: info: Discovery: Device volumio disappeared from network Jun 09 19:11:33 volumio volumio[842]: info: go-librespot daemon successfully initialized Jun 09 19:11:33 volumio volumio[842]: info: CoreCommandRouter::volumioGetState Jun 09 19:11:33 volumio volumio[842]: info: CorePlayQueue::getTrack 0 Jun 09 19:11:33 volumio volumio[842]: info: touch_display: Setting screensaver timeout to 500 seconds. Jun 09 19:11:34 volumio go-librespot[1110]: time="2025-06-09T19:11:34+02:00" level=debug msg="obtained new client token: AADt0/ndHFNQLx1RmKme01uGO8USnzRuamtWs8+c6VXiH/T4AzE4JRMDVuH8lajfMcAzg4tDorZ91yYk5bws++W8FnyTn0pCdT03kAnH5MjujsLb2qLwoSV/CxS092K8UuSWibSeLMU/Fy99VoPj+6wuz9AmSGEtAZtiYg2JUHaNiZAqK6EnXQMta4SCbSdItL8njPz0kofGEbeHtGSr2lvTEymLt2oPSQGH7c3faIvih3InjzHtA3a3cIHSCHVx" Jun 09 19:11:34 volumio go-librespot[1110]: time="2025-06-09T19:11:34+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Jun 09 19:11:34 volumio go-librespot[1110]: time="2025-06-09T19:11:34+02:00" level=debug msg="completed keyexchange" Jun 09 19:11:35 volumio go-librespot[1110]: time="2025-06-09T19:11:35+02:00" level=debug msg="completed challenge" Jun 09 19:11:35 volumio go-librespot[1110]: time="2025-06-09T19:11:35+02:00" level=debug msg="authenticated as 4fb3dwm0kfmeawzdkaqjuyxy0" Jun 09 19:11:35 volumio volumio[972]: Generating RSA private key, 4096 bit long modulus (2 primes) Jun 09 19:11:35 volumio go-librespot[1110]: time="2025-06-09T19:11:35+02:00" level=debug msg="authenticated as 4fb3dwm0kfmeawzdkaqjuyxy0" Jun 09 19:11:35 volumio volumio[842]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jun 09 19:11:35 volumio go-librespot[1110]: time="2025-06-09T19:11:35+02:00" level=debug msg="dealer connection opened" Jun 09 19:11:35 volumio go-librespot[1110]: time="2025-06-09T19:11:35+02:00" level=info msg="accepted zeroconf user 4fb3dwm0kfmeawzdkaqjuyxy0 from MW" Jun 09 19:11:35 volumio go-librespot[1110]: time="2025-06-09T19:11:35+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jun 09 19:11:35 volumio go-librespot[1110]: time="2025-06-09T19:11:35+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jun 09 19:11:35 volumio go-librespot[1110]: time="2025-06-09T19:11:35+02:00" level=debug msg="autoplay enabled: false" Jun 09 19:11:35 volumio go-librespot[1110]: time="2025-06-09T19:11:35+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jun 09 19:11:35 volumio go-librespot[1110]: time="2025-06-09T19:11:35+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jun 09 19:11:35 volumio go-librespot[1110]: time="2025-06-09T19:11:35+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jun 09 19:11:35 volumio go-librespot[1110]: time="2025-06-09T19:11:35+02:00" level=debug msg="received connection id: OTkzZGQyNGYtNjU1Yi00NGM5LThjZjEtM2QwMzhjMTE0ODliK2RlYWxlcit0Y3A6Ly8wYWNhNThiZC5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArMzdFNDNCNjFFODVDMTdBMTFEREM4QjI3MDVCOERBMkI5QTQyNEVEMUNEMDVBQUYwMEE0NkI0NzVCN0MyM0QwRA==" Jun 09 19:11:35 volumio go-librespot[1110]: time="2025-06-09T19:11:35+02:00" level=debug msg="put connect state because NEW_DEVICE" Jun 09 19:11:36 volumio go-librespot[1110]: time="2025-06-09T19:11:36+02:00" level=debug msg="handling transfer player command from 3fe10a1f74b9fdf0e6bd883a6bd2e178dd832f46" Jun 09 19:11:36 volumio go-librespot[1110]: time="2025-06-09T19:11:36+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZF1E36KBmf354BbV" Jun 09 19:11:36 volumio go-librespot[1110]: time="2025-06-09T19:11:36+02:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" uri="spotify:playlist:37i9dQZF1E36KBmf354BbV" Jun 09 19:11:36 volumio go-librespot[1110]: time="2025-06-09T19:11:36+02:00" level=debug msg="loading track (paused: false, position: 136339ms)" uri="spotify:track:58kUEj9sd9Z2XIPh3BhJRR" Jun 09 19:11:36 volumio go-librespot[1110]: time="2025-06-09T19:11:36+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Jun 09 19:11:36 volumio go-librespot[1110]: time="2025-06-09T19:11:36+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 09 19:11:36 volumio go-librespot[1110]: time="2025-06-09T19:11:36+02:00" level=trace msg="emitting websocket event: will_play" Jun 09 19:11:36 volumio go-librespot[1110]: time="2025-06-09T19:11:36+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Jun 09 19:11:36 volumio go-librespot[1110]: time="2025-06-09T19:11:36+02:00" level=debug msg="selected format OGG_VORBIS_320 (6ca2083ee4b05b831d7d69fc18e530abef8188a8)" uri="spotify:track:58kUEj9sd9Z2XIPh3BhJRR" Jun 09 19:11:36 volumio go-librespot[1110]: time="2025-06-09T19:11:36+02:00" level=debug msg="requested aes key for file 6ca2083ee4b05b831d7d69fc18e530abef8188a8, gid: 58kUEj9sd9Z2XIPh3BhJRR" Jun 09 19:11:36 volumio go-librespot[1110]: time="2025-06-09T19:11:36+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2006" Jun 09 19:11:36 volumio systemd[1]: man-db.service: Succeeded. Jun 09 19:11:36 volumio systemd[1]: Started Daily man-db regeneration. Jun 09 19:11:36 volumio go-librespot[1110]: time="2025-06-09T19:11:36+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1447" Jun 09 19:11:36 volumio volumio[842]: info: Initializing connection to go-librespot Websocket Jun 09 19:11:36 volumio go-librespot[1110]: time="2025-06-09T19:11:36+02:00" level=debug msg="new websocket client" Jun 09 19:11:36 volumio volumio[842]: info: Connection to go-librespot Websocket established Jun 09 19:11:36 volumio go-librespot[1110]: time="2025-06-09T19:11:36+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Jun 09 19:11:36 volumio volumio[842]: info: Discovery: adding 33508c2c-a3ec-47a3-a3c2-6ba10fa7b8d3 Jun 09 19:11:36 volumio volumio[842]: info: Discovery: Found device Volumio Jun 09 19:11:36 volumio volumio[842]: info: CoreCommandRouter::volumioGetState Jun 09 19:11:36 volumio volumio[842]: info: CorePlayQueue::getTrack 0 Jun 09 19:11:37 volumio go-librespot[1110]: time="2025-06-09T19:11:37+02:00" level=debug msg="fetched first chunk of 17, total size is 8751024 bytes" uri="spotify:track:58kUEj9sd9Z2XIPh3BhJRR" Jun 09 19:11:37 volumio go-librespot[1110]: time="2025-06-09T19:11:37+02:00" level=debug msg="fetched chunk 1/16, size: 524288" uri="spotify:track:58kUEj9sd9Z2XIPh3BhJRR" Jun 09 19:11:38 volumio go-librespot[1110]: time="2025-06-09T19:11:38+02:00" level=debug msg="fetched chunk 2/16, size: 524288" uri="spotify:track:58kUEj9sd9Z2XIPh3BhJRR" Jun 09 19:11:38 volumio go-librespot[1110]: time="2025-06-09T19:11:38+02:00" level=debug msg="fetched chunk 11/16, size: 524288" uri="spotify:track:58kUEj9sd9Z2XIPh3BhJRR" Jun 09 19:11:38 volumio go-librespot[1110]: time="2025-06-09T19:11:38+02:00" level=debug msg="fetched chunk 10/16, size: 524288" uri="spotify:track:58kUEj9sd9Z2XIPh3BhJRR" Jun 09 19:11:38 volumio go-librespot[1110]: time="2025-06-09T19:11:38+02:00" level=debug msg="fetched chunk 13/16, size: 524288" uri="spotify:track:58kUEj9sd9Z2XIPh3BhJRR" Jun 09 19:11:38 volumio go-librespot[1110]: time="2025-06-09T19:11:38+02:00" level=trace msg="seek to 136339ms (diff: 173ms, samples: 6012549, bytes: 5340194)" uri="spotify:track:58kUEj9sd9Z2XIPh3BhJRR" Jun 09 19:11:38 volumio go-librespot[1110]: time="2025-06-09T19:11:38+02:00" level=debug msg="fetched chunk 3/16, size: 524288" uri="spotify:track:58kUEj9sd9Z2XIPh3BhJRR" Jun 09 19:11:39 volumio go-librespot[1110]: time="2025-06-09T19:11:39+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Jun 09 19:11:39 volumio go-librespot[1110]: time="2025-06-09T19:11:39+02:00" level=debug msg="created new output device" Jun 09 19:11:39 volumio go-librespot[1110]: time="2025-06-09T19:11:39+02:00" level=info msg="loaded track \"The Sign (with CamelPhat)\" (paused: false, position: 136339ms, duration: 213495ms, prefetched: false)" uri="spotify:track:58kUEj9sd9Z2XIPh3BhJRR" Jun 09 19:11:39 volumio systemd[1]: apt-daily.service: Succeeded. Jun 09 19:11:39 volumio systemd[1]: Started Daily apt download activities. Jun 09 19:11:39 volumio go-librespot[1110]: time="2025-06-09T19:11:39+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 09 19:11:39 volumio go-librespot[1110]: time="2025-06-09T19:11:39+02:00" level=trace msg="scheduling prefetch in 47s" Jun 09 19:11:39 volumio go-librespot[1110]: time="2025-06-09T19:11:39+02:00" level=trace msg="emitting websocket event: metadata" Jun 09 19:11:39 volumio systemd[1]: Starting Daily apt upgrade and clean activities... Jun 09 19:11:39 volumio volumio[842]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:58kUEj9sd9Z2XIPh3BhJRR","name":"The Sign (with CamelPhat)","artist_names":["Anyma","CamelPhat"],"album_name":"Genesys","album_cover_url":"https://i.scdn.co/image/ab67616d00001e022f952feea610a910c7daf561","position":136339,"duration":213495,"release_date":"year:2023 month:8 day:11","track_number":11,"disc_number":1}} Jun 09 19:11:39 volumio go-librespot[1110]: time="2025-06-09T19:11:39+02:00" level=trace msg="emitting websocket event: active" Jun 09 19:11:39 volumio go-librespot[1110]: time="2025-06-09T19:11:39+02:00" level=debug msg="sending successful reply for dealer request" Jun 09 19:11:39 volumio go-librespot[1110]: time="2025-06-09T19:11:39+02:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1E36KBmf354BbV" Jun 09 19:11:39 volumio go-librespot[1110]: time="2025-06-09T19:11:39+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 09 19:11:39 volumio go-librespot[1110]: time="2025-06-09T19:11:39+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 09 19:11:39 volumio go-librespot[1110]: time="2025-06-09T19:11:39+02:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1E36KBmf354BbV" Jun 09 19:11:39 volumio volumio[842]: SPOTIFY: received: {"type":"active","data":null} Jun 09 19:11:39 volumio volumio[842]: info: Aligning Spotify Volume to Volumio Volume Jun 09 19:11:39 volumio volumio[842]: info: CoreCommandRouter::volumioGetState Jun 09 19:11:39 volumio volumio[842]: info: CorePlayQueue::getTrack 0 Jun 09 19:11:39 volumio volumio[842]: info: Getting Spotify volume Jun 09 19:11:39 volumio go-librespot[1110]: time="2025-06-09T19:11:39+02:00" level=debug msg="fetched chunk 12/16, size: 524288" uri="spotify:track:58kUEj9sd9Z2XIPh3BhJRR" Jun 09 19:11:39 volumio go-librespot[1110]: time="2025-06-09T19:11:39+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 09 19:11:39 volumio go-librespot[1110]: time="2025-06-09T19:11:39+02:00" level=trace msg="emitting websocket event: playing" Jun 09 19:11:39 volumio go-librespot[1110]: time="2025-06-09T19:11:39+02:00" level=debug msg="handling update_context player command from 3fe10a1f74b9fdf0e6bd883a6bd2e178dd832f46" Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jun 09 19:11:39 volumio go-librespot[1110]: time="2025-06-09T19:11:39+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 09 19:11:39 volumio go-librespot[1110]: time="2025-06-09T19:11:39+02:00" level=debug msg="sending successful reply for dealer request" Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jun 09 19:11:39 volumio volumio[842]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jun 09 19:11:40 volumio volumio[842]: info: Adding plugin bluetooth to MyMusic Plugins Jun 09 19:11:40 volumio volumio[842]: info: Adding plugin multiroom to MyMusic Plugins Jun 09 19:11:40 volumio volumio[842]: info: Adding plugin metavolumio to MyMusic Plugins Jun 09 19:11:40 volumio volumio[842]: info: Adding plugin cd_controller to MyMusic Plugins Jun 09 19:11:40 volumio volumio[842]: info: Adding plugin smart_inputs to MyMusic Plugins Jun 09 19:11:40 volumio volumio[842]: info: Adding plugin tidalconnect to MyMusic Plugins Jun 09 19:11:40 volumio volumio[842]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jun 09 19:11:41 volumio go-librespot[1110]: time="2025-06-09T19:11:41+02:00" level=debug msg="update volume to 55669/65535" Jun 09 19:11:41 volumio go-librespot[1110]: time="2025-06-09T19:11:41+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Jun 09 19:11:41 volumio go-librespot[1110]: time="2025-06-09T19:11:41+02:00" level=trace msg="emitting websocket event: volume" Jun 09 19:11:41 volumio go-librespot[1110]: time="2025-06-09T19:11:41+02:00" level=debug msg="update volume to 45099/65535" Jun 09 19:11:41 volumio go-librespot[1110]: time="2025-06-09T19:11:41+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Jun 09 19:11:41 volumio go-librespot[1110]: time="2025-06-09T19:11:41+02:00" level=trace msg="emitting websocket event: volume" Jun 09 19:11:41 volumio go-librespot[1110]: time="2025-06-09T19:11:41+02:00" level=debug msg="update volume to 40871/65535" Jun 09 19:11:41 volumio go-librespot[1110]: time="2025-06-09T19:11:41+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Jun 09 19:11:41 volumio go-librespot[1110]: time="2025-06-09T19:11:41+02:00" level=trace msg="emitting websocket event: volume" Jun 09 19:11:43 volumio volumio[842]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jun 09 19:11:43 volumio volumio[842]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jun 09 19:11:43 volumio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 09 19:11:43 volumio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 09 19:11:43 volumio volumio[842]: info: Starting MyVolumio Remote Streaming Endpoints Jun 09 19:11:43 volumio volumio[842]: info: MyVolumio login type: Token Jun 09 19:11:43 volumio volumio[842]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jun 09 19:11:43 volumio volumio[842]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jun 09 19:11:43 volumio volumio[972]: ...........................++++ Jun 09 19:11:43 volumio go-librespot[1110]: time="2025-06-09T19:11:43+02:00" level=debug msg="update volume to 45099/65535" Jun 09 19:11:43 volumio go-librespot[1110]: time="2025-06-09T19:11:43+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Jun 09 19:11:43 volumio go-librespot[1110]: time="2025-06-09T19:11:43+02:00" level=trace msg="emitting websocket event: volume" Jun 09 19:11:43 volumio systemd[1]: apt-daily-upgrade.service: Succeeded. Jun 09 19:11:43 volumio systemd[1]: Started Daily apt upgrade and clean activities. Jun 09 19:11:44 volumio go-librespot[1110]: time="2025-06-09T19:11:44+02:00" level=debug msg="update volume to 58488/65535" Jun 09 19:11:44 volumio go-librespot[1110]: time="2025-06-09T19:11:44+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Jun 09 19:11:44 volumio go-librespot[1110]: time="2025-06-09T19:11:44+02:00" level=trace msg="emitting websocket event: volume" Jun 09 19:11:44 volumio go-librespot[1110]: time="2025-06-09T19:11:44+02:00" level=debug msg="update volume to 65535/65535" Jun 09 19:11:44 volumio go-librespot[1110]: time="2025-06-09T19:11:44+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Jun 09 19:11:44 volumio go-librespot[1110]: time="2025-06-09T19:11:44+02:00" level=trace msg="emitting websocket event: volume" Jun 09 19:11:46 volumio volumio[842]: info: Starting Streaming Service Transparent Proxy Jun 09 19:11:46 volumio volumio[842]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jun 09 19:11:46 volumio volumio[842]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jun 09 19:11:46 volumio volumio[842]: info: Streaming services startup Jun 09 19:11:46 volumio volumio[842]: info: Starting Streaming Daemon Jun 09 19:11:47 volumio volumio[842]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jun 09 19:11:47 volumio sudo[1392]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 09 19:11:47 volumio sudo[1392]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 19:11:47 volumio sudo[1392]: pam_unix(sudo:session): session closed for user root Jun 09 19:11:47 volumio volumio[842]: info: Spotify volume: 100 Jun 09 19:11:47 volumio volumio[842]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:58kUEj9sd9Z2XIPh3BhJRR","play_origin":"playlist"}} Jun 09 19:11:47 volumio volumio[842]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 09 19:11:47 volumio volumio[842]: TypeError: Cannot read property 'service' of undefined Jun 09 19:11:47 volumio volumio[842]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:337:50) Jun 09 19:11:47 volumio volumio[842]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:263:18) Jun 09 19:11:47 volumio volumio[842]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Jun 09 19:11:47 volumio volumio[842]: at WebSocket.emit (events.js:315:20) Jun 09 19:11:47 volumio volumio[842]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Jun 09 19:11:47 volumio volumio[842]: at Receiver.emit (events.js:315:20) Jun 09 19:11:47 volumio volumio[842]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Jun 09 19:11:47 volumio volumio[842]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Jun 09 19:11:47 volumio volumio[842]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Jun 09 19:11:47 volumio volumio[842]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Jun 09 19:11:47 volumio volumio[842]: at writeOrBuffer (internal/streams/writable.js:358:12) Jun 09 19:11:47 volumio volumio[842]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Jun 09 19:11:47 volumio volumio[842]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Jun 09 19:11:47 volumio volumio[842]: at Socket.emit (events.js:315:20) Jun 09 19:11:47 volumio volumio[842]: at addChunk (internal/streams/readable.js:309:12) Jun 09 19:11:47 volumio volumio[842]: at readableAddChunk (internal/streams/readable.js:284:9) Jun 09 19:11:47 volumio volumio[842]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 09 19:11:49 volumio sudo[1437]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-09 19:10 Jun 09 19:11:49 volumio sudo[1437]: pam_unix(sudo:session): session opened for user root by (uid=0) 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" VOLUMIO_BUILD_VERSION="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"