Jan 10 00:31:08 volumio-rpi volumio[1125]: Searching plugin music_service/spop Jan 10 00:31:08 volumio-rpi volumio[1125]: info: CoreCommandRouter::executeOnPlugin: spop , search Jan 10 00:31:09 volumio-rpi volumio[1125]: info: All search sources collected, pushing search results Jan 10 00:31:09 volumio-rpi volumio[1125]: Searching plugin music_service/spop Jan 10 00:31:09 volumio-rpi volumio[1125]: info: CoreCommandRouter::executeOnPlugin: spop , search Jan 10 00:31:10 volumio-rpi volumio[1125]: info: All search sources collected, pushing search results Jan 10 00:31:10 volumio-rpi volumio[1125]: Searching plugin music_service/spop Jan 10 00:31:10 volumio-rpi volumio[1125]: info: CoreCommandRouter::executeOnPlugin: spop , search Jan 10 00:31:11 volumio-rpi volumio[1125]: info: All search sources collected, pushing search results Jan 10 00:31:11 volumio-rpi volumio[1125]: info: CorePlayQueue::getTrack 7 Jan 10 00:31:11 volumio-rpi volumio[1125]: info: CorePlayQueue::getTrack 8 Jan 10 00:31:11 volumio-rpi volumio[1125]: info: Prefetching next song Jan 10 00:31:11 volumio-rpi volumio[1125]: info: [1768001471484] ControllerSpotify::prefetch Jan 10 00:31:11 volumio-rpi volumio[1125]: info: Sending Spotify command with payload to local API: /player/add_to_queue Jan 10 00:31:11 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:11+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 10 00:31:11 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:11+01:00" level=trace msg="prefetch as soon as possible" Jan 10 00:31:11 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:11+01:00" level=debug msg="prefetching next track" uri="spotify:track:1z3ugFmUKoCzGsI6jdY4Ci" Jan 10 00:31:11 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:11+01:00" level=debug msg="selected format OGG_VORBIS_320 (c1f467bd8fd5b762ba69ec12156ab9b1b48d9167)" uri="spotify:track:1z3ugFmUKoCzGsI6jdY4Ci" Jan 10 00:31:11 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:11+01:00" level=debug msg="requested aes key for file c1f467bd8fd5b762ba69ec12156ab9b1b48d9167, gid: 1z3ugFmUKoCzGsI6jdY4Ci" Jan 10 00:31:11 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:11+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:1z3ugFmUKoCzGsI6jdY4Ci" Jan 10 00:31:11 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:11+01:00" level=debug msg="fetched first chunk of 28, total size is 14662475 bytes" uri="spotify:track:1z3ugFmUKoCzGsI6jdY4Ci" Jan 10 00:31:11 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:11+01:00" level=info msg="prefetched track \"Like a Prayer\" (duration: 342680ms)" uri="spotify:track:1z3ugFmUKoCzGsI6jdY4Ci" Jan 10 00:31:11 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:11+01:00" level=debug msg="fetched chunk 1/27, size: 524288" uri="spotify:track:1z3ugFmUKoCzGsI6jdY4Ci" Jan 10 00:31:11 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:11+01:00" level=debug msg="fetched chunk 2/27, size: 524288" uri="spotify:track:1z3ugFmUKoCzGsI6jdY4Ci" Jan 10 00:31:11 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:11+01:00" level=debug msg="fetched chunk 3/27, size: 524288" uri="spotify:track:1z3ugFmUKoCzGsI6jdY4Ci" Jan 10 00:31:12 volumio-rpi volumio[1125]: Searching plugin music_service/spop Jan 10 00:31:12 volumio-rpi volumio[1125]: info: CoreCommandRouter::executeOnPlugin: spop , search Jan 10 00:31:12 volumio-rpi systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 154. Jan 10 00:31:12 volumio-rpi systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 10 00:31:12 volumio-rpi systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 10 00:31:12 volumio-rpi upmpdcli[6385]: Could not open config: /tmp/upmpdcli.conf Jan 10 00:31:12 volumio-rpi systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 10 00:31:12 volumio-rpi systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 10 00:31:12 volumio-rpi volumio[1125]: info: All search sources collected, pushing search results Jan 10 00:31:14 volumio-rpi volumio[1125]: Searching plugin music_service/spop Jan 10 00:31:14 volumio-rpi volumio[1125]: info: CoreCommandRouter::executeOnPlugin: spop , search Jan 10 00:31:14 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:14+01:00" level=trace msg="emitting websocket event: not_playing" Jan 10 00:31:14 volumio-rpi volumio[1125]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:track:2m0M7YqCy4lXfedh18qd8N","uri":"spotify:track:2m0M7YqCy4lXfedh18qd8N","play_origin":"go-librespot"}} Jan 10 00:31:14 volumio-rpi volumio[1125]: error: Failed to decode event: not_playing Jan 10 00:31:14 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:14+01:00" level=debug msg="loading track (paused: false, position: 2ms)" uri="spotify:track:1z3ugFmUKoCzGsI6jdY4Ci" Jan 10 00:31:15 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:15+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 10 00:31:15 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:15+01:00" level=trace msg="emitting websocket event: will_play" Jan 10 00:31:15 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:15+01:00" level=info msg="loaded track \"Like a Prayer\" (paused: false, position: 2ms, duration: 342680ms, prefetched: true)" uri="spotify:track:1z3ugFmUKoCzGsI6jdY4Ci" Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:2m0M7YqCy4lXfedh18qd8N","uri":"spotify:track:1z3ugFmUKoCzGsI6jdY4Ci","play_origin":"go-librespot"}} Jan 10 00:31:15 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:15+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 10 00:31:15 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:15+01:00" level=trace msg="scheduling prefetch in 313s" Jan 10 00:31:15 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:15+01:00" level=trace msg="emitting websocket event: metadata" Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1z3ugFmUKoCzGsI6jdY4Ci","name":"Like a Prayer","artist_names":["Madonna"],"album_name":"Celebration (double disc version)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e026b44fa8f5415cc4c945117be","position":2,"duration":342680,"release_date":"year:2009 month:9 day:18","track_number":9,"disc_number":1}} Jan 10 00:31:15 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:15+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 10 00:31:15 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:15+01:00" level=trace msg="emitting websocket event: playing" Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:2m0M7YqCy4lXfedh18qd8N","uri":"spotify:track:1z3ugFmUKoCzGsI6jdY4Ci","resume":false,"play_origin":"go-librespot"}} Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: PUSH STATE SPOTIFY Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: {"status":"play","service":"spop","title":"Like a Prayer","artist":"Madonna","album":"Celebration (double disc version)","albumart":"https://i.scdn.co/image/ab67616d00001e026b44fa8f5415cc4c945117be","uri":"spotify:track:1z3ugFmUKoCzGsI6jdY4Ci","trackType":"spotify","seek":2,"duration":342,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CoreCommandRouter::servicePushState Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CorePlayQueue::getTrack 7 Jan 10 00:31:15 volumio-rpi volumio[1125]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Like a Prayer","artist":"Madonna","album":"Celebration (double disc version)","albumart":"https://i.scdn.co/image/ab67616d00001e026b44fa8f5415cc4c945117be","uri":"spotify:track:1z3ugFmUKoCzGsI6jdY4Ci","trackType":"spotify","seek":2,"duration":342,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 10 00:31:15 volumio-rpi volumio[1125]: verbose: CURRENT POSITION 7 Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CoreStateMachine::syncState stateService play Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CoreStateMachine::syncState currentStatus play Jan 10 00:31:15 volumio-rpi volumio[1125]: info: Received an update from plugin. extracting info from payload Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CoreStateMachine::pushState Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CorePlayQueue::getTrack 7 Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CoreCommandRouter::volumioPushState Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CoreStateMachine::pushState Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CorePlayQueue::getTrack 7 Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CoreCommandRouter::volumioPushState Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: SPOTIFY VOLUME 31 Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: VOLUMIO VOLUME 30 Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: SPOTIFY VOLUME 31 Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: VOLUMIO VOLUME 30 Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 10 00:31:15 volumio-rpi volumio[1125]: info: All search sources collected, pushing search results Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: PUSH STATE SPOTIFY Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: {"status":"play","service":"spop","title":"Like a Prayer","artist":"Madonna","album":"Celebration (double disc version)","albumart":"https://i.scdn.co/image/ab67616d00001e026b44fa8f5415cc4c945117be","uri":"spotify:track:1z3ugFmUKoCzGsI6jdY4Ci","trackType":"spotify","seek":1002,"duration":342,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CoreCommandRouter::servicePushState Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CorePlayQueue::getTrack 7 Jan 10 00:31:15 volumio-rpi volumio[1125]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Like a Prayer","artist":"Madonna","album":"Celebration (double disc version)","albumart":"https://i.scdn.co/image/ab67616d00001e026b44fa8f5415cc4c945117be","uri":"spotify:track:1z3ugFmUKoCzGsI6jdY4Ci","trackType":"spotify","seek":1002,"duration":342,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 10 00:31:15 volumio-rpi volumio[1125]: verbose: CURRENT POSITION 7 Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CoreStateMachine::syncState stateService play Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CoreStateMachine::syncState currentStatus play Jan 10 00:31:15 volumio-rpi volumio[1125]: info: Received an update from plugin. extracting info from payload Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CoreStateMachine::pushState Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CorePlayQueue::getTrack 7 Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CoreCommandRouter::volumioPushState Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CoreStateMachine::pushState Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CorePlayQueue::getTrack 7 Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CoreCommandRouter::volumioPushState Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: SPOTIFY VOLUME 31 Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: VOLUMIO VOLUME 30 Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: SPOTIFY VOLUME 31 Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: VOLUMIO VOLUME 30 Jan 10 00:31:15 volumio-rpi volumio[1125]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CoreStateMachine::startPlaybackTimer Jan 10 00:31:15 volumio-rpi volumio[1125]: info: CorePlayQueue::getTrack 8 Jan 10 00:31:16 volumio-rpi volumio[1125]: info: CoreStateMachine::pushState Jan 10 00:31:16 volumio-rpi volumio[1125]: info: CorePlayQueue::getTrack 8 Jan 10 00:31:16 volumio-rpi volumio[1125]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 00:31:16 volumio-rpi volumio[1125]: info: CoreCommandRouter::volumioPushState Jan 10 00:31:16 volumio-rpi volumio[1125]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jan 10 00:31:16 volumio-rpi volumio[1125]: SPOTIFY: SPOTIFY VOLUME 31 Jan 10 00:31:16 volumio-rpi volumio[1125]: SPOTIFY: VOLUMIO VOLUME 30 Jan 10 00:31:16 volumio-rpi volumio[1125]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 10 00:31:20 volumio-rpi volumio[1125]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jan 10 00:31:20 volumio-rpi volumio[1125]: info: In handleBrowseUri, curUri=spotify:album:7CglWjC8A5ve6TnUMvEFOt Jan 10 00:31:20 volumio-rpi volumio[1125]: info: Preload queue cleared Jan 10 00:31:20 volumio-rpi volumio[1125]: info: Preloading song: spotify:track:0t6HnXs3lyLrv8DFszfQrl Jan 10 00:31:20 volumio-rpi volumio[1125]: info: Exploding uri spotify:track:0t6HnXs3lyLrv8DFszfQrl in service spop Jan 10 00:31:20 volumio-rpi volumio[1125]: SPOTIFY: EXPLODING URI:spotify:track:0t6HnXs3lyLrv8DFszfQrl Jan 10 00:31:21 volumio-rpi volumio[1125]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0t6HnXs3lyLrv8DFszfQrl","service":"spop","name":"Into The Groove (You Can Dance Remix Edit) - 2022 Remaster","artist":"Madonna","album":"Into The Groove (You Can Dance Remix Edit) [2022 Remaster]","type":"song","duration":284,"albumart":"https://i.scdn.co/image/ab67616d0000b273345bca596184f8f8ff98d1d9","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 10 00:31:21 volumio-rpi volumio[1125]: info: No valid Plugin REST Endpoint Jan 10 00:31:25 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:25+01:00" level=trace msg="sent dealer ping" Jan 10 00:31:25 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:25+01:00" level=trace msg="received dealer pong" Jan 10 00:31:27 volumio-rpi systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 155. Jan 10 00:31:27 volumio-rpi systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 10 00:31:27 volumio-rpi systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 10 00:31:27 volumio-rpi upmpdcli[6417]: Could not open config: /tmp/upmpdcli.conf Jan 10 00:31:27 volumio-rpi systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 10 00:31:27 volumio-rpi systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 10 00:31:29 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:29+01:00" level=debug msg="fetched chunk 4/27, size: 524288" uri="spotify:track:1z3ugFmUKoCzGsI6jdY4Ci" Jan 10 00:31:42 volumio-rpi systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 156. Jan 10 00:31:42 volumio-rpi systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 10 00:31:42 volumio-rpi systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 10 00:31:43 volumio-rpi upmpdcli[6439]: Could not open config: /tmp/upmpdcli.conf Jan 10 00:31:43 volumio-rpi systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 10 00:31:43 volumio-rpi systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 10 00:31:43 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:43+01:00" level=debug msg="fetched chunk 5/27, size: 524288" uri="spotify:track:1z3ugFmUKoCzGsI6jdY4Ci" Jan 10 00:31:55 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:55+01:00" level=trace msg="sent dealer ping" Jan 10 00:31:55 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:55+01:00" level=trace msg="received dealer pong" Jan 10 00:31:55 volumio-rpi go-librespot[1520]: time="2026-01-10T00:31:55+01:00" level=debug msg="fetched chunk 6/27, size: 524288" uri="spotify:track:1z3ugFmUKoCzGsI6jdY4Ci" Jan 10 00:31:58 volumio-rpi systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 157. Jan 10 00:31:58 volumio-rpi systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 10 00:31:58 volumio-rpi systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 10 00:31:58 volumio-rpi upmpdcli[6468]: Could not open config: /tmp/upmpdcli.conf Jan 10 00:31:58 volumio-rpi systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 10 00:31:58 volumio-rpi systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 10 00:32:07 volumio-rpi go-librespot[1520]: time="2026-01-10T00:32:07+01:00" level=debug msg="fetched chunk 7/27, size: 524288" uri="spotify:track:1z3ugFmUKoCzGsI6jdY4Ci" Jan 10 00:32:10 volumio-rpi volumio[1125]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jan 10 00:32:10 volumio-rpi volumio[1125]: info: In handleBrowseUri, curUri=spotify:album:2IU9ftOgyRL2caQGWK1jjX Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Preload queue cleared Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Preloading song: spotify:track:7bkyXSi4GtVfD7itZRUR3e Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Preloading song: spotify:track:7ov1nZ2QZc3LIuCXXERZP0 Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Preloading song: spotify:track:1ZPlNanZsJSPK5h9YZZFbZ Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Preloading song: spotify:track:0uIqV0X1M1vjti0ubMOInt Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Preloading song: spotify:track:1S14j6I0RrdQoxrm7zZNHL Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Preloading song: spotify:track:1Fhx9C87IjEAtWI9FF0IzF Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Preloading song: spotify:track:36IHTITiDnlpQWUacWWZpB Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Preloading song: spotify:track:0S9EixwOfXC0LyILi8kVFh Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Preloading song: spotify:track:19gLqMCui3hxPDTKTEoELa Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Preloading song: spotify:track:17WvhmXF06yquUwZjtjHsc Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Preloading song: spotify:track:4vle25yO4Rf7AYkWtzSfAS Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Exploding uri spotify:track:7bkyXSi4GtVfD7itZRUR3e in service spop Jan 10 00:32:10 volumio-rpi volumio[1125]: SPOTIFY: EXPLODING URI:spotify:track:7bkyXSi4GtVfD7itZRUR3e Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Exploding uri spotify:track:7ov1nZ2QZc3LIuCXXERZP0 in service spop Jan 10 00:32:10 volumio-rpi volumio[1125]: SPOTIFY: EXPLODING URI:spotify:track:7ov1nZ2QZc3LIuCXXERZP0 Jan 10 00:32:10 volumio-rpi volumio[1125]: info: No valid Plugin REST Endpoint Jan 10 00:32:10 volumio-rpi volumio[1125]: info: No valid Plugin REST Endpoint Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Exploding uri spotify:track:1ZPlNanZsJSPK5h9YZZFbZ in service spop Jan 10 00:32:10 volumio-rpi volumio[1125]: SPOTIFY: EXPLODING URI:spotify:track:1ZPlNanZsJSPK5h9YZZFbZ Jan 10 00:32:10 volumio-rpi volumio[1125]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7bkyXSi4GtVfD7itZRUR3e","service":"spop","name":"Material Girl","artist":"Madonna","album":"Like a Virgin","type":"song","duration":240,"albumart":"https://i.scdn.co/image/ab67616d0000b27399d424b0873a9a714279a9f3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Exploding uri spotify:track:0uIqV0X1M1vjti0ubMOInt in service spop Jan 10 00:32:10 volumio-rpi volumio[1125]: SPOTIFY: EXPLODING URI:spotify:track:0uIqV0X1M1vjti0ubMOInt Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Exploding uri spotify:track:1S14j6I0RrdQoxrm7zZNHL in service spop Jan 10 00:32:10 volumio-rpi volumio[1125]: SPOTIFY: EXPLODING URI:spotify:track:1S14j6I0RrdQoxrm7zZNHL Jan 10 00:32:10 volumio-rpi volumio[1125]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7ov1nZ2QZc3LIuCXXERZP0","service":"spop","name":"Angel","artist":"Madonna","album":"Like a Virgin","type":"song","duration":236,"albumart":"https://i.scdn.co/image/ab67616d0000b27399d424b0873a9a714279a9f3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Exploding uri spotify:track:1Fhx9C87IjEAtWI9FF0IzF in service spop Jan 10 00:32:10 volumio-rpi volumio[1125]: SPOTIFY: EXPLODING URI:spotify:track:1Fhx9C87IjEAtWI9FF0IzF Jan 10 00:32:10 volumio-rpi volumio[1125]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1ZPlNanZsJSPK5h9YZZFbZ","service":"spop","name":"Like a Virgin","artist":"Madonna","album":"Like a Virgin","type":"song","duration":218,"albumart":"https://i.scdn.co/image/ab67616d0000b27399d424b0873a9a714279a9f3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Exploding uri spotify:track:36IHTITiDnlpQWUacWWZpB in service spop Jan 10 00:32:10 volumio-rpi volumio[1125]: SPOTIFY: EXPLODING URI:spotify:track:36IHTITiDnlpQWUacWWZpB Jan 10 00:32:10 volumio-rpi volumio[1125]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0uIqV0X1M1vjti0ubMOInt","service":"spop","name":"Over and Over","artist":"Madonna","album":"Like a Virgin","type":"song","duration":252,"albumart":"https://i.scdn.co/image/ab67616d0000b27399d424b0873a9a714279a9f3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Exploding uri spotify:track:0S9EixwOfXC0LyILi8kVFh in service spop Jan 10 00:32:10 volumio-rpi volumio[1125]: SPOTIFY: EXPLODING URI:spotify:track:0S9EixwOfXC0LyILi8kVFh Jan 10 00:32:10 volumio-rpi volumio[1125]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1S14j6I0RrdQoxrm7zZNHL","service":"spop","name":"Love Don't Live Here Anymore","artist":"Madonna","album":"Like a Virgin","type":"song","duration":290,"albumart":"https://i.scdn.co/image/ab67616d0000b27399d424b0873a9a714279a9f3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 10 00:32:10 volumio-rpi volumio[1125]: info: Exploding uri spotify:track:19gLqMCui3hxPDTKTEoELa in service spop Jan 10 00:32:10 volumio-rpi volumio[1125]: SPOTIFY: EXPLODING URI:spotify:track:19gLqMCui3hxPDTKTEoELa Jan 10 00:32:11 volumio-rpi volumio[1125]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1Fhx9C87IjEAtWI9FF0IzF","service":"spop","name":"Dress You Up","artist":"Madonna","album":"Like a Virgin","type":"song","duration":241,"albumart":"https://i.scdn.co/image/ab67616d0000b27399d424b0873a9a714279a9f3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 10 00:32:11 volumio-rpi volumio[1125]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:36IHTITiDnlpQWUacWWZpB","service":"spop","name":"Shoo-Bee-Doo","artist":"Madonna","album":"Like a Virgin","type":"song","duration":317,"albumart":"https://i.scdn.co/image/ab67616d0000b27399d424b0873a9a714279a9f3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 10 00:32:11 volumio-rpi volumio[1125]: info: Exploding uri spotify:track:17WvhmXF06yquUwZjtjHsc in service spop Jan 10 00:32:11 volumio-rpi volumio[1125]: SPOTIFY: EXPLODING URI:spotify:track:17WvhmXF06yquUwZjtjHsc Jan 10 00:32:11 volumio-rpi volumio[1125]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0S9EixwOfXC0LyILi8kVFh","service":"spop","name":"Pretender","artist":"Madonna","album":"Like a Virgin","type":"song","duration":270,"albumart":"https://i.scdn.co/image/ab67616d0000b27399d424b0873a9a714279a9f3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 10 00:32:11 volumio-rpi volumio[1125]: info: Exploding uri spotify:track:4vle25yO4Rf7AYkWtzSfAS in service spop Jan 10 00:32:11 volumio-rpi volumio[1125]: SPOTIFY: EXPLODING URI:spotify:track:4vle25yO4Rf7AYkWtzSfAS Jan 10 00:32:11 volumio-rpi volumio[1125]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:19gLqMCui3hxPDTKTEoELa","service":"spop","name":"Stay","artist":"Madonna","album":"Like a Virgin","type":"song","duration":246,"albumart":"https://i.scdn.co/image/ab67616d0000b27399d424b0873a9a714279a9f3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 10 00:32:11 volumio-rpi volumio[1125]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:17WvhmXF06yquUwZjtjHsc","service":"spop","name":"Like a Virgin - Extended Dance Remix","artist":"Madonna","album":"Like a Virgin","type":"song","duration":369,"albumart":"https://i.scdn.co/image/ab67616d0000b27399d424b0873a9a714279a9f3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 10 00:32:11 volumio-rpi volumio[1125]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4vle25yO4Rf7AYkWtzSfAS","service":"spop","name":"Material Girl - Extended Dance Remix","artist":"Madonna","album":"Like a Virgin","type":"song","duration":369,"albumart":"https://i.scdn.co/image/ab67616d0000b27399d424b0873a9a714279a9f3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 10 00:32:13 volumio-rpi systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 158. Jan 10 00:32:13 volumio-rpi systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 10 00:32:13 volumio-rpi systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 10 00:32:13 volumio-rpi upmpdcli[6488]: Could not open config: /tmp/upmpdcli.conf Jan 10 00:32:13 volumio-rpi systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 10 00:32:13 volumio-rpi systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 10 00:32:20 volumio-rpi go-librespot[1520]: time="2026-01-10T00:32:20+01:00" level=debug msg="fetched chunk 8/27, size: 524288" uri="spotify:track:1z3ugFmUKoCzGsI6jdY4Ci" Jan 10 00:32:25 volumio-rpi go-librespot[1520]: time="2026-01-10T00:32:25+01:00" level=trace msg="sent dealer ping" Jan 10 00:32:25 volumio-rpi go-librespot[1520]: time="2026-01-10T00:32:25+01:00" level=trace msg="received dealer pong" Jan 10 00:32:28 volumio-rpi systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 159. Jan 10 00:32:28 volumio-rpi systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 10 00:32:28 volumio-rpi systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 10 00:32:28 volumio-rpi upmpdcli[6520]: Could not open config: /tmp/upmpdcli.conf Jan 10 00:32:28 volumio-rpi systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 10 00:32:28 volumio-rpi systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 10 00:32:29 volumio-rpi volumio[1125]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jan 10 00:32:29 volumio-rpi volumio[1125]: info: In handleBrowseUri, curUri=spotify:artist:13veHv7qJjiYsLBaO95jBx Jan 10 00:32:30 volumio-rpi volumio[1125]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 10 00:32:30 volumio-rpi volumio[1125]: TypeError: Cannot read properties of undefined (reading 'url') Jan 10 00:32:30 volumio-rpi volumio[1125]: at /data/plugins/music_service/spop/index.js:2446:60 Jan 10 00:32:30 volumio-rpi volumio[1125]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Jan 10 00:32:30 volumio-rpi volumio[1125]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 10 00:32:31 volumio-rpi sudo[6535]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-10 00:31' Jan 10 00:32:31 volumio-rpi sudo[6535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"