Aug 29 12:57:10 volumio go-librespot[24648]: time="2026-08-29T12:57:10+10:00" level=debug msg="fetched chunk 9/16, size: 524288" uri="spotify:track:6OB05ZAAWBEk3bKuioKMT5" Aug 29 12:57:19 volumio go-librespot[24648]: time="2026-08-29T12:57:19+10:00" level=trace msg="sent dealer ping" Aug 29 12:57:19 volumio go-librespot[24648]: time="2026-08-29T12:57:19+10:00" level=trace msg="received dealer pong" Aug 29 12:57:22 volumio go-librespot[24648]: time="2026-08-29T12:57:22+10:00" level=debug msg="fetched chunk 10/16, size: 524288" uri="spotify:track:6OB05ZAAWBEk3bKuioKMT5" Aug 29 12:57:34 volumio go-librespot[24648]: time="2026-08-29T12:57:34+10:00" level=debug msg="fetched chunk 11/16, size: 524288" uri="spotify:track:6OB05ZAAWBEk3bKuioKMT5" Aug 29 12:57:45 volumio go-librespot[24648]: time="2026-08-29T12:57:45+10:00" level=debug msg="fetched chunk 12/16, size: 524288" uri="spotify:track:6OB05ZAAWBEk3bKuioKMT5" Aug 29 12:57:49 volumio go-librespot[24648]: time="2026-08-29T12:57:49+10:00" level=trace msg="received accesspoint ping" Aug 29 12:57:49 volumio go-librespot[24648]: time="2026-08-29T12:57:49+10:00" level=trace msg="received accesspoint pong ack" Aug 29 12:57:49 volumio go-librespot[24648]: time="2026-08-29T12:57:49+10:00" level=trace msg="sent dealer ping" Aug 29 12:57:49 volumio go-librespot[24648]: time="2026-08-29T12:57:49+10:00" level=trace msg="received dealer pong" Aug 29 12:57:56 volumio go-librespot[24648]: time="2026-08-29T12:57:56+10:00" level=debug msg="fetched chunk 13/16, size: 524288" uri="spotify:track:6OB05ZAAWBEk3bKuioKMT5" Aug 29 12:58:03 volumio volumio[1240]: info: CoreCommandRouter::volumioNext Aug 29 12:58:03 volumio volumio[1240]: info: CoreStateMachine::next Aug 29 12:58:03 volumio volumio[1240]: info: CoreStateMachine::stop Aug 29 12:58:03 volumio volumio[1240]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 12:58:03 volumio volumio[1240]: info: CoreStateMachine::stPlaybackTimer Aug 29 12:58:03 volumio volumio[1240]: info: CoreStateMachine::updateTrackBlock Aug 29 12:58:03 volumio volumio[1240]: info: CorePlayQueue::getTrackBlock Aug 29 12:58:03 volumio volumio[1240]: info: CoreStateMachine::pushState Aug 29 12:58:03 volumio volumio[1240]: info: CorePlayQueue::getTrack 7 Aug 29 12:58:03 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 12:58:03 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState Aug 29 12:58:03 volumio volumio[1240]: info: CoreStateMachine::serviceStop Aug 29 12:58:03 volumio volumio[1240]: info: CorePlayQueue::getTrack 7 Aug 29 12:58:03 volumio volumio[1240]: info: CoreCommandRouter::serviceStop Aug 29 12:58:03 volumio volumio[1240]: info: Spotify Stop Aug 29 12:58:03 volumio volumio[1240]: info: Sending Spotify command to local API: /player/pause Aug 29 12:58:03 volumio volumio[1240]: info: CoreStateMachine::play index undefined Aug 29 12:58:03 volumio volumio[1240]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 12:58:03 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:03 volumio volumio[1240]: info: CoreStateMachine::startPlaybackTimer Aug 29 12:58:03 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:03 volumio volumio[1240]: info: [1787972283691] ControllerSpotify::clearAddPlayTrack Aug 29 12:58:03 volumio volumio[1240]: info: Sending Spotify command with payload to local API: /player/play Aug 29 12:58:03 volumio volumio[1240]: info: CoreStateMachine::updateTrackBlock Aug 29 12:58:03 volumio volumio[1240]: info: CorePlayQueue::getTrackBlock Aug 29 12:58:03 volumio go-librespot[24648]: time="2026-08-29T12:58:03+10:00" level=debug msg="pause track at 130663ms" Aug 29 12:58:03 volumio volumio[1240]: info: touch_display: Setting screensaver timeout to 120 seconds. Aug 29 12:58:03 volumio go-librespot[24648]: time="2026-08-29T12:58:03+10:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 12:58:04 volumio go-librespot[24648]: time="2026-08-29T12:58:04+10:00" level=debug msg="resolved context of track" uri="spotify:track:77svvOHCRb1GljfNLeuK91" Aug 29 12:58:04 volumio go-librespot[24648]: time="2026-08-29T12:58:04+10:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:77svvOHCRb1GljfNLeuK91" Aug 29 12:58:04 volumio go-librespot[24648]: time="2026-08-29T12:58:04+10:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:77svvOHCRb1GljfNLeuK91" Aug 29 12:58:04 volumio go-librespot[24648]: time="2026-08-29T12:58:04+10:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 12:58:04 volumio go-librespot[24648]: time="2026-08-29T12:58:04+10:00" level=trace msg="emitting websocket event: will_play" Aug 29 12:58:04 volumio go-librespot[24648]: time="2026-08-29T12:58:04+10:00" level=debug msg="selected format OGG_VORBIS_320 (ea62d7f8e3bd3bc5b689a6ad12998a3516d78656)" uri="spotify:track:77svvOHCRb1GljfNLeuK91" Aug 29 12:58:04 volumio go-librespot[24648]: time="2026-08-29T12:58:04+10:00" level=debug msg="requested aes key for file ea62d7f8e3bd3bc5b689a6ad12998a3516d78656, gid: 77svvOHCRb1GljfNLeuK91" Aug 29 12:58:04 volumio go-librespot[24648]: time="2026-08-29T12:58:04+10:00" level=trace msg="found 2 cdn urls" uri="spotify:track:77svvOHCRb1GljfNLeuK91" Aug 29 12:58:05 volumio go-librespot[24648]: time="2026-08-29T12:58:05+10:00" level=debug msg="fetched first chunk of 26, total size is 13403924 bytes" uri="spotify:track:77svvOHCRb1GljfNLeuK91" Aug 29 12:58:05 volumio go-librespot[24648]: time="2026-08-29T12:58:05+10: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" Aug 29 12:58:05 volumio go-librespot[24648]: time="2026-08-29T12:58:05+10:00" level=info msg="loaded track \"Washing by Hand\" (paused: false, position: 0ms, duration: 330400ms, prefetched: false)" uri="spotify:track:77svvOHCRb1GljfNLeuK91" Aug 29 12:58:05 volumio go-librespot[24648]: time="2026-08-29T12:58:05+10:00" level=debug msg="fetched chunk 2/25, size: 524288" uri="spotify:track:77svvOHCRb1GljfNLeuK91" Aug 29 12:58:05 volumio go-librespot[24648]: time="2026-08-29T12:58:05+10:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 12:58:05 volumio go-librespot[24648]: time="2026-08-29T12:58:05+10:00" level=debug msg="fetched chunk 3/25, size: 524288" uri="spotify:track:77svvOHCRb1GljfNLeuK91" Aug 29 12:58:05 volumio go-librespot[24648]: time="2026-08-29T12:58:05+10:00" level=trace msg="scheduling prefetch in 300s" Aug 29 12:58:05 volumio go-librespot[24648]: time="2026-08-29T12:58:05+10:00" level=trace msg="emitting websocket event: metadata" Aug 29 12:58:05 volumio go-librespot[24648]: time="2026-08-29T12:58:05+10:00" level=debug msg="fetched chunk 1/25, size: 524288" uri="spotify:track:77svvOHCRb1GljfNLeuK91" Aug 29 12:58:05 volumio go-librespot[24648]: time="2026-08-29T12:58:05+10:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 12:58:05 volumio go-librespot[24648]: time="2026-08-29T12:58:05+10:00" level=trace msg="emitting websocket event: paused" Aug 29 12:58:05 volumio volumio[1240]: info: CoreCommandRouter::servicePushState Aug 29 12:58:05 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:05 volumio volumio[1240]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Washing by Hand","artist":"Jackie Leven","album":"Creatures of Light & Darkness","albumart":"https://i.scdn.co/image/ab67616d00001e0285405eab20a0fbc4fde0bc03","uri":"spotify:track:77svvOHCRb1GljfNLeuK91","trackType":"spotify","seek":0,"duration":330,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 12:58:05 volumio volumio[1240]: verbose: CURRENT POSITION 8 Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::syncState stateService pause Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::syncState currentStatus stop Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::pushState Aug 29 12:58:05 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:05 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 12:58:05 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState Aug 29 12:58:05 volumio volumio[1240]: info: CoreCommandRouter::servicePushState Aug 29 12:58:05 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:05 volumio volumio[1240]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Washing by Hand","artist":"Jackie Leven","album":"Creatures of Light & Darkness","albumart":"https://i.scdn.co/image/ab67616d00001e0285405eab20a0fbc4fde0bc03","uri":"spotify:track:77svvOHCRb1GljfNLeuK91","trackType":"spotify","seek":0,"duration":330,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 12:58:05 volumio volumio[1240]: verbose: CURRENT POSITION 8 Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::syncState stateService pause Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::syncState currentStatus stop Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::pushState Aug 29 12:58:05 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:05 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState Aug 29 12:58:05 volumio volumio[1240]: info: CoreCommandRouter::servicePushState Aug 29 12:58:05 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:05 volumio volumio[1240]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Washing by Hand","artist":"Jackie Leven","album":"Creatures of Light & Darkness","albumart":"https://i.scdn.co/image/ab67616d00001e0285405eab20a0fbc4fde0bc03","uri":"spotify:track:77svvOHCRb1GljfNLeuK91","trackType":"spotify","seek":0,"duration":330,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 12:58:05 volumio volumio[1240]: verbose: CURRENT POSITION 8 Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::syncState stateService pause Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::syncState currentStatus stop Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::pushState Aug 29 12:58:05 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:05 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState Aug 29 12:58:05 volumio go-librespot[24648]: time="2026-08-29T12:58:05+10:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 12:58:05 volumio go-librespot[24648]: time="2026-08-29T12:58:05+10:00" level=trace msg="emitting websocket event: playing" Aug 29 12:58:05 volumio volumio[1240]: info: CoreCommandRouter::servicePushState Aug 29 12:58:05 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:05 volumio volumio[1240]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Washing by Hand","artist":"Jackie Leven","album":"Creatures of Light & Darkness","albumart":"https://i.scdn.co/image/ab67616d00001e0285405eab20a0fbc4fde0bc03","uri":"spotify:track:77svvOHCRb1GljfNLeuK91","trackType":"spotify","seek":0,"duration":330,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 12:58:05 volumio volumio[1240]: verbose: CURRENT POSITION 8 Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::syncState stateService play Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::syncState currentStatus stop Aug 29 12:58:05 volumio volumio[1240]: info: CoreCommandRouter::servicePushState Aug 29 12:58:05 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:05 volumio volumio[1240]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Washing by Hand","artist":"Jackie Leven","album":"Creatures of Light & Darkness","albumart":"https://i.scdn.co/image/ab67616d00001e0285405eab20a0fbc4fde0bc03","uri":"spotify:track:77svvOHCRb1GljfNLeuK91","trackType":"spotify","seek":0,"duration":330,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 12:58:05 volumio volumio[1240]: verbose: CURRENT POSITION 8 Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::syncState stateService play Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::syncState currentStatus play Aug 29 12:58:05 volumio volumio[1240]: info: Received an update from plugin. extracting info from payload Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::pushState Aug 29 12:58:05 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:05 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 12:58:05 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::pushState Aug 29 12:58:05 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:05 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState Aug 29 12:58:05 volumio volumio[1240]: info: CoreCommandRouter::servicePushState Aug 29 12:58:05 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:05 volumio volumio[1240]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Washing by Hand","artist":"Jackie Leven","album":"Creatures of Light & Darkness","albumart":"https://i.scdn.co/image/ab67616d00001e0285405eab20a0fbc4fde0bc03","uri":"spotify:track:77svvOHCRb1GljfNLeuK91","trackType":"spotify","seek":0,"duration":330,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 12:58:05 volumio volumio[1240]: verbose: CURRENT POSITION 8 Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::syncState stateService play Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::syncState currentStatus play Aug 29 12:58:05 volumio volumio[1240]: info: Received an update from plugin. extracting info from payload Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::pushState Aug 29 12:58:05 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:05 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState Aug 29 12:58:05 volumio volumio[1240]: info: CoreStateMachine::pushState Aug 29 12:58:05 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:05 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState Aug 29 12:58:05 volumio volumio[1240]: info: touch_display: Setting screensaver timeout to 0 seconds. Aug 29 12:58:06 volumio volumio[1240]: info: CoreCommandRouter::servicePushState Aug 29 12:58:06 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:06 volumio volumio[1240]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Washing by Hand","artist":"Jackie Leven","album":"Creatures of Light & Darkness","albumart":"https://i.scdn.co/image/ab67616d00001e0285405eab20a0fbc4fde0bc03","uri":"spotify:track:77svvOHCRb1GljfNLeuK91","trackType":"spotify","seek":0,"duration":330,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 12:58:06 volumio volumio[1240]: verbose: CURRENT POSITION 8 Aug 29 12:58:06 volumio volumio[1240]: info: CoreStateMachine::syncState stateService play Aug 29 12:58:06 volumio volumio[1240]: info: CoreStateMachine::syncState currentStatus play Aug 29 12:58:06 volumio volumio[1240]: info: Received an update from plugin. extracting info from payload Aug 29 12:58:06 volumio volumio[1240]: info: CoreStateMachine::pushState Aug 29 12:58:06 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:06 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState Aug 29 12:58:06 volumio volumio[1240]: info: CoreStateMachine::pushState Aug 29 12:58:06 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:06 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState Aug 29 12:58:06 volumio volumio[1240]: info: CoreCommandRouter::servicePushState Aug 29 12:58:06 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:06 volumio volumio[1240]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Washing by Hand","artist":"Jackie Leven","album":"Creatures of Light & Darkness","albumart":"https://i.scdn.co/image/ab67616d00001e0285405eab20a0fbc4fde0bc03","uri":"spotify:track:77svvOHCRb1GljfNLeuK91","trackType":"spotify","seek":0,"duration":330,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 12:58:06 volumio volumio[1240]: verbose: CURRENT POSITION 8 Aug 29 12:58:06 volumio volumio[1240]: info: CoreStateMachine::syncState stateService play Aug 29 12:58:06 volumio volumio[1240]: info: CoreStateMachine::syncState currentStatus play Aug 29 12:58:06 volumio volumio[1240]: info: Received an update from plugin. extracting info from payload Aug 29 12:58:06 volumio volumio[1240]: info: CoreStateMachine::pushState Aug 29 12:58:06 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:06 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState Aug 29 12:58:06 volumio volumio[1240]: info: CoreStateMachine::pushState Aug 29 12:58:06 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:06 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState Aug 29 12:58:06 volumio volumio[1240]: info: CoreCommandRouter::servicePushState Aug 29 12:58:06 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:06 volumio volumio[1240]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Washing by Hand","artist":"Jackie Leven","album":"Creatures of Light & Darkness","albumart":"https://i.scdn.co/image/ab67616d00001e0285405eab20a0fbc4fde0bc03","uri":"spotify:track:77svvOHCRb1GljfNLeuK91","trackType":"spotify","seek":0,"duration":330,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 12:58:06 volumio volumio[1240]: verbose: CURRENT POSITION 8 Aug 29 12:58:06 volumio volumio[1240]: info: CoreStateMachine::syncState stateService play Aug 29 12:58:06 volumio volumio[1240]: info: CoreStateMachine::syncState currentStatus play Aug 29 12:58:06 volumio volumio[1240]: info: Received an update from plugin. extracting info from payload Aug 29 12:58:06 volumio volumio[1240]: info: CoreStateMachine::pushState Aug 29 12:58:06 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:06 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState Aug 29 12:58:06 volumio volumio[1240]: info: CoreStateMachine::pushState Aug 29 12:58:06 volumio volumio[1240]: info: CorePlayQueue::getTrack 8 Aug 29 12:58:06 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState Aug 29 12:58:14 volumio volumio[1240]: info: CoreCommandRouter::volumioGetQueue Aug 29 12:58:14 volumio volumio[1240]: info: CoreStateMachine::getQueue Aug 29 12:58:14 volumio volumio[1240]: info: CorePlayQueue::getQueue Aug 29 12:58:17 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Aug 29 12:58:17 volumio volumio[1240]: info: CURURI: playlists Aug 29 12:58:17 volumio volumio[1240]: info: Listing playlists Aug 29 12:58:17 volumio volumio[1240]: info: Preload queue cleared Aug 29 12:58:19 volumio go-librespot[24648]: time="2026-08-29T12:58:19+10:00" level=trace msg="sent dealer ping" Aug 29 12:58:19 volumio go-librespot[24648]: time="2026-08-29T12:58:19+10:00" level=trace msg="received dealer pong" Aug 29 12:58:20 volumio go-librespot[24648]: time="2026-08-29T12:58:20+10:00" level=debug msg="fetched chunk 4/25, size: 524288" uri="spotify:track:77svvOHCRb1GljfNLeuK91" Aug 29 12:58:28 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 29 12:58:28 volumio volumio[1240]: info: In handleBrowseUri, curUri=spotify Aug 29 12:58:29 volumio volumio[1240]: info: Preload queue cleared Aug 29 12:58:29 volumio volumio[1240]: info: Preload queue cleared Aug 29 12:58:29 volumio volumio[1240]: info: Preload queue cleared Aug 29 12:58:29 volumio volumio[1240]: info: Preload queue cleared Aug 29 12:58:34 volumio go-librespot[24648]: time="2026-08-29T12:58:34+10:00" level=debug msg="fetched chunk 5/25, size: 524288" uri="spotify:track:77svvOHCRb1GljfNLeuK91" Aug 29 12:58:34 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 29 12:58:34 volumio volumio[1240]: info: In handleBrowseUri, curUri=spotify/myalbums Aug 29 12:58:35 volumio volumio[1240]: info: Preload queue cleared Aug 29 12:58:41 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 29 12:58:41 volumio volumio[1240]: info: In handleBrowseUri, curUri=spotify:album:6voL7QeFcwPlDVN84fzyYa Aug 29 12:58:42 volumio volumio[1240]: info: Preload queue cleared Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:1SmiawcqIWkEcILuAsJ83O Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:2629nSdHjNQ17wSEWRYbFl Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:1zXZVk7gihMzJbqUdnusYK Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:6RXiC6BKrYHHPTy2ziSLWN Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:3J9ZM34PcFHgPp91cnvYJv Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:5CihS4dEiBWPbwHWuFhycP Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:7evbBhm7jGbbPSw2mK7r8Y Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:17iJlSxpwFmVMXwMtYyDi8 Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:4LxBghpQFwYa5StsTi6eKU Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:4vuuNeEGnSiKREM8Y9ra8x Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:4i7YhVWrnNLNR5zIi8jtxK Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:7JMh4LThaAMCsgUSdY7DXd Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:47F6pW8T4Z77XZqBSmCRf5 Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:1d709BSBALxo4stQk1NYLy Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:3gnpwVkct2cRx7zMjJRwGb Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:5rGQ7cYAnI0irHKmES224G Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:5uZjLoylCp6kR9Qx9iiiPF Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:2x8Ew9zoktik1Obde8nqON Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:3Ad27to2PHaqITL8RiRCI7 Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:36Lj6cYZQhU1iIJXC5Pe1n Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:3xHZful7bDkV3zPX8TSzR8 Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:4g74yRHIfw9zeCtZZA4swK Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:0NHhi9dI9wuirnT6P6KKyY Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:023v9maRl8OKW6PqHwhdFW Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:6AYA06VU29Wu87oUIN6gSF Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:2PtD7gC4CwhBSPnQr3gF2G Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:1bXgLqbh9rddMEOk1oWE5R Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:6gQr16qyznT8SPRTMRUJlp Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:5ERC4fdENJtaJ2TGeu6XYE Aug 29 12:58:42 volumio volumio[1240]: info: Preloading song: spotify:track:4CBkxWT0gXJOAqT8a2Q1Zo Aug 29 12:58:42 volumio volumio[1240]: info: Exploding uri spotify:track:1SmiawcqIWkEcILuAsJ83O in service spop Aug 29 12:58:42 volumio volumio[1240]: info: Exploding uri spotify:track:2629nSdHjNQ17wSEWRYbFl in service spop Aug 29 12:58:42 volumio volumio[1240]: info: Exploding uri spotify:track:1zXZVk7gihMzJbqUdnusYK in service spop Aug 29 12:58:42 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Aug 29 12:58:42 volumio volumio[1240]: info: Exploding uri spotify:track:6RXiC6BKrYHHPTy2ziSLWN in service spop Aug 29 12:58:42 volumio volumio[1240]: info: Exploding uri spotify:track:3J9ZM34PcFHgPp91cnvYJv in service spop Aug 29 12:58:42 volumio volumio[1240]: info: Exploding uri spotify:track:5CihS4dEiBWPbwHWuFhycP in service spop Aug 29 12:58:42 volumio volumio[1240]: info: Exploding uri spotify:track:7evbBhm7jGbbPSw2mK7r8Y in service spop Aug 29 12:58:42 volumio volumio[1240]: info: Exploding uri spotify:track:17iJlSxpwFmVMXwMtYyDi8 in service spop Aug 29 12:58:42 volumio volumio[1240]: info: Exploding uri spotify:track:4LxBghpQFwYa5StsTi6eKU in service spop Aug 29 12:58:42 volumio volumio[1240]: info: Exploding uri spotify:track:4vuuNeEGnSiKREM8Y9ra8x in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:4i7YhVWrnNLNR5zIi8jtxK in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:7JMh4LThaAMCsgUSdY7DXd in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:47F6pW8T4Z77XZqBSmCRf5 in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:1d709BSBALxo4stQk1NYLy in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:3gnpwVkct2cRx7zMjJRwGb in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:5rGQ7cYAnI0irHKmES224G in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:5uZjLoylCp6kR9Qx9iiiPF in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:2x8Ew9zoktik1Obde8nqON in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:3Ad27to2PHaqITL8RiRCI7 in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:36Lj6cYZQhU1iIJXC5Pe1n in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:3xHZful7bDkV3zPX8TSzR8 in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:4g74yRHIfw9zeCtZZA4swK in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:0NHhi9dI9wuirnT6P6KKyY in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:023v9maRl8OKW6PqHwhdFW in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:6AYA06VU29Wu87oUIN6gSF in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:2PtD7gC4CwhBSPnQr3gF2G in service spop Aug 29 12:58:43 volumio volumio[1240]: info: No valid Plugin REST Endpoint Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:1bXgLqbh9rddMEOk1oWE5R in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:6gQr16qyznT8SPRTMRUJlp in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:5ERC4fdENJtaJ2TGeu6XYE in service spop Aug 29 12:58:43 volumio volumio[1240]: info: Exploding uri spotify:track:4CBkxWT0gXJOAqT8a2Q1Zo in service spop Aug 29 12:58:45 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 29 12:58:45 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 29 12:58:45 volumio systemd[1]: setdatetime-helper.service: Consumed 1.776s CPU time. Aug 29 12:58:47 volumio go-librespot[24648]: time="2026-08-29T12:58:47+10:00" level=debug msg="fetched chunk 6/25, size: 524288" uri="spotify:track:77svvOHCRb1GljfNLeuK91" Aug 29 12:58:48 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: my_music , getSuperSearchEnabledSourcesList Aug 29 12:58:48 volumio volumio[1240]: info: CoreCommandRouter::volumioGetBrowseSources Aug 29 12:58:48 volumio volumio[1240]: info: CoreCommandRouter::volumioGetBrowseSources Aug 29 12:58:48 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: mpd , search Aug 29 12:58:48 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: spop , search Aug 29 12:58:49 volumio volumio[1240]: info: All search sources collected, pushing search results Aug 29 12:58:49 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 29 12:58:49 volumio volumio[1240]: info: In handleBrowseUri, curUri=spotify:artist:6Lk1jIrgO8o4hftqQwPSjg Aug 29 12:58:49 volumio go-librespot[24648]: time="2026-08-29T12:58:49+10:00" level=trace msg="sent dealer ping" Aug 29 12:58:49 volumio go-librespot[24648]: time="2026-08-29T12:58:49+10:00" level=trace msg="received dealer pong" Aug 29 12:58:50 volumio volumio[1240]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 12:58:50 volumio volumio[1240]: TypeError: Cannot read properties of undefined (reading 'url') Aug 29 12:58:50 volumio volumio[1240]: at /data/plugins/music_service/spop/index.js:2410:60 Aug 29 12:58:50 volumio volumio[1240]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Aug 29 12:58:50 volumio volumio[1240]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 12:58:53 volumio sudo[15890]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-29 12:57' Aug 29 12:58:53 volumio sudo[15890]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"