Oct 12 20:18:02 volumio volumio[1208]: info: CoreCommandRouter::volumioSeek Oct 12 20:18:02 volumio volumio[1208]: info: CoreStateMachine::seek Oct 12 20:18:02 volumio volumio[1208]: info: CoreStateMachine::startPlaybackTimer Oct 12 20:18:02 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Oct 12 20:18:02 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:02 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:02 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:02 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:02.413+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=82097 volume=100 Oct 12 20:18:02 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:02.415+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:1r013shkDTXLLe3yFfpq7x title="here we go again" Oct 12 20:18:02 volumio launch-soloist.sh[1768]: 2026-10-12 20:18:02.689: playing spotify:track:1r013shkDTXLLe3yFfpq7x "here we go again" by "Alex Kehm" [1:50 / 3:12] Oct 12 20:18:02 volumio volumio[1208]: info: CoreCommandRouter::servicePushState Oct 12 20:18:02 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:02 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:02 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:02 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:02.754+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=110606 volume=100 Oct 12 20:18:02 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:02.755+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:1r013shkDTXLLe3yFfpq7x title="here we go again" Oct 12 20:18:02 volumio volumio[1208]: info: CoreCommandRouter::servicePushState Oct 12 20:18:02 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:02 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:02 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:02 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:02.802+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=110579 volume=100 Oct 12 20:18:02 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:02.803+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:1r013shkDTXLLe3yFfpq7x title="here we go again" Oct 12 20:18:07 volumio volumio[1208]: info: CoreCommandRouter::volumioNext Oct 12 20:18:07 volumio volumio[1208]: info: CoreStateMachine::next Oct 12 20:18:07 volumio launch-soloist.sh[1768]: 2026-10-12 20:18:07.886: playing spotify:track:5yOqLv04tYyFcaXOtyBpz7 "Forgotten Ghosts" by "Jadu Heart" [0:00 / 5:08] Oct 12 20:18:07 volumio volumio[1208]: info: SoloistConnect: open /data/soloist/cache/cache/28/285b2efe996977e6b71136e7f314da0c863924b8.file 40087606 bytes over 308s = 1041 kbps -> Lossless Oct 12 20:18:07 volumio volumio[1208]: info: CoreCommandRouter::servicePushState Oct 12 20:18:07 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:07 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:07 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:07 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:07.926+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=115708 volume=100 Oct 12 20:18:07 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:07.927+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:5yOqLv04tYyFcaXOtyBpz7 title="Forgotten Ghosts" Oct 12 20:18:07 volumio volumio[1208]: info: CoreCommandRouter::servicePushState Oct 12 20:18:07 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:07 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:07 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:08 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:08.046+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=107 volume=100 Oct 12 20:18:08 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:08.046+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:5yOqLv04tYyFcaXOtyBpz7 title="Forgotten Ghosts" Oct 12 20:18:08 volumio volumio[1208]: info: CoreCommandRouter::servicePushState Oct 12 20:18:08 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:08 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:08 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:08 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:08.059+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=774 volume=100 Oct 12 20:18:08 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:08.061+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:5yOqLv04tYyFcaXOtyBpz7 title="Forgotten Ghosts" Oct 12 20:18:15 volumio volumio[1208]: info: CoreCommandRouter::volumioSeek Oct 12 20:18:15 volumio volumio[1208]: info: CoreStateMachine::seek Oct 12 20:18:15 volumio volumio[1208]: info: CoreStateMachine::startPlaybackTimer Oct 12 20:18:15 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Oct 12 20:18:15 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:15 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:15 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:15 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:15.963+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=8385 volume=100 Oct 12 20:18:15 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:15.964+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:5yOqLv04tYyFcaXOtyBpz7 title="Forgotten Ghosts" Oct 12 20:18:16 volumio volumio[1208]: info: CoreCommandRouter::servicePushState Oct 12 20:18:16 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:16 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:16 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:16 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:16.279+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=44065 volume=100 Oct 12 20:18:16 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:16.279+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:5yOqLv04tYyFcaXOtyBpz7 title="Forgotten Ghosts" Oct 12 20:18:16 volumio volumio[1208]: info: CoreCommandRouter::servicePushState Oct 12 20:18:16 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:16 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:16 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:16 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:16.326+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=44059 volume=100 Oct 12 20:18:16 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:16.326+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:5yOqLv04tYyFcaXOtyBpz7 title="Forgotten Ghosts" Oct 12 20:18:18 volumio launch-soloist.sh[1768]: 2026-10-12 20:18:18.624: playing spotify:track:5yOqLv04tYyFcaXOtyBpz7 "Forgotten Ghosts" by "Jadu Heart" [0:46 / 5:08] Oct 12 20:18:18 volumio volumio[1208]: info: CoreCommandRouter::volumioNext Oct 12 20:18:18 volumio volumio[1208]: info: CoreStateMachine::next Oct 12 20:18:18 volumio launch-soloist.sh[1768]: 2026-10-12 20:18:18.771: playing spotify:track:6I2RLyNZdBBfAheAYFDq3Q "Tears On My Pillow" by "River Simmons" [0:00 / 3:18] Oct 12 20:18:18 volumio volumio[1208]: info: SoloistConnect: quality hold: fds=0 empty Oct 12 20:18:18 volumio volumio[1208]: info: CoreCommandRouter::servicePushState Oct 12 20:18:18 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:18 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:18 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:18 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:18.819+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=46553 volume=100 Oct 12 20:18:18 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:18.819+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:6I2RLyNZdBBfAheAYFDq3Q title="Tears On My Pillow" Oct 12 20:18:18 volumio volumio[1208]: info: SoloistConnect: open /data/soloist/cache/cache/96/96c2f62cb3197f66ee6a900453f4697e5f037791.file 32768 bytes over 198s = 1 kbps (growing, hold) Oct 12 20:18:18 volumio volumio[1208]: info: CoreCommandRouter::servicePushState Oct 12 20:18:18 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:18 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:18 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:18 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:18.964+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=175 volume=100 Oct 12 20:18:18 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:18.964+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:6I2RLyNZdBBfAheAYFDq3Q title="Tears On My Pillow" Oct 12 20:18:19 volumio volumio[1208]: info: SoloistConnect: open /data/soloist/cache/cache/96/96c2f62cb3197f66ee6a900453f4697e5f037791.file 1507328 bytes over 198s = 61 kbps (growing, hold) Oct 12 20:18:19 volumio volumio[1208]: info: CoreCommandRouter::servicePushState Oct 12 20:18:19 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:19 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:19 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:19 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:19.066+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=681 volume=100 Oct 12 20:18:19 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:19.066+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:6I2RLyNZdBBfAheAYFDq3Q title="Tears On My Pillow" Oct 12 20:18:19 volumio volumio[1208]: info: SoloistConnect: quality hold: fds=2 ambiguous Oct 12 20:18:19 volumio volumio[1208]: info: SoloistConnect: open /data/soloist/cache/cache/96/96c2f62cb3197f66ee6a900453f4697e5f037791.file 6291456 bytes over 198s = 254 kbps (growing, hold) Oct 12 20:18:20 volumio volumio[1208]: info: SoloistConnect: open /data/soloist/cache/cache/96/96c2f62cb3197f66ee6a900453f4697e5f037791.file 12582912 bytes over 198s = 508 kbps -> Lossless Oct 12 20:18:20 volumio volumio[1208]: info: CoreCommandRouter::servicePushState Oct 12 20:18:20 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:20 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:20 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:20 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:20.089+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=1844 volume=100 Oct 12 20:18:20 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:20.090+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:6I2RLyNZdBBfAheAYFDq3Q title="Tears On My Pillow" Oct 12 20:18:28 volumio volumio[1208]: info: CoreCommandRouter::volumioSeek Oct 12 20:18:28 volumio volumio[1208]: info: CoreStateMachine::seek Oct 12 20:18:28 volumio volumio[1208]: info: CoreStateMachine::startPlaybackTimer Oct 12 20:18:28 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Oct 12 20:18:28 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:28 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:28 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:28 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:28.958+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=10422 volume=100 Oct 12 20:18:28 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:28.959+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:6I2RLyNZdBBfAheAYFDq3Q title="Tears On My Pillow" Oct 12 20:18:29 volumio volumio[1208]: info: SoloistConnect: open /data/soloist/cache/cache/96/96c2f62cb3197f66ee6a900453f4697e5f037791.file 12604540 bytes over 198s = 509 kbps -> Lossless Oct 12 20:18:29 volumio volumio[1208]: info: CoreCommandRouter::servicePushState Oct 12 20:18:29 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:29 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:29 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:29 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:29.294+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=27079 volume=100 Oct 12 20:18:29 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:29.294+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:6I2RLyNZdBBfAheAYFDq3Q title="Tears On My Pillow" Oct 12 20:18:29 volumio volumio[1208]: info: CoreCommandRouter::servicePushState Oct 12 20:18:29 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:29 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:29 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:29 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:29.339+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=27058 volume=100 Oct 12 20:18:29 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:29.340+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:6I2RLyNZdBBfAheAYFDq3Q title="Tears On My Pillow" Oct 12 20:18:29 volumio launch-soloist.sh[1768]: 2026-10-12 20:18:29.624: playing spotify:track:6I2RLyNZdBBfAheAYFDq3Q "Tears On My Pillow" by "River Simmons" [0:27 / 3:18] Oct 12 20:18:36 volumio volumio[1208]: info: CoreCommandRouter::volumioNext Oct 12 20:18:36 volumio volumio[1208]: info: CoreStateMachine::next Oct 12 20:18:36 volumio launch-soloist.sh[1768]: 2026-10-12 20:18:36.228: playing spotify:track:589C4vLPU0XHkIMoUayE6o "Gone To Seed" by "Emory Duncan" [0:00 / 4:03] Oct 12 20:18:36 volumio volumio[1208]: info: SoloistConnect: quality hold: fds=1 stale Oct 12 20:18:36 volumio volumio[1208]: info: CoreCommandRouter::servicePushState Oct 12 20:18:36 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:36 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:36 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:36 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:36.264+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=33983 volume=100 Oct 12 20:18:36 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:36.265+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:589C4vLPU0XHkIMoUayE6o title="Gone To Seed" Oct 12 20:18:36 volumio volumio[1208]: info: SoloistConnect: quality hold: fds=0 empty Oct 12 20:18:36 volumio volumio[1208]: info: CoreCommandRouter::servicePushState Oct 12 20:18:36 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:36 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:36 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:36 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:36.812+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=566 volume=100 Oct 12 20:18:36 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:36.812+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:589C4vLPU0XHkIMoUayE6o title="Gone To Seed" Oct 12 20:18:36 volumio volumio[1208]: info: SoloistConnect: open /data/soloist/cache/cache/2c/2c0b8c12be33d222deae8182cf8812709fdcf541.file 1458176 bytes over 243s = 48 kbps (growing, hold) Oct 12 20:18:36 volumio volumio[1208]: info: CoreCommandRouter::servicePushState Oct 12 20:18:36 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:36 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:36 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:36 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:36.860+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=1173 volume=100 Oct 12 20:18:36 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:36.861+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:589C4vLPU0XHkIMoUayE6o title="Gone To Seed" Oct 12 20:18:36 volumio volumio[1208]: info: SoloistConnect: open /data/soloist/cache/cache/2c/2c0b8c12be33d222deae8182cf8812709fdcf541.file 3096576 bytes over 243s = 102 kbps (growing, hold) Oct 12 20:18:37 volumio volumio[1208]: info: SoloistConnect: open /data/soloist/cache/cache/2c/2c0b8c12be33d222deae8182cf8812709fdcf541.file 13090816 bytes over 243s = 430 kbps (growing, hold) Oct 12 20:18:38 volumio volumio[1208]: info: SoloistConnect: open /data/soloist/cache/cache/2c/2c0b8c12be33d222deae8182cf8812709fdcf541.file 13680640 bytes over 243s = 450 kbps -> Lossless Oct 12 20:18:38 volumio volumio[1208]: info: CoreCommandRouter::servicePushState Oct 12 20:18:38 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 12 20:18:38 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:18:38 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 12 20:18:38 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:38.934+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" state=STATUS_PLAYING positionMs=3219 volume=100 Oct 12 20:18:38 volumio volumio5-onboarding[1613]: time=2026-10-12T20:18:38.934+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.53:64075,00:00:00:00:00:00%01 @ 0x22e26c0" id=spotify:track:589C4vLPU0XHkIMoUayE6o title="Gone To Seed" Oct 12 20:18:42 volumio volumio[1208]: info: Preload queue cleared Oct 12 20:18:42 volumio volumio[1208]: info: Preloading song: spotify:track:06xmw3uDTNYrVz8IlkIeFT Oct 12 20:18:43 volumio volumio[1208]: info: Exploding uri spotify:track:06xmw3uDTNYrVz8IlkIeFT in service soloist_connect Oct 12 20:18:46 volumio launch-soloist.sh[1768]: 2026-10-12 20:18:46.623: playing spotify:track:589C4vLPU0XHkIMoUayE6o "Gone To Seed" by "Emory Duncan" [0:10 / 4:03] Oct 12 20:18:56 volumio launch-soloist.sh[1768]: 2026-10-12 20:18:56.624: playing spotify:track:589C4vLPU0XHkIMoUayE6o "Gone To Seed" by "Emory Duncan" [0:20 / 4:03] Oct 12 20:19:00 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 12 20:19:00 volumio volumio[1208]: info: CURURI: albums:// Oct 12 20:19:00 volumio volumio[1208]: info: listAlbums - loading Albums from cache Oct 12 20:19:00 volumio volumio[1208]: info: Preload queue cleared Oct 12 20:19:03 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 12 20:19:03 volumio volumio[1208]: info: CURURI: artists:// Oct 12 20:19:03 volumio volumio[1208]: info: Preload queue cleared Oct 12 20:19:06 volumio launch-soloist.sh[1768]: 2026-10-12 20:19:06.624: playing spotify:track:589C4vLPU0XHkIMoUayE6o "Gone To Seed" by "Emory Duncan" [0:30 / 4:03] Oct 12 20:19:09 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 12 20:19:09 volumio volumio[1208]: info: CURURI: playlists Oct 12 20:19:09 volumio volumio[1208]: info: Listing playlists Oct 12 20:19:09 volumio volumio[1208]: info: Preload queue cleared Oct 12 20:19:11 volumio volumio[1208]: info: Preload queue cleared Oct 12 20:19:15 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: last_100 , handleBrowseUri Oct 12 20:19:15 volumio volumio[1208]: info: Preload queue cleared Oct 12 20:19:15 volumio volumio[1208]: info: Preloading song: https://stream.radioparadise.com/flacm Oct 12 20:19:15 volumio volumio[1208]: info: Preloading song: upnp/folder/http://192.168.0.88:2869/upnphost/udhisapi.dll?control=uuid:bcf5dafc-391c-40c3-ba96-0c9d15dcf6e6+urn:upnp-org:serviceId:ContentDirectory@14_6a1f5e17_a92b1858_6c43c81f Oct 12 20:19:15 volumio volumio[1208]: info: Preloading song: upnp/folder/http://192.168.0.88:2869/upnphost/udhisapi.dll?control=uuid:bcf5dafc-391c-40c3-ba96-0c9d15dcf6e6+urn:upnp-org:serviceId:ContentDirectory@14_6a1f5e17_82e9a1b8 Oct 12 20:19:15 volumio volumio[1208]: info: Preloading song: upnp/folder/http://192.168.0.88:2869/upnphost/udhisapi.dll?control=uuid:bcf5dafc-391c-40c3-ba96-0c9d15dcf6e6+urn:upnp-org:serviceId:ContentDirectory@14_6a1f5e17_39d63fe2_16b7d3ef_612cd696 Oct 12 20:19:15 volumio volumio[1208]: info: Preloading song: https://rozhlas.stream/jazz_mp3_256.mp3 Oct 12 20:19:15 volumio volumio[1208]: info: Preloading song: upnp/http://192.168.0.88:2869/upnphost/udhisapi.dll?control=uuid:bcf5dafc-391c-40c3-ba96-0c9d15dcf6e6+urn:upnp-org:serviceId:ContentDirectory@14_6a1f5e17_a57bc396_954658ce-875 Oct 12 20:19:15 volumio volumio[1208]: info: Preloading song: upnp/http://192.168.0.88:2869/upnphost/udhisapi.dll?control=uuid:bcf5dafc-391c-40c3-ba96-0c9d15dcf6e6+urn:upnp-org:serviceId:ContentDirectory@14_6a1f5e17_a57bc396_954658ce-881 Oct 12 20:19:15 volumio volumio[1208]: info: Preloading song: upnp/http://192.168.0.88:2869/upnphost/udhisapi.dll?control=uuid:bcf5dafc-391c-40c3-ba96-0c9d15dcf6e6+urn:upnp-org:serviceId:ContentDirectory@14_6a1f5e17_a57bc396_954658ce-878 Oct 12 20:19:15 volumio volumio[1208]: info: Preloading song: upnp/folder/http://192.168.0.88:2869/upnphost/udhisapi.dll?control=uuid:bcf5dafc-391c-40c3-ba96-0c9d15dcf6e6+urn:upnp-org:serviceId:ContentDirectory@14_6a1f5e17_30a76145 Oct 12 20:19:15 volumio volumio[1208]: info: Exploding uri https://stream.radioparadise.com/flacm in service radio_paradise Oct 12 20:19:15 volumio volumio[1208]: error: [RadioParadise] explodeUri: No station found for uri "https://stream.radioparadise.com/flacm" Oct 12 20:19:15 volumio volumio[1208]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 20:19:15 volumio volumio[1208]: TypeError: Cannot read properties of undefined (reading 'then') Oct 12 20:19:15 volumio volumio[1208]: at CoreCommandRouter.explodeUriFromService (/volumio/app/index.js:1384:31) Oct 12 20:19:15 volumio volumio[1208]: at CorePlayQueue.explodeUriFromCache (/volumio/app/playqueue.js:123:24) Oct 12 20:19:15 volumio volumio[1208]: at CorePlayQueue.explodeUri (/volumio/app/playqueue.js:181:19) Oct 12 20:19:15 volumio volumio[1208]: at Timeout._onTimeout (/volumio/app/playqueue.js:146:100) Oct 12 20:19:15 volumio volumio[1208]: at listOnTimeout (node:internal/timers:573:17) Oct 12 20:19:15 volumio volumio[1208]: at process.processTimers (node:internal/timers:514:7) Oct 12 20:19:15 volumio volumio[1208]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 20:19:16 volumio launch-soloist.sh[1768]: 2026-10-12 20:19:16.624: playing spotify:track:589C4vLPU0XHkIMoUayE6o "Gone To Seed" by "Emory Duncan" [0:40 / 4:03] Oct 12 20:19:17 volumio sudo[22382]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-12 20:18' Oct 12 20:19:17 volumio sudo[22382]: 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"