Feb 11 20:36:00 volumio go-librespot[1591]: time="2026-02-11T20:36:00-07:00" level=debug msg="fetched first chunk of 9, total size is 4274112 bytes" uri="spotify:track:1P6JOqWxGIOrqZRGYR3p05" Feb 11 20:36:00 volumio go-librespot[1591]: time="2026-02-11T20:36:00-07:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames, PCM format = FLOAT_LE" Feb 11 20:36:00 volumio go-librespot[1591]: time="2026-02-11T20:36:00-07:00" level=info msg="loaded track \"Du bist mein Engel auf Erden - Radio Version\" (paused: false, position: 0ms, duration: 220826ms, prefetched: false)" uri="spotify:track:1P6JOqWxGIOrqZRGYR3p05" Feb 11 20:36:00 volumio go-librespot[1591]: time="2026-02-11T20:36:00-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 11 20:36:00 volumio go-librespot[1591]: time="2026-02-11T20:36:00-07:00" level=trace msg="scheduling prefetch in 191s" Feb 11 20:36:00 volumio go-librespot[1591]: time="2026-02-11T20:36:00-07:00" level=trace msg="emitting websocket event: metadata" Feb 11 20:36:00 volumio volumio[1213]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1P6JOqWxGIOrqZRGYR3p05","name":"Du bist mein Engel auf Erden - Radio Version","artist_names":["Silvio Samoni"],"album_name":"Irgendwann","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0249d131c4a10df2f748035a44","position":0,"duration":220826,"release_date":"year:2016 month:10 day:28","track_number":7,"disc_number":1}} Feb 11 20:36:00 volumio go-librespot[1591]: time="2026-02-11T20:36:00-07:00" level=debug msg="fetched chunk 2/8, size: 524288" uri="spotify:track:1P6JOqWxGIOrqZRGYR3p05" Feb 11 20:36:00 volumio go-librespot[1591]: time="2026-02-11T20:36:00-07:00" level=debug msg="fetched chunk 1/8, size: 524288" uri="spotify:track:1P6JOqWxGIOrqZRGYR3p05" Feb 11 20:36:01 volumio go-librespot[1591]: time="2026-02-11T20:36:01-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 11 20:36:01 volumio go-librespot[1591]: time="2026-02-11T20:36:01-07:00" level=trace msg="emitting websocket event: paused" Feb 11 20:36:01 volumio volumio[1213]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1P6JOqWxGIOrqZRGYR3p05","uri":"spotify:track:1P6JOqWxGIOrqZRGYR3p05","play_origin":"go-librespot"}} Feb 11 20:36:01 volumio volumio[1213]: SPOTIFY: PUSH STATE SPOTIFY Feb 11 20:36:01 volumio volumio[1213]: SPOTIFY: {"status":"pause","service":"spop","title":"Du bist mein Engel auf Erden - Radio Version","artist":"Silvio Samoni","album":"Irgendwann","albumart":"https://i.scdn.co/image/ab67616d00001e0249d131c4a10df2f748035a44","uri":"spotify:track:1P6JOqWxGIOrqZRGYR3p05","trackType":"spotify","seek":0,"duration":220,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 11 20:36:01 volumio volumio[1213]: info: CoreCommandRouter::servicePushState Feb 11 20:36:01 volumio volumio[1213]: info: CorePlayQueue::getTrack 32 Feb 11 20:36:01 volumio volumio[1213]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Du bist mein Engel auf Erden - Radio Version","artist":"Silvio Samoni","album":"Irgendwann","albumart":"https://i.scdn.co/image/ab67616d00001e0249d131c4a10df2f748035a44","uri":"spotify:track:1P6JOqWxGIOrqZRGYR3p05","trackType":"spotify","seek":0,"duration":220,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 11 20:36:01 volumio volumio[1213]: verbose: CURRENT POSITION 32 Feb 11 20:36:01 volumio volumio[1213]: info: CoreStateMachine::syncState stateService pause Feb 11 20:36:01 volumio volumio[1213]: info: CoreStateMachine::syncState currentStatus stop Feb 11 20:36:01 volumio volumio[1213]: info: CoreStateMachine::pushState Feb 11 20:36:01 volumio volumio[1213]: info: CorePlayQueue::getTrack 32 Feb 11 20:36:01 volumio volumio[1213]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 20:36:01 volumio volumio[1213]: info: CoreCommandRouter::volumioPushState Feb 11 20:36:01 volumio go-librespot[1591]: time="2026-02-11T20:36:01-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 11 20:36:01 volumio go-librespot[1591]: time="2026-02-11T20:36:01-07:00" level=trace msg="emitting websocket event: playing" Feb 11 20:36:01 volumio volumio[1213]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1P6JOqWxGIOrqZRGYR3p05","uri":"spotify:track:1P6JOqWxGIOrqZRGYR3p05","resume":false,"play_origin":"go-librespot"}} Feb 11 20:36:01 volumio volumio[1213]: SPOTIFY: PUSH STATE SPOTIFY Feb 11 20:36:01 volumio volumio[1213]: SPOTIFY: {"status":"play","service":"spop","title":"Du bist mein Engel auf Erden - Radio Version","artist":"Silvio Samoni","album":"Irgendwann","albumart":"https://i.scdn.co/image/ab67616d00001e0249d131c4a10df2f748035a44","uri":"spotify:track:1P6JOqWxGIOrqZRGYR3p05","trackType":"spotify","seek":0,"duration":220,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 11 20:36:01 volumio volumio[1213]: info: CoreCommandRouter::servicePushState Feb 11 20:36:01 volumio volumio[1213]: info: CorePlayQueue::getTrack 32 Feb 11 20:36:01 volumio volumio[1213]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Du bist mein Engel auf Erden - Radio Version","artist":"Silvio Samoni","album":"Irgendwann","albumart":"https://i.scdn.co/image/ab67616d00001e0249d131c4a10df2f748035a44","uri":"spotify:track:1P6JOqWxGIOrqZRGYR3p05","trackType":"spotify","seek":0,"duration":220,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 11 20:36:01 volumio volumio[1213]: verbose: CURRENT POSITION 32 Feb 11 20:36:01 volumio volumio[1213]: info: CoreStateMachine::syncState stateService play Feb 11 20:36:01 volumio volumio[1213]: info: CoreStateMachine::syncState currentStatus stop Feb 11 20:36:01 volumio go-librespot[1591]: time="2026-02-11T20:36:01-07:00" level=debug msg="fetched chunk 3/8, size: 524288" uri="spotify:track:1P6JOqWxGIOrqZRGYR3p05" Feb 11 20:36:01 volumio volumio[1213]: SPOTIFY: PUSH STATE SPOTIFY Feb 11 20:36:01 volumio volumio[1213]: SPOTIFY: {"status":"play","service":"spop","title":"Du bist mein Engel auf Erden - Radio Version","artist":"Silvio Samoni","album":"Irgendwann","albumart":"https://i.scdn.co/image/ab67616d00001e0249d131c4a10df2f748035a44","uri":"spotify:track:1P6JOqWxGIOrqZRGYR3p05","trackType":"spotify","seek":0,"duration":220,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 11 20:36:01 volumio volumio[1213]: info: CoreCommandRouter::servicePushState Feb 11 20:36:01 volumio volumio[1213]: info: CorePlayQueue::getTrack 32 Feb 11 20:36:01 volumio volumio[1213]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Du bist mein Engel auf Erden - Radio Version","artist":"Silvio Samoni","album":"Irgendwann","albumart":"https://i.scdn.co/image/ab67616d00001e0249d131c4a10df2f748035a44","uri":"spotify:track:1P6JOqWxGIOrqZRGYR3p05","trackType":"spotify","seek":0,"duration":220,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 11 20:36:01 volumio volumio[1213]: verbose: CURRENT POSITION 32 Feb 11 20:36:01 volumio volumio[1213]: info: CoreStateMachine::syncState stateService play Feb 11 20:36:01 volumio volumio[1213]: info: CoreStateMachine::syncState currentStatus play Feb 11 20:36:01 volumio volumio[1213]: info: Received an update from plugin. extracting info from payload Feb 11 20:36:01 volumio volumio[1213]: info: CoreStateMachine::pushState Feb 11 20:36:01 volumio volumio[1213]: info: CorePlayQueue::getTrack 32 Feb 11 20:36:01 volumio volumio[1213]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 20:36:01 volumio volumio[1213]: info: CoreCommandRouter::volumioPushState Feb 11 20:36:01 volumio volumio[1213]: info: CoreStateMachine::pushState Feb 11 20:36:01 volumio volumio[1213]: info: CorePlayQueue::getTrack 32 Feb 11 20:36:01 volumio volumio[1213]: info: CoreCommandRouter::volumioPushState Feb 11 20:36:04 volumio nmbd[1066]: [2026/02/11 20:36:04.325153, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 11 20:36:04 volumio nmbd[1066]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.8.184 for name WORKGROUP<1d>. Feb 11 20:36:04 volumio nmbd[1066]: This response was from IP 192.168.8.172, reporting an IP address of 192.168.8.172. Feb 11 20:36:16 volumio go-librespot[1591]: time="2026-02-11T20:36:16-07:00" level=trace msg="sent dealer ping" Feb 11 20:36:16 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Feb 11 20:36:16 volumio go-librespot[1591]: time="2026-02-11T20:36:16-07:00" level=trace msg="received dealer pong" Feb 11 20:36:20 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 11 20:36:20 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 11 20:36:20 volumio systemd[1]: setdatetime-helper.service: Consumed 1.811s CPU time. Feb 11 20:36:25 volumio go-librespot[1591]: time="2026-02-11T20:36:25-07:00" level=debug msg="fetched chunk 4/8, size: 524288" uri="spotify:track:1P6JOqWxGIOrqZRGYR3p05" Feb 11 20:36:29 volumio volumio[1213]: info: Preload queue cleared Feb 11 20:36:29 volumio volumio[1213]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 11 20:36:29 volumio volumio[1213]: info: CoreStateMachine::ClearQueue Feb 11 20:36:29 volumio volumio[1213]: info: CoreStateMachine::stop Feb 11 20:36:29 volumio volumio[1213]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 11 20:36:29 volumio volumio[1213]: info: CoreStateMachine::stPlaybackTimer Feb 11 20:36:29 volumio volumio[1213]: info: CoreStateMachine::updateTrackBlock Feb 11 20:36:29 volumio volumio[1213]: info: CorePlayQueue::getTrackBlock Feb 11 20:36:29 volumio volumio[1213]: info: CoreStateMachine::pushState Feb 11 20:36:29 volumio volumio[1213]: info: CorePlayQueue::getTrack 32 Feb 11 20:36:29 volumio volumio[1213]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 20:36:29 volumio volumio[1213]: info: CoreCommandRouter::volumioPushState Feb 11 20:36:29 volumio volumio[1213]: info: CoreStateMachine::serviceStop Feb 11 20:36:29 volumio volumio[1213]: info: CorePlayQueue::getTrack 32 Feb 11 20:36:29 volumio volumio[1213]: info: CoreCommandRouter::serviceStop Feb 11 20:36:29 volumio volumio[1213]: info: Spotify Stop Feb 11 20:36:29 volumio volumio[1213]: SPOTIFY: SPOTIFY STOP Feb 11 20:36:29 volumio volumio[1213]: SPOTIFY: {"status":"play","position":32,"title":"Du bist mein Engel auf Erden - Radio Version","artist":"Silvio Samoni","album":"Irgendwann","albumart":"https://i.scdn.co/image/ab67616d0000b27349d131c4a10df2f748035a44","uri":"spotify:track:1P6JOqWxGIOrqZRGYR3p05","trackType":"spotify","codec":"ogg","seek":0,"duration":220,"samplerate":"160 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":true,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Feb 11 20:36:29 volumio volumio[1213]: info: Sending Spotify command to local API: /player/pause Feb 11 20:36:29 volumio volumio[1213]: info: CorePlayQueue::clearPlayQueue Feb 11 20:36:29 volumio volumio[1213]: info: CorePlayQueue::saveQueue Feb 11 20:36:29 volumio volumio[1213]: info: CoreCommandRouter::volumioPushQueue Feb 11 20:36:29 volumio volumio[1213]: info: CoreStateMachine::addQueueItems Feb 11 20:36:29 volumio volumio[1213]: info: CorePlayQueue::addQueueItems Feb 11 20:36:29 volumio volumio[1213]: info: Preload queue cleared Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:61PE1FpvEUMjz3NBA116U7 Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:61PE1FpvEUMjz3NBA116U7 Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:4OUw5OehgURxzbnJRWS2c2 Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:4OUw5OehgURxzbnJRWS2c2 Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:4EBQQoWB73ibm5Bgnwm7hN Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:4EBQQoWB73ibm5Bgnwm7hN Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:7xHH2qIEsmrxqzmNfMYUdB Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:7xHH2qIEsmrxqzmNfMYUdB Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:4YnqPAn5RqmQdKaPvJOVaT Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:4YnqPAn5RqmQdKaPvJOVaT Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:7Gdp1RTWIKx3vMxWqoxvv5 Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:7Gdp1RTWIKx3vMxWqoxvv5 Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:5IEQwO1Ars45KEDQRuLNWb Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:5IEQwO1Ars45KEDQRuLNWb Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:51iFnSVbOHyeDQYVtxjyJ4 Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:51iFnSVbOHyeDQYVtxjyJ4 Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:26Igbw4XCE1FB5ariB3USP Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:26Igbw4XCE1FB5ariB3USP Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:0KwJI1C07xFhupWuE2fJd5 Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:0KwJI1C07xFhupWuE2fJd5 Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:25rfZrwhCqdc38Hym6K26W Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:25rfZrwhCqdc38Hym6K26W Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:4cl6aNgORQ65dZXPl5dKeH Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:4cl6aNgORQ65dZXPl5dKeH Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:6A4KPISBo2nt7CxMZkjpNm Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:6A4KPISBo2nt7CxMZkjpNm Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:5eaBf8llLsSVcRWF0p3m3a Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:5eaBf8llLsSVcRWF0p3m3a Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:2TJbCxKgiFWgeKZJSa5RhY Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:2TJbCxKgiFWgeKZJSa5RhY Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:0RcQh6CSHaRXKwOQTOlD62 Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:0RcQh6CSHaRXKwOQTOlD62 Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:27eZRmmrrKJ6sOXSOFEPQG Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:27eZRmmrrKJ6sOXSOFEPQG Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:6kPk7kYSpxQ70osHCENpSb Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:6kPk7kYSpxQ70osHCENpSb Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:5bXSfbR3cGPchGg9xe4ztx Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:5bXSfbR3cGPchGg9xe4ztx Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:4L7g9wAdiCl0brBF4GPuNP Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:4L7g9wAdiCl0brBF4GPuNP Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:57FSvXMf18XiHZRR5ghwsE Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:57FSvXMf18XiHZRR5ghwsE Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:1pOaBwOH7rEK84De9dRlsM Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:1pOaBwOH7rEK84De9dRlsM Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:3n38EpC5rqgIf9WhoveP2o Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:3n38EpC5rqgIf9WhoveP2o Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:0HBjqFGFv6U682YG8fxkmh Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:0HBjqFGFv6U682YG8fxkmh Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:0f6vfyc3qGayES8BPX2pJb Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:0f6vfyc3qGayES8BPX2pJb Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:5nbl1aSV05axW6ZriTcypw Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:5nbl1aSV05axW6ZriTcypw Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:5mssZk4C9zg4bGEgasoh74 Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:5mssZk4C9zg4bGEgasoh74 Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:6OQBLoJyJpz1DPb3cuegG8 Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:6OQBLoJyJpz1DPb3cuegG8 Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:0Q242q2wYr5YR69WXaW3bm Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:0Q242q2wYr5YR69WXaW3bm Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:74wEAfslQ2CGEYzWI3YY5O Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:74wEAfslQ2CGEYzWI3YY5O Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:3soRtJNYKSS9C8woWBypFJ Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:3soRtJNYKSS9C8woWBypFJ Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:36OeXrSFaSshoPJxToWeMM Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:36OeXrSFaSshoPJxToWeMM Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:1P6JOqWxGIOrqZRGYR3p05 Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:1P6JOqWxGIOrqZRGYR3p05 Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:2ZGiJ7tw71gdBHmfx7gUK2 Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:2ZGiJ7tw71gdBHmfx7gUK2 Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:2z2MlsFK0Xd0wgf4qXxNR3 Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:2z2MlsFK0Xd0wgf4qXxNR3 Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:2U1zfcfgHQaGu1S0lSCtrM Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:2U1zfcfgHQaGu1S0lSCtrM Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:1tTSMCI49XNSz2QkWLMoW3 Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:1tTSMCI49XNSz2QkWLMoW3 Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:5W83YniU78XUA3pEIlkszh Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:5W83YniU78XUA3pEIlkszh Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:5KA8DpcCOaENdEcSr9IoZG Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:5KA8DpcCOaENdEcSr9IoZG Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:5ELlzz63dkWjuvMTCctJ9F Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:5ELlzz63dkWjuvMTCctJ9F Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:63qzf9phlXnyG3Yv5iiLYf Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:63qzf9phlXnyG3Yv5iiLYf Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:27ws7OAeLAnjg0P3uIXXuk Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:27ws7OAeLAnjg0P3uIXXuk Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:5j3D9exiCQFH5cUeLkpbUZ Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:5j3D9exiCQFH5cUeLkpbUZ Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:0mg5Vo5GhKxPC6EY8M85dS Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:0mg5Vo5GhKxPC6EY8M85dS Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:6a2haLXzUn5jwUsWJdfcyu Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:6a2haLXzUn5jwUsWJdfcyu Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:0ip3OenCpu72ahzH44y4VO Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:0ip3OenCpu72ahzH44y4VO Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:5W1iYQiV7rsA69TYcIGk9j Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:5W1iYQiV7rsA69TYcIGk9j Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:7LJg5CQaqf5olJr8NEWZar Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:7LJg5CQaqf5olJr8NEWZar Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:4Y8rJHbKA0lnMeSQ0DrST4 Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:4Y8rJHbKA0lnMeSQ0DrST4 Feb 11 20:36:29 volumio volumio[1213]: info: Adding Item to queue: spotify:track:2JlU7w8yqYzFtLqnzzFtRy Feb 11 20:36:29 volumio volumio[1213]: info: Using cached record of: spotify:track:2JlU7w8yqYzFtLqnzzFtRy Feb 11 20:36:29 volumio volumio[1213]: info: CoreCommandRouter::volumioPushQueue Feb 11 20:36:29 volumio volumio[1213]: info: CorePlayQueue::saveQueue Feb 11 20:36:29 volumio volumio[1213]: info: CoreStateMachine::updateTrackBlock Feb 11 20:36:29 volumio volumio[1213]: info: CorePlayQueue::getTrackBlock Feb 11 20:36:29 volumio volumio[1213]: info: CoreCommandRouter::volumioPlay Feb 11 20:36:29 volumio volumio[1213]: info: CoreStateMachine::play index 49 Feb 11 20:36:29 volumio volumio[1213]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 11 20:36:29 volumio volumio[1213]: info: CoreStateMachine::stop Feb 11 20:36:29 volumio volumio[1213]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 11 20:36:29 volumio volumio[1213]: info: CoreStateMachine::play index undefined Feb 11 20:36:29 volumio volumio[1213]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 11 20:36:29 volumio volumio[1213]: info: CorePlayQueue::getTrack 49 Feb 11 20:36:29 volumio volumio[1213]: info: CoreStateMachine::startPlaybackTimer Feb 11 20:36:29 volumio volumio[1213]: info: CorePlayQueue::getTrack 49 Feb 11 20:36:29 volumio volumio[1213]: info: [1770867389238] ControllerSpotify::clearAddPlayTrack Feb 11 20:36:29 volumio volumio[1213]: info: Sending Spotify command with payload to local API: /player/play Feb 11 20:36:29 volumio go-librespot[1591]: time="2026-02-11T20:36:29-07:00" level=debug msg="pause track at 29059ms" Feb 11 20:36:29 volumio go-librespot[1591]: time="2026-02-11T20:36:29-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 11 20:36:30 volumio go-librespot[1591]: time="2026-02-11T20:36:30-07:00" level=debug msg="resolved context of track" uri="spotify:track:2JlU7w8yqYzFtLqnzzFtRy" Feb 11 20:36:30 volumio go-librespot[1591]: time="2026-02-11T20:36:30-07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:2JlU7w8yqYzFtLqnzzFtRy" Feb 11 20:36:30 volumio go-librespot[1591]: time="2026-02-11T20:36:30-07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:2JlU7w8yqYzFtLqnzzFtRy" Feb 11 20:36:31 volumio go-librespot[1591]: time="2026-02-11T20:36:31-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 11 20:36:31 volumio go-librespot[1591]: time="2026-02-11T20:36:31-07:00" level=trace msg="emitting websocket event: will_play" Feb 11 20:36:31 volumio volumio[1213]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:2JlU7w8yqYzFtLqnzzFtRy","uri":"spotify:track:2JlU7w8yqYzFtLqnzzFtRy","play_origin":"go-librespot"}} Feb 11 20:36:31 volumio go-librespot[1591]: time="2026-02-11T20:36:31-07:00" level=debug msg="selected format OGG_VORBIS_160 (626afd47e74095783145d8ec779cf2ccff5f8e84)" uri="spotify:track:2JlU7w8yqYzFtLqnzzFtRy" Feb 11 20:36:31 volumio go-librespot[1591]: time="2026-02-11T20:36:31-07:00" level=debug msg="requested aes key for file 626afd47e74095783145d8ec779cf2ccff5f8e84, gid: 2JlU7w8yqYzFtLqnzzFtRy" Feb 11 20:36:31 volumio go-librespot[1591]: time="2026-02-11T20:36:31-07:00" level=trace msg="found 2 cdn urls" uri="spotify:track:2JlU7w8yqYzFtLqnzzFtRy" Feb 11 20:36:31 volumio go-librespot[1591]: time="2026-02-11T20:36:31-07:00" level=debug msg="fetched first chunk of 8, total size is 4011380 bytes" uri="spotify:track:2JlU7w8yqYzFtLqnzzFtRy" Feb 11 20:36:32 volumio go-librespot[1591]: time="2026-02-11T20:36:32-07:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames, PCM format = FLOAT_LE" Feb 11 20:36:32 volumio go-librespot[1591]: time="2026-02-11T20:36:32-07:00" level=info msg="loaded track \"Forever I Love You\" (paused: false, position: 0ms, duration: 200084ms, prefetched: false)" uri="spotify:track:2JlU7w8yqYzFtLqnzzFtRy" Feb 11 20:36:32 volumio go-librespot[1591]: time="2026-02-11T20:36:32-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 11 20:36:32 volumio go-librespot[1591]: time="2026-02-11T20:36:32-07:00" level=trace msg="scheduling prefetch in 170s" Feb 11 20:36:32 volumio go-librespot[1591]: time="2026-02-11T20:36:32-07:00" level=trace msg="emitting websocket event: metadata" Feb 11 20:36:32 volumio volumio[1213]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2JlU7w8yqYzFtLqnzzFtRy","name":"Forever I Love You","artist_names":["Stixi \u0026 Sonja"],"album_name":"Pure Liebe","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02d60b8f5e4f04c5fa0033d191","position":0,"duration":200084,"release_date":"year:2011","track_number":1,"disc_number":1}} Feb 11 20:36:32 volumio go-librespot[1591]: time="2026-02-11T20:36:32-07:00" level=debug msg="fetched chunk 2/7, size: 524288" uri="spotify:track:2JlU7w8yqYzFtLqnzzFtRy" Feb 11 20:36:32 volumio go-librespot[1591]: time="2026-02-11T20:36:32-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 11 20:36:32 volumio go-librespot[1591]: time="2026-02-11T20:36:32-07:00" level=trace msg="emitting websocket event: paused" Feb 11 20:36:32 volumio volumio[1213]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:2JlU7w8yqYzFtLqnzzFtRy","uri":"spotify:track:2JlU7w8yqYzFtLqnzzFtRy","play_origin":"go-librespot"}} Feb 11 20:36:32 volumio volumio[1213]: SPOTIFY: PUSH STATE SPOTIFY Feb 11 20:36:32 volumio volumio[1213]: SPOTIFY: {"status":"pause","service":"spop","title":"Forever I Love You","artist":"Stixi & Sonja","album":"Pure Liebe","albumart":"https://i.scdn.co/image/ab67616d00001e02d60b8f5e4f04c5fa0033d191","uri":"spotify:track:2JlU7w8yqYzFtLqnzzFtRy","trackType":"spotify","seek":1000,"duration":200,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 11 20:36:32 volumio volumio[1213]: info: CoreCommandRouter::servicePushState Feb 11 20:36:32 volumio volumio[1213]: info: CorePlayQueue::getTrack 49 Feb 11 20:36:32 volumio volumio[1213]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Forever I Love You","artist":"Stixi & Sonja","album":"Pure Liebe","albumart":"https://i.scdn.co/image/ab67616d00001e02d60b8f5e4f04c5fa0033d191","uri":"spotify:track:2JlU7w8yqYzFtLqnzzFtRy","trackType":"spotify","seek":1000,"duration":200,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 11 20:36:32 volumio volumio[1213]: verbose: CURRENT POSITION 49 Feb 11 20:36:32 volumio volumio[1213]: info: CoreStateMachine::syncState stateService pause Feb 11 20:36:32 volumio volumio[1213]: info: CoreStateMachine::syncState currentStatus stop Feb 11 20:36:32 volumio volumio[1213]: info: CoreStateMachine::pushState Feb 11 20:36:32 volumio volumio[1213]: info: CorePlayQueue::getTrack 49 Feb 11 20:36:32 volumio volumio[1213]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 20:36:32 volumio volumio[1213]: info: CoreCommandRouter::volumioPushState Feb 11 20:36:32 volumio go-librespot[1591]: time="2026-02-11T20:36:32-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 11 20:36:32 volumio go-librespot[1591]: time="2026-02-11T20:36:32-07:00" level=trace msg="emitting websocket event: playing" Feb 11 20:36:32 volumio volumio[1213]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:2JlU7w8yqYzFtLqnzzFtRy","uri":"spotify:track:2JlU7w8yqYzFtLqnzzFtRy","resume":false,"play_origin":"go-librespot"}} Feb 11 20:36:32 volumio volumio[1213]: SPOTIFY: PUSH STATE SPOTIFY Feb 11 20:36:32 volumio volumio[1213]: SPOTIFY: {"status":"play","service":"spop","title":"Forever I Love You","artist":"Stixi & Sonja","album":"Pure Liebe","albumart":"https://i.scdn.co/image/ab67616d00001e02d60b8f5e4f04c5fa0033d191","uri":"spotify:track:2JlU7w8yqYzFtLqnzzFtRy","trackType":"spotify","seek":1000,"duration":200,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 11 20:36:32 volumio volumio[1213]: info: CoreCommandRouter::servicePushState Feb 11 20:36:32 volumio volumio[1213]: info: CorePlayQueue::getTrack 49 Feb 11 20:36:32 volumio volumio[1213]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Forever I Love You","artist":"Stixi & Sonja","album":"Pure Liebe","albumart":"https://i.scdn.co/image/ab67616d00001e02d60b8f5e4f04c5fa0033d191","uri":"spotify:track:2JlU7w8yqYzFtLqnzzFtRy","trackType":"spotify","seek":1000,"duration":200,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 11 20:36:32 volumio volumio[1213]: verbose: CURRENT POSITION 49 Feb 11 20:36:32 volumio volumio[1213]: info: CoreStateMachine::syncState stateService play Feb 11 20:36:32 volumio volumio[1213]: info: CoreStateMachine::syncState currentStatus stop Feb 11 20:36:32 volumio go-librespot[1591]: time="2026-02-11T20:36:32-07:00" level=debug msg="fetched chunk 1/7, size: 524288" uri="spotify:track:2JlU7w8yqYzFtLqnzzFtRy" Feb 11 20:36:32 volumio go-librespot[1591]: time="2026-02-11T20:36:32-07:00" level=debug msg="fetched chunk 3/7, size: 524288" uri="spotify:track:2JlU7w8yqYzFtLqnzzFtRy" Feb 11 20:36:32 volumio volumio[1213]: SPOTIFY: PUSH STATE SPOTIFY Feb 11 20:36:32 volumio volumio[1213]: SPOTIFY: {"status":"play","service":"spop","title":"Forever I Love You","artist":"Stixi & Sonja","album":"Pure Liebe","albumart":"https://i.scdn.co/image/ab67616d00001e02d60b8f5e4f04c5fa0033d191","uri":"spotify:track:2JlU7w8yqYzFtLqnzzFtRy","trackType":"spotify","seek":1000,"duration":200,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 11 20:36:32 volumio volumio[1213]: info: CoreCommandRouter::servicePushState Feb 11 20:36:32 volumio volumio[1213]: info: CorePlayQueue::getTrack 49 Feb 11 20:36:32 volumio volumio[1213]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Forever I Love You","artist":"Stixi & Sonja","album":"Pure Liebe","albumart":"https://i.scdn.co/image/ab67616d00001e02d60b8f5e4f04c5fa0033d191","uri":"spotify:track:2JlU7w8yqYzFtLqnzzFtRy","trackType":"spotify","seek":1000,"duration":200,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 11 20:36:32 volumio volumio[1213]: verbose: CURRENT POSITION 49 Feb 11 20:36:32 volumio volumio[1213]: info: CoreStateMachine::syncState stateService play Feb 11 20:36:32 volumio volumio[1213]: info: CoreStateMachine::syncState currentStatus play Feb 11 20:36:32 volumio volumio[1213]: info: Received an update from plugin. extracting info from payload Feb 11 20:36:32 volumio volumio[1213]: info: CoreStateMachine::pushState Feb 11 20:36:32 volumio volumio[1213]: info: CorePlayQueue::getTrack 49 Feb 11 20:36:32 volumio volumio[1213]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 20:36:32 volumio volumio[1213]: info: CoreCommandRouter::volumioPushState Feb 11 20:36:32 volumio volumio[1213]: info: CoreStateMachine::pushState Feb 11 20:36:32 volumio volumio[1213]: info: CorePlayQueue::getTrack 49 Feb 11 20:36:32 volumio volumio[1213]: info: CoreCommandRouter::volumioPushState Feb 11 20:36:38 volumio volumio[1213]: Searching plugin music_service/spop Feb 11 20:36:38 volumio volumio[1213]: info: CoreCommandRouter::executeOnPlugin: spop , search Feb 11 20:36:40 volumio volumio[1213]: info: All search sources collected, pushing search results Feb 11 20:36:40 volumio volumio[1213]: Searching plugin music_service/spop Feb 11 20:36:40 volumio volumio[1213]: info: CoreCommandRouter::executeOnPlugin: spop , search Feb 11 20:36:40 volumio volumio[1213]: Searching plugin music_service/spop Feb 11 20:36:40 volumio volumio[1213]: info: CoreCommandRouter::executeOnPlugin: spop , search Feb 11 20:36:41 volumio volumio[1213]: info: All search sources collected, pushing search results Feb 11 20:36:41 volumio volumio[1213]: info: All search sources collected, pushing search results Feb 11 20:36:43 volumio volumio[1213]: Searching plugin music_service/spop Feb 11 20:36:43 volumio volumio[1213]: info: CoreCommandRouter::executeOnPlugin: spop , search Feb 11 20:36:44 volumio volumio[1213]: info: All search sources collected, pushing search results Feb 11 20:36:46 volumio go-librespot[1591]: time="2026-02-11T20:36:46-07:00" level=trace msg="sent dealer ping" Feb 11 20:36:46 volumio go-librespot[1591]: time="2026-02-11T20:36:46-07:00" level=trace msg="received dealer pong" Feb 11 20:36:59 volumio go-librespot[1591]: time="2026-02-11T20:36:59-07:00" level=debug msg="fetched chunk 4/7, size: 524288" uri="spotify:track:2JlU7w8yqYzFtLqnzzFtRy" Feb 11 20:36:59 volumio volumio[1213]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Feb 11 20:36:59 volumio volumio[1213]: info: In handleBrowseUri, curUri=spotify:artist:2gMamthjRs9Y8sTScxSROS Feb 11 20:37:01 volumio volumio[1213]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 20:37:01 volumio volumio[1213]: TypeError: Cannot read properties of undefined (reading 'url') Feb 11 20:37:01 volumio volumio[1213]: at /data/plugins/music_service/spop/index.js:2449:60 Feb 11 20:37:01 volumio volumio[1213]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Feb 11 20:37:01 volumio volumio[1213]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 20:37:02 volumio sudo[23589]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 20:36' Feb 11 20:37:02 volumio sudo[23589]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"