Dec 07 20:11:04 volumio go-librespot[1574]: time="2025-12-07T20:11:04Z" level=trace msg="sent dealer ping" Dec 07 20:11:04 volumio go-librespot[1574]: time="2025-12-07T20:11:04Z" level=trace msg="received dealer pong" Dec 07 20:11:05 volumio go-librespot[1574]: time="2025-12-07T20:11:05Z" level=trace msg="received accesspoint ping" Dec 07 20:11:05 volumio go-librespot[1574]: time="2025-12-07T20:11:05Z" level=trace msg="received accesspoint pong ack" Dec 07 20:11:11 volumio go-librespot[1574]: time="2025-12-07T20:11:11Z" level=debug msg="fetched chunk 6/28, size: 524288" uri="spotify:track:4gzc5PFLNN0M8TWwGj5PnF" Dec 07 20:11:23 volumio go-librespot[1574]: time="2025-12-07T20:11:23Z" level=debug msg="fetched chunk 7/28, size: 524288" uri="spotify:track:4gzc5PFLNN0M8TWwGj5PnF" Dec 07 20:11:31 volumio volumio[1124]: info: Preload queue cleared Dec 07 20:11:31 volumio volumio[1124]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::ClearQueue Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::stop Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::stPlaybackTimer Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::updateTrackBlock Dec 07 20:11:31 volumio volumio[1124]: info: CorePlayQueue::getTrackBlock Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::pushState Dec 07 20:11:31 volumio volumio[1124]: info: CorePlayQueue::getTrack 43 Dec 07 20:11:31 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 20:11:31 volumio volumio[1124]: info: CoreCommandRouter::volumioPushState Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::serviceStop Dec 07 20:11:31 volumio volumio[1124]: info: CorePlayQueue::getTrack 43 Dec 07 20:11:31 volumio volumio[1124]: info: CoreCommandRouter::serviceStop Dec 07 20:11:31 volumio volumio[1124]: info: Spotify Stop Dec 07 20:11:31 volumio volumio[1124]: SPOTIFY: SPOTIFY STOP Dec 07 20:11:31 volumio volumio[1124]: SPOTIFY: {"status":"play","position":43,"title":"Long Train Runnin' - Live","artist":"The Doobie Brothers","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d0000b273e15c257226c56421f74fe43d","uri":"spotify:track:4gzc5PFLNN0M8TWwGj5PnF","trackType":"spotify","codec":"ogg","seek":0,"duration":351,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Dec 07 20:11:31 volumio volumio[1124]: info: Sending Spotify command to local API: /player/pause Dec 07 20:11:31 volumio volumio[1124]: info: CorePlayQueue::clearPlayQueue Dec 07 20:11:31 volumio volumio[1124]: info: CorePlayQueue::saveQueue Dec 07 20:11:31 volumio volumio[1124]: info: CoreCommandRouter::volumioPushQueue Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::addQueueItems Dec 07 20:11:31 volumio volumio[1124]: info: CorePlayQueue::addQueueItems Dec 07 20:11:31 volumio volumio[1124]: info: Preload queue cleared Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:65O6GbjtemClygCr7kw0Vn Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:65O6GbjtemClygCr7kw0Vn Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:71gsZTXQxiVB1N4JzXcLXq Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:71gsZTXQxiVB1N4JzXcLXq Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:6hVSmYapASfFhWIUmksBY2 Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:6hVSmYapASfFhWIUmksBY2 Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:788AStPNtuuK5CxD5enb2O Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:788AStPNtuuK5CxD5enb2O Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:509K9DfXVUypqa1xAm5ZxV Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:509K9DfXVUypqa1xAm5ZxV Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:0jxV5krDErIi6X4DCGtqzC Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:0jxV5krDErIi6X4DCGtqzC Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:6Tf0ZFu4ICrVaSYLNEblHl Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:6Tf0ZFu4ICrVaSYLNEblHl Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:524d5WfipgMzb1TMWhrSe2 Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:524d5WfipgMzb1TMWhrSe2 Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4Ntidy5rQYaH1UzqQ5AKh6 Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:4Ntidy5rQYaH1UzqQ5AKh6 Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4dLxpsHnrfhcwFjVfd9yxP Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:4dLxpsHnrfhcwFjVfd9yxP Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:2b9l0r4V5FX18EygPoB6aR Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:2b9l0r4V5FX18EygPoB6aR Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:0yBNAZCLkL9xrr73qjydbN Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:0yBNAZCLkL9xrr73qjydbN Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4qgVZRu9oHg6e96cTRaaCP Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:4qgVZRu9oHg6e96cTRaaCP Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:3t6gawmmTTm1BVuVuIhhuu Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:3t6gawmmTTm1BVuVuIhhuu Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:1sbiUfrWQ62bSqSjlTMlFY Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:1sbiUfrWQ62bSqSjlTMlFY Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:7iK6prZV8li4kdE0LJPlZ0 Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:7iK6prZV8li4kdE0LJPlZ0 Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:1PlITqDGKanxzzvEITCgPf Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:1PlITqDGKanxzzvEITCgPf Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:3JFDNEbmTMepSDBIDbWk5z Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:3JFDNEbmTMepSDBIDbWk5z Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:3vXvdDXZe0V2sDK23LNJk9 Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:3vXvdDXZe0V2sDK23LNJk9 Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:14X4kwctPfMUrS1meeIUmC Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:14X4kwctPfMUrS1meeIUmC Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:60US1f3AWpYJrZNKKdNquZ Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:60US1f3AWpYJrZNKKdNquZ Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:57YWnVgpSpzXpZygg6eJfW Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:57YWnVgpSpzXpZygg6eJfW Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:1g3YIuFoSOTmuiFYfsahT3 Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:1g3YIuFoSOTmuiFYfsahT3 Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:19Znqx8oR4IMVpPDNZ6aDo Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:19Znqx8oR4IMVpPDNZ6aDo Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:2K22Gk2wC7tH5j0Pm6JAEc Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:2K22Gk2wC7tH5j0Pm6JAEc Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:2azSTTlDg0VNNGxGsD3iDQ Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:2azSTTlDg0VNNGxGsD3iDQ Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:3YNaliQzXAmnxxFbTIG1S3 Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:3YNaliQzXAmnxxFbTIG1S3 Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:3QNalg8Q83fCmaz5efca2t Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:3QNalg8Q83fCmaz5efca2t Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:0fOMOAGNeR6Ic9IySipUmT Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:0fOMOAGNeR6Ic9IySipUmT Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:7IPFX6AoiukSRnSevDPOCG Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:7IPFX6AoiukSRnSevDPOCG Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:2n1xGch3RCfNTS0SuTqB2D Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:2n1xGch3RCfNTS0SuTqB2D Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:40RB5XoVDPV4lQKHGvkMWd Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:40RB5XoVDPV4lQKHGvkMWd Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:7tICXJscOvTktERqbl5qdT Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:7tICXJscOvTktERqbl5qdT Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:49BOFvmMR12hChCNZNutVU Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:49BOFvmMR12hChCNZNutVU Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:7inusJXRvhFQl6XZe062HB Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:7inusJXRvhFQl6XZe062HB Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:7vN8vReDIiGFYLqbF3XSyC Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:7vN8vReDIiGFYLqbF3XSyC Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:31icXNIFjX9YQ9z7I1UAz8 Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:31icXNIFjX9YQ9z7I1UAz8 Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:3nBc8pa5CucsWR7fkMr9iO Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:3nBc8pa5CucsWR7fkMr9iO Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:6igOUEOwKLRfHQ6NmYRRDM Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:6igOUEOwKLRfHQ6NmYRRDM Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:46iQAzV1N16XiQcXjYOETT Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:46iQAzV1N16XiQcXjYOETT Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:7oy880fepIH46YlcwfhyFJ Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:7oy880fepIH46YlcwfhyFJ Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:0FGUQRHYmxcQ9U3a6DVHE2 Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:0FGUQRHYmxcQ9U3a6DVHE2 Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4CNL4GBNTdVIU5Nk6hB4LC Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:4CNL4GBNTdVIU5Nk6hB4LC Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4gzc5PFLNN0M8TWwGj5PnF Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:4gzc5PFLNN0M8TWwGj5PnF Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4Pjv2kNzpuUtMVdoSqegnq Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:4Pjv2kNzpuUtMVdoSqegnq Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4oneNquOUM0AzuFEhEWiGE Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:4oneNquOUM0AzuFEhEWiGE Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:5jbqwoIn1xcbVmVjDd8ZB6 Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:5jbqwoIn1xcbVmVjDd8ZB6 Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:0rEmsXJxxrgD0cEqY7dUP2 Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:0rEmsXJxxrgD0cEqY7dUP2 Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:6JVMr3TcokCtjVafRK0VdZ Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:6JVMr3TcokCtjVafRK0VdZ Dec 07 20:11:31 volumio volumio[1124]: info: Adding Item to queue: spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj Dec 07 20:11:31 volumio volumio[1124]: info: Using cached record of: spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj Dec 07 20:11:31 volumio volumio[1124]: info: CoreCommandRouter::volumioPushQueue Dec 07 20:11:31 volumio volumio[1124]: info: CorePlayQueue::saveQueue Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::updateTrackBlock Dec 07 20:11:31 volumio volumio[1124]: info: CorePlayQueue::getTrackBlock Dec 07 20:11:31 volumio volumio[1124]: info: CoreCommandRouter::volumioPlay Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::play index 49 Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::stop Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::play index undefined Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 20:11:31 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::startPlaybackTimer Dec 07 20:11:31 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:31 volumio volumio[1124]: info: [1765138291225] ControllerSpotify::clearAddPlayTrack Dec 07 20:11:31 volumio volumio[1124]: info: Sending Spotify command with payload to local API: /player/play Dec 07 20:11:31 volumio volumio[1124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=debug msg="resolved context of track" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:31 volumio volumio[1124]: info: touch_display: Setting screensaver timeout to 120 seconds. Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=trace msg="emitting websocket event: will_play" Dec 07 20:11:31 volumio volumio[1124]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","play_origin":"go-librespot"}} Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=debug msg="selected format OGG_VORBIS_320 (73f1b393d4b9a72aa5b688dfd7f80fb0e9ff515a)" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=debug msg="requested aes key for file 73f1b393d4b9a72aa5b688dfd7f80fb0e9ff515a, gid: 2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=trace msg="found 2 cdn urls" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=debug msg="fetched first chunk of 23, total size is 11574412 bytes" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=info msg="loaded track \"Runaway Train\" (paused: false, position: 0ms, duration: 266613ms, prefetched: false)" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=debug msg="fetched chunk 1/22, size: 524288" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=trace msg="scheduling prefetch in 237s" Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=trace msg="emitting websocket event: metadata" Dec 07 20:11:31 volumio volumio[1124]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","name":"Runaway Train","artist_names":["Soul Asylum"],"album_name":"Pure... Guitar Heroes","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","position":0,"duration":266613,"release_date":"year:2010 month:12 day:10","track_number":16,"disc_number":3}} Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=debug msg="fetched chunk 2/22, size: 524288" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=debug msg="fetched chunk 3/22, size: 524288" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=trace msg="emitting websocket event: playing" Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=debug msg="pause track at 91ms" Dec 07 20:11:31 volumio volumio[1124]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","resume":false,"play_origin":"go-librespot"}} Dec 07 20:11:31 volumio volumio[1124]: SPOTIFY: PUSH STATE SPOTIFY Dec 07 20:11:31 volumio volumio[1124]: SPOTIFY: {"status":"play","service":"spop","title":"Runaway Train","artist":"Soul Asylum","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","trackType":"spotify","seek":0,"duration":266,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 07 20:11:31 volumio volumio[1124]: info: CoreCommandRouter::servicePushState Dec 07 20:11:31 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:31 volumio volumio[1124]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Runaway Train","artist":"Soul Asylum","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","trackType":"spotify","seek":0,"duration":266,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 07 20:11:31 volumio volumio[1124]: verbose: CURRENT POSITION 49 Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::syncState stateService play Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::syncState currentStatus stop Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 07 20:11:31 volumio go-librespot[1574]: time="2025-12-07T20:11:31Z" level=trace msg="emitting websocket event: paused" Dec 07 20:11:31 volumio volumio[1124]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","play_origin":"go-librespot"}} Dec 07 20:11:31 volumio volumio[1124]: SPOTIFY: PUSH STATE SPOTIFY Dec 07 20:11:31 volumio volumio[1124]: SPOTIFY: {"status":"pause","service":"spop","title":"Runaway Train","artist":"Soul Asylum","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","trackType":"spotify","seek":0,"duration":266,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 07 20:11:31 volumio volumio[1124]: info: CoreCommandRouter::servicePushState Dec 07 20:11:31 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:31 volumio volumio[1124]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Runaway Train","artist":"Soul Asylum","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","trackType":"spotify","seek":0,"duration":266,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 07 20:11:31 volumio volumio[1124]: verbose: CURRENT POSITION 49 Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::syncState stateService pause Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::syncState currentStatus play Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::pushState Dec 07 20:11:31 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:31 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 20:11:31 volumio volumio[1124]: info: CoreCommandRouter::volumioPushState Dec 07 20:11:31 volumio volumio[1124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 07 20:11:31 volumio volumio[1124]: info: touch_display: Setting screensaver timeout to 0 seconds. Dec 07 20:11:31 volumio volumio[1124]: SPOTIFY: PUSH STATE SPOTIFY Dec 07 20:11:31 volumio volumio[1124]: SPOTIFY: {"status":"pause","service":"spop","title":"Runaway Train","artist":"Soul Asylum","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","trackType":"spotify","seek":0,"duration":266,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 07 20:11:31 volumio volumio[1124]: info: CoreCommandRouter::servicePushState Dec 07 20:11:31 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:31 volumio volumio[1124]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Runaway Train","artist":"Soul Asylum","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","trackType":"spotify","seek":0,"duration":266,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 07 20:11:31 volumio volumio[1124]: verbose: CURRENT POSITION 49 Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::syncState stateService pause Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::syncState currentStatus play Dec 07 20:11:31 volumio volumio[1124]: info: CoreStateMachine::pushState Dec 07 20:11:31 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:31 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 20:11:31 volumio volumio[1124]: info: CoreCommandRouter::volumioPushState Dec 07 20:11:31 volumio volumio[1124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 07 20:11:34 volumio go-librespot[1574]: time="2025-12-07T20:11:34Z" level=trace msg="sent dealer ping" Dec 07 20:11:34 volumio go-librespot[1574]: time="2025-12-07T20:11:34Z" level=trace msg="received dealer pong" Dec 07 20:11:42 volumio volumio[1124]: info: Preload queue cleared Dec 07 20:11:42 volumio volumio[1124]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 07 20:11:42 volumio volumio[1124]: info: CoreStateMachine::ClearQueue Dec 07 20:11:42 volumio volumio[1124]: info: CoreStateMachine::stop Dec 07 20:11:42 volumio volumio[1124]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 20:11:42 volumio volumio[1124]: info: CoreStateMachine::stPlaybackTimer Dec 07 20:11:42 volumio volumio[1124]: info: CoreStateMachine::updateTrackBlock Dec 07 20:11:42 volumio volumio[1124]: info: CorePlayQueue::getTrackBlock Dec 07 20:11:42 volumio volumio[1124]: info: CoreStateMachine::pushState Dec 07 20:11:42 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:42 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 20:11:42 volumio volumio[1124]: info: CoreCommandRouter::volumioPushState Dec 07 20:11:42 volumio volumio[1124]: info: CoreStateMachine::serviceStop Dec 07 20:11:42 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:42 volumio volumio[1124]: info: CoreCommandRouter::serviceStop Dec 07 20:11:42 volumio volumio[1124]: info: Spotify Stop Dec 07 20:11:42 volumio volumio[1124]: SPOTIFY: SPOTIFY STOP Dec 07 20:11:42 volumio volumio[1124]: SPOTIFY: {"status":"play","position":49,"title":"Runaway Train","artist":"Soul Asylum","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d0000b273e15c257226c56421f74fe43d","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","trackType":"spotify","codec":"ogg","seek":250,"duration":266,"samplerate":"320 kbps","bitdepth":"16 bit","random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Dec 07 20:11:42 volumio volumio[1124]: info: Sending Spotify command to local API: /player/pause Dec 07 20:11:42 volumio volumio[1124]: info: CorePlayQueue::clearPlayQueue Dec 07 20:11:42 volumio volumio[1124]: info: CorePlayQueue::saveQueue Dec 07 20:11:42 volumio volumio[1124]: info: CoreCommandRouter::volumioPushQueue Dec 07 20:11:42 volumio volumio[1124]: info: CoreStateMachine::addQueueItems Dec 07 20:11:42 volumio volumio[1124]: info: CorePlayQueue::addQueueItems Dec 07 20:11:42 volumio volumio[1124]: info: Preload queue cleared Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:65O6GbjtemClygCr7kw0Vn Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:65O6GbjtemClygCr7kw0Vn Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:71gsZTXQxiVB1N4JzXcLXq Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:71gsZTXQxiVB1N4JzXcLXq Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:6hVSmYapASfFhWIUmksBY2 Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:6hVSmYapASfFhWIUmksBY2 Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:788AStPNtuuK5CxD5enb2O Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:788AStPNtuuK5CxD5enb2O Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:509K9DfXVUypqa1xAm5ZxV Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:509K9DfXVUypqa1xAm5ZxV Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:0jxV5krDErIi6X4DCGtqzC Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:0jxV5krDErIi6X4DCGtqzC Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:6Tf0ZFu4ICrVaSYLNEblHl Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:6Tf0ZFu4ICrVaSYLNEblHl Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:524d5WfipgMzb1TMWhrSe2 Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:524d5WfipgMzb1TMWhrSe2 Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4Ntidy5rQYaH1UzqQ5AKh6 Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:4Ntidy5rQYaH1UzqQ5AKh6 Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4dLxpsHnrfhcwFjVfd9yxP Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:4dLxpsHnrfhcwFjVfd9yxP Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:2b9l0r4V5FX18EygPoB6aR Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:2b9l0r4V5FX18EygPoB6aR Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:0yBNAZCLkL9xrr73qjydbN Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:0yBNAZCLkL9xrr73qjydbN Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4qgVZRu9oHg6e96cTRaaCP Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:4qgVZRu9oHg6e96cTRaaCP Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:3t6gawmmTTm1BVuVuIhhuu Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:3t6gawmmTTm1BVuVuIhhuu Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:1sbiUfrWQ62bSqSjlTMlFY Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:1sbiUfrWQ62bSqSjlTMlFY Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:7iK6prZV8li4kdE0LJPlZ0 Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:7iK6prZV8li4kdE0LJPlZ0 Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:1PlITqDGKanxzzvEITCgPf Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:1PlITqDGKanxzzvEITCgPf Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:3JFDNEbmTMepSDBIDbWk5z Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:3JFDNEbmTMepSDBIDbWk5z Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:3vXvdDXZe0V2sDK23LNJk9 Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:3vXvdDXZe0V2sDK23LNJk9 Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:14X4kwctPfMUrS1meeIUmC Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:14X4kwctPfMUrS1meeIUmC Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:60US1f3AWpYJrZNKKdNquZ Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:60US1f3AWpYJrZNKKdNquZ Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:57YWnVgpSpzXpZygg6eJfW Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:57YWnVgpSpzXpZygg6eJfW Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:1g3YIuFoSOTmuiFYfsahT3 Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:1g3YIuFoSOTmuiFYfsahT3 Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:19Znqx8oR4IMVpPDNZ6aDo Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:19Znqx8oR4IMVpPDNZ6aDo Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:2K22Gk2wC7tH5j0Pm6JAEc Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:2K22Gk2wC7tH5j0Pm6JAEc Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:2azSTTlDg0VNNGxGsD3iDQ Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:2azSTTlDg0VNNGxGsD3iDQ Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:3YNaliQzXAmnxxFbTIG1S3 Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:3YNaliQzXAmnxxFbTIG1S3 Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:3QNalg8Q83fCmaz5efca2t Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:3QNalg8Q83fCmaz5efca2t Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:0fOMOAGNeR6Ic9IySipUmT Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:0fOMOAGNeR6Ic9IySipUmT Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:7IPFX6AoiukSRnSevDPOCG Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:7IPFX6AoiukSRnSevDPOCG Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:2n1xGch3RCfNTS0SuTqB2D Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:2n1xGch3RCfNTS0SuTqB2D Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:40RB5XoVDPV4lQKHGvkMWd Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:40RB5XoVDPV4lQKHGvkMWd Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:7tICXJscOvTktERqbl5qdT Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:7tICXJscOvTktERqbl5qdT Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:49BOFvmMR12hChCNZNutVU Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:49BOFvmMR12hChCNZNutVU Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:7inusJXRvhFQl6XZe062HB Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:7inusJXRvhFQl6XZe062HB Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:7vN8vReDIiGFYLqbF3XSyC Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:7vN8vReDIiGFYLqbF3XSyC Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:31icXNIFjX9YQ9z7I1UAz8 Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:31icXNIFjX9YQ9z7I1UAz8 Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:3nBc8pa5CucsWR7fkMr9iO Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:3nBc8pa5CucsWR7fkMr9iO Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:6igOUEOwKLRfHQ6NmYRRDM Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:6igOUEOwKLRfHQ6NmYRRDM Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:46iQAzV1N16XiQcXjYOETT Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:46iQAzV1N16XiQcXjYOETT Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:7oy880fepIH46YlcwfhyFJ Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:7oy880fepIH46YlcwfhyFJ Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:0FGUQRHYmxcQ9U3a6DVHE2 Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:0FGUQRHYmxcQ9U3a6DVHE2 Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4CNL4GBNTdVIU5Nk6hB4LC Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:4CNL4GBNTdVIU5Nk6hB4LC Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4gzc5PFLNN0M8TWwGj5PnF Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:4gzc5PFLNN0M8TWwGj5PnF Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4Pjv2kNzpuUtMVdoSqegnq Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:4Pjv2kNzpuUtMVdoSqegnq Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4oneNquOUM0AzuFEhEWiGE Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:4oneNquOUM0AzuFEhEWiGE Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:5jbqwoIn1xcbVmVjDd8ZB6 Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:5jbqwoIn1xcbVmVjDd8ZB6 Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:0rEmsXJxxrgD0cEqY7dUP2 Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:0rEmsXJxxrgD0cEqY7dUP2 Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:6JVMr3TcokCtjVafRK0VdZ Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:6JVMr3TcokCtjVafRK0VdZ Dec 07 20:11:42 volumio volumio[1124]: info: Adding Item to queue: spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj Dec 07 20:11:42 volumio volumio[1124]: info: Using cached record of: spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj Dec 07 20:11:42 volumio volumio[1124]: info: CoreCommandRouter::volumioPushQueue Dec 07 20:11:42 volumio volumio[1124]: info: CorePlayQueue::saveQueue Dec 07 20:11:42 volumio volumio[1124]: info: CoreStateMachine::updateTrackBlock Dec 07 20:11:42 volumio volumio[1124]: info: CorePlayQueue::getTrackBlock Dec 07 20:11:42 volumio volumio[1124]: info: CoreCommandRouter::volumioPlay Dec 07 20:11:42 volumio volumio[1124]: info: CoreStateMachine::play index 49 Dec 07 20:11:42 volumio volumio[1124]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 20:11:42 volumio volumio[1124]: info: CoreStateMachine::stop Dec 07 20:11:42 volumio volumio[1124]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 20:11:42 volumio volumio[1124]: info: CoreStateMachine::play index undefined Dec 07 20:11:42 volumio volumio[1124]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 20:11:42 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:42 volumio volumio[1124]: info: CoreStateMachine::startPlaybackTimer Dec 07 20:11:42 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:42 volumio volumio[1124]: info: [1765138302645] ControllerSpotify::clearAddPlayTrack Dec 07 20:11:42 volumio volumio[1124]: info: Sending Spotify command with payload to local API: /player/play Dec 07 20:11:42 volumio volumio[1124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 07 20:11:42 volumio go-librespot[1574]: time="2025-12-07T20:11:42Z" level=debug msg="pause track at 551ms" Dec 07 20:11:42 volumio volumio[1124]: info: touch_display: Setting screensaver timeout to 120 seconds. Dec 07 20:11:42 volumio go-librespot[1574]: time="2025-12-07T20:11:42Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 07 20:11:42 volumio go-librespot[1574]: time="2025-12-07T20:11:42Z" level=debug msg="resolved context of track" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:42 volumio go-librespot[1574]: time="2025-12-07T20:11:42Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:42 volumio go-librespot[1574]: time="2025-12-07T20:11:42Z" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:42 volumio go-librespot[1574]: time="2025-12-07T20:11:42Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 07 20:11:42 volumio go-librespot[1574]: time="2025-12-07T20:11:42Z" level=trace msg="emitting websocket event: will_play" Dec 07 20:11:42 volumio volumio[1124]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","play_origin":"go-librespot"}} Dec 07 20:11:42 volumio go-librespot[1574]: time="2025-12-07T20:11:42Z" level=debug msg="selected format OGG_VORBIS_320 (73f1b393d4b9a72aa5b688dfd7f80fb0e9ff515a)" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:42 volumio go-librespot[1574]: time="2025-12-07T20:11:42Z" level=debug msg="requested aes key for file 73f1b393d4b9a72aa5b688dfd7f80fb0e9ff515a, gid: 2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:42 volumio go-librespot[1574]: time="2025-12-07T20:11:42Z" level=trace msg="found 2 cdn urls" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:42 volumio go-librespot[1574]: time="2025-12-07T20:11:42Z" level=debug msg="fetched first chunk of 23, total size is 11574412 bytes" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:42 volumio go-librespot[1574]: time="2025-12-07T20:11:42Z" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:42 volumio go-librespot[1574]: time="2025-12-07T20:11:42Z" 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" Dec 07 20:11:42 volumio go-librespot[1574]: time="2025-12-07T20:11:42Z" level=info msg="loaded track \"Runaway Train\" (paused: false, position: 1ms, duration: 266613ms, prefetched: false)" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:42 volumio go-librespot[1574]: time="2025-12-07T20:11:42Z" level=debug msg="fetched chunk 3/22, size: 524288" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:43 volumio go-librespot[1574]: time="2025-12-07T20:11:43Z" level=debug msg="fetched chunk 1/22, size: 524288" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:43 volumio go-librespot[1574]: time="2025-12-07T20:11:43Z" level=debug msg="fetched chunk 2/22, size: 524288" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:43 volumio go-librespot[1574]: time="2025-12-07T20:11:43Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 07 20:11:43 volumio go-librespot[1574]: time="2025-12-07T20:11:43Z" level=trace msg="scheduling prefetch in 236s" Dec 07 20:11:43 volumio go-librespot[1574]: time="2025-12-07T20:11:43Z" level=trace msg="emitting websocket event: metadata" Dec 07 20:11:43 volumio volumio[1124]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","name":"Runaway Train","artist_names":["Soul Asylum"],"album_name":"Pure... Guitar Heroes","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","position":1,"duration":266613,"release_date":"year:2010 month:12 day:10","track_number":16,"disc_number":3}} Dec 07 20:11:43 volumio go-librespot[1574]: time="2025-12-07T20:11:43Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 07 20:11:43 volumio go-librespot[1574]: time="2025-12-07T20:11:43Z" level=trace msg="emitting websocket event: paused" Dec 07 20:11:43 volumio volumio[1124]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","play_origin":"go-librespot"}} Dec 07 20:11:43 volumio volumio[1124]: SPOTIFY: PUSH STATE SPOTIFY Dec 07 20:11:43 volumio volumio[1124]: SPOTIFY: {"status":"pause","service":"spop","title":"Runaway Train","artist":"Soul Asylum","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","trackType":"spotify","seek":1,"duration":266,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 07 20:11:43 volumio volumio[1124]: info: CoreCommandRouter::servicePushState Dec 07 20:11:43 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:43 volumio volumio[1124]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Runaway Train","artist":"Soul Asylum","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","trackType":"spotify","seek":1,"duration":266,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 07 20:11:43 volumio volumio[1124]: verbose: CURRENT POSITION 49 Dec 07 20:11:43 volumio volumio[1124]: info: CoreStateMachine::syncState stateService pause Dec 07 20:11:43 volumio volumio[1124]: info: CoreStateMachine::syncState currentStatus stop Dec 07 20:11:43 volumio volumio[1124]: info: CoreStateMachine::pushState Dec 07 20:11:43 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:43 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 20:11:43 volumio volumio[1124]: info: CoreCommandRouter::volumioPushState Dec 07 20:11:43 volumio volumio[1124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 07 20:11:43 volumio go-librespot[1574]: time="2025-12-07T20:11:43Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 07 20:11:43 volumio go-librespot[1574]: time="2025-12-07T20:11:43Z" level=trace msg="emitting websocket event: playing" Dec 07 20:11:43 volumio volumio[1124]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","resume":false,"play_origin":"go-librespot"}} Dec 07 20:11:43 volumio volumio[1124]: SPOTIFY: PUSH STATE SPOTIFY Dec 07 20:11:43 volumio volumio[1124]: SPOTIFY: {"status":"play","service":"spop","title":"Runaway Train","artist":"Soul Asylum","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","trackType":"spotify","seek":1,"duration":266,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 07 20:11:43 volumio volumio[1124]: info: CoreCommandRouter::servicePushState Dec 07 20:11:43 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:43 volumio volumio[1124]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Runaway Train","artist":"Soul Asylum","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","trackType":"spotify","seek":1,"duration":266,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 07 20:11:43 volumio volumio[1124]: verbose: CURRENT POSITION 49 Dec 07 20:11:43 volumio volumio[1124]: info: CoreStateMachine::syncState stateService play Dec 07 20:11:43 volumio volumio[1124]: info: CoreStateMachine::syncState currentStatus stop Dec 07 20:11:43 volumio volumio[1124]: SPOTIFY: PUSH STATE SPOTIFY Dec 07 20:11:43 volumio volumio[1124]: SPOTIFY: {"status":"play","service":"spop","title":"Runaway Train","artist":"Soul Asylum","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","trackType":"spotify","seek":1,"duration":266,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 07 20:11:43 volumio volumio[1124]: info: CoreCommandRouter::servicePushState Dec 07 20:11:43 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:43 volumio volumio[1124]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Runaway Train","artist":"Soul Asylum","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","trackType":"spotify","seek":1,"duration":266,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 07 20:11:43 volumio volumio[1124]: verbose: CURRENT POSITION 49 Dec 07 20:11:43 volumio volumio[1124]: info: CoreStateMachine::syncState stateService play Dec 07 20:11:43 volumio volumio[1124]: info: CoreStateMachine::syncState currentStatus play Dec 07 20:11:43 volumio volumio[1124]: info: Received an update from plugin. extracting info from payload Dec 07 20:11:43 volumio volumio[1124]: info: CoreStateMachine::pushState Dec 07 20:11:43 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:43 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 20:11:43 volumio volumio[1124]: info: CoreCommandRouter::volumioPushState Dec 07 20:11:43 volumio volumio[1124]: info: CoreStateMachine::pushState Dec 07 20:11:43 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:43 volumio volumio[1124]: info: CoreCommandRouter::volumioPushState Dec 07 20:11:43 volumio volumio[1124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 07 20:11:43 volumio volumio[1124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 07 20:11:43 volumio volumio[1124]: info: touch_display: Setting screensaver timeout to 0 seconds. Dec 07 20:11:54 volumio go-librespot[1574]: time="2025-12-07T20:11:54Z" level=debug msg="fetched chunk 4/22, size: 524288" uri="spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj" Dec 07 20:11:54 volumio volumio[1124]: info: Preload queue cleared Dec 07 20:11:54 volumio volumio[1124]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 07 20:11:54 volumio volumio[1124]: info: CoreStateMachine::ClearQueue Dec 07 20:11:54 volumio volumio[1124]: info: CoreStateMachine::stop Dec 07 20:11:54 volumio volumio[1124]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 20:11:54 volumio volumio[1124]: info: CoreStateMachine::stPlaybackTimer Dec 07 20:11:54 volumio volumio[1124]: info: CoreStateMachine::updateTrackBlock Dec 07 20:11:54 volumio volumio[1124]: info: CorePlayQueue::getTrackBlock Dec 07 20:11:54 volumio volumio[1124]: info: CoreStateMachine::pushState Dec 07 20:11:54 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:54 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 20:11:54 volumio volumio[1124]: info: CoreCommandRouter::volumioPushState Dec 07 20:11:54 volumio volumio[1124]: info: CoreStateMachine::serviceStop Dec 07 20:11:54 volumio volumio[1124]: info: CorePlayQueue::getTrack 49 Dec 07 20:11:54 volumio volumio[1124]: info: CoreCommandRouter::serviceStop Dec 07 20:11:54 volumio volumio[1124]: info: Spotify Stop Dec 07 20:11:54 volumio volumio[1124]: SPOTIFY: SPOTIFY STOP Dec 07 20:11:54 volumio volumio[1124]: SPOTIFY: {"status":"play","position":49,"title":"Runaway Train","artist":"Soul Asylum","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d0000b273e15c257226c56421f74fe43d","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","trackType":"spotify","codec":"ogg","seek":1,"duration":266,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Dec 07 20:11:54 volumio volumio[1124]: info: Sending Spotify command to local API: /player/pause Dec 07 20:11:54 volumio volumio[1124]: info: CorePlayQueue::clearPlayQueue Dec 07 20:11:54 volumio volumio[1124]: info: CorePlayQueue::saveQueue Dec 07 20:11:54 volumio volumio[1124]: info: CoreCommandRouter::volumioPushQueue Dec 07 20:11:54 volumio volumio[1124]: info: CoreStateMachine::addQueueItems Dec 07 20:11:54 volumio volumio[1124]: info: CorePlayQueue::addQueueItems Dec 07 20:11:54 volumio volumio[1124]: info: Preload queue cleared Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:65O6GbjtemClygCr7kw0Vn Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:65O6GbjtemClygCr7kw0Vn Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:71gsZTXQxiVB1N4JzXcLXq Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:71gsZTXQxiVB1N4JzXcLXq Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:6hVSmYapASfFhWIUmksBY2 Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:6hVSmYapASfFhWIUmksBY2 Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:788AStPNtuuK5CxD5enb2O Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:788AStPNtuuK5CxD5enb2O Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:509K9DfXVUypqa1xAm5ZxV Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:509K9DfXVUypqa1xAm5ZxV Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:0jxV5krDErIi6X4DCGtqzC Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:0jxV5krDErIi6X4DCGtqzC Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:6Tf0ZFu4ICrVaSYLNEblHl Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:6Tf0ZFu4ICrVaSYLNEblHl Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:524d5WfipgMzb1TMWhrSe2 Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:524d5WfipgMzb1TMWhrSe2 Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4Ntidy5rQYaH1UzqQ5AKh6 Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:4Ntidy5rQYaH1UzqQ5AKh6 Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4dLxpsHnrfhcwFjVfd9yxP Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:4dLxpsHnrfhcwFjVfd9yxP Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:2b9l0r4V5FX18EygPoB6aR Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:2b9l0r4V5FX18EygPoB6aR Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:0yBNAZCLkL9xrr73qjydbN Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:0yBNAZCLkL9xrr73qjydbN Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4qgVZRu9oHg6e96cTRaaCP Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:4qgVZRu9oHg6e96cTRaaCP Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:3t6gawmmTTm1BVuVuIhhuu Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:3t6gawmmTTm1BVuVuIhhuu Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:1sbiUfrWQ62bSqSjlTMlFY Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:1sbiUfrWQ62bSqSjlTMlFY Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:7iK6prZV8li4kdE0LJPlZ0 Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:7iK6prZV8li4kdE0LJPlZ0 Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:1PlITqDGKanxzzvEITCgPf Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:1PlITqDGKanxzzvEITCgPf Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:3JFDNEbmTMepSDBIDbWk5z Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:3JFDNEbmTMepSDBIDbWk5z Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:3vXvdDXZe0V2sDK23LNJk9 Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:3vXvdDXZe0V2sDK23LNJk9 Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:14X4kwctPfMUrS1meeIUmC Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:14X4kwctPfMUrS1meeIUmC Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:60US1f3AWpYJrZNKKdNquZ Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:60US1f3AWpYJrZNKKdNquZ Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:57YWnVgpSpzXpZygg6eJfW Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:57YWnVgpSpzXpZygg6eJfW Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:1g3YIuFoSOTmuiFYfsahT3 Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:1g3YIuFoSOTmuiFYfsahT3 Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:19Znqx8oR4IMVpPDNZ6aDo Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:19Znqx8oR4IMVpPDNZ6aDo Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:2K22Gk2wC7tH5j0Pm6JAEc Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:2K22Gk2wC7tH5j0Pm6JAEc Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:2azSTTlDg0VNNGxGsD3iDQ Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:2azSTTlDg0VNNGxGsD3iDQ Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:3YNaliQzXAmnxxFbTIG1S3 Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:3YNaliQzXAmnxxFbTIG1S3 Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:3QNalg8Q83fCmaz5efca2t Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:3QNalg8Q83fCmaz5efca2t Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:0fOMOAGNeR6Ic9IySipUmT Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:0fOMOAGNeR6Ic9IySipUmT Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:7IPFX6AoiukSRnSevDPOCG Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:7IPFX6AoiukSRnSevDPOCG Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:2n1xGch3RCfNTS0SuTqB2D Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:2n1xGch3RCfNTS0SuTqB2D Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:40RB5XoVDPV4lQKHGvkMWd Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:40RB5XoVDPV4lQKHGvkMWd Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:7tICXJscOvTktERqbl5qdT Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:7tICXJscOvTktERqbl5qdT Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:49BOFvmMR12hChCNZNutVU Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:49BOFvmMR12hChCNZNutVU Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:7inusJXRvhFQl6XZe062HB Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:7inusJXRvhFQl6XZe062HB Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:7vN8vReDIiGFYLqbF3XSyC Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:7vN8vReDIiGFYLqbF3XSyC Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:31icXNIFjX9YQ9z7I1UAz8 Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:31icXNIFjX9YQ9z7I1UAz8 Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:3nBc8pa5CucsWR7fkMr9iO Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:3nBc8pa5CucsWR7fkMr9iO Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:6igOUEOwKLRfHQ6NmYRRDM Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:6igOUEOwKLRfHQ6NmYRRDM Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:46iQAzV1N16XiQcXjYOETT Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:46iQAzV1N16XiQcXjYOETT Dec 07 20:11:54 volumio volumio[1124]: info: CoreCommandRouter::volumioPushQueue Dec 07 20:11:54 volumio volumio[1124]: info: CorePlayQueue::saveQueue Dec 07 20:11:54 volumio volumio[1124]: info: CoreStateMachine::updateTrackBlock Dec 07 20:11:54 volumio volumio[1124]: info: CorePlayQueue::getTrackBlock Dec 07 20:11:54 volumio volumio[1124]: info: CoreCommandRouter::volumioPlay Dec 07 20:11:54 volumio volumio[1124]: info: CoreStateMachine::play index 39 Dec 07 20:11:54 volumio volumio[1124]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 20:11:54 volumio volumio[1124]: info: CoreStateMachine::addQueueItems Dec 07 20:11:54 volumio volumio[1124]: info: CorePlayQueue::addQueueItems Dec 07 20:11:54 volumio volumio[1124]: info: Preload queue cleared Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:7oy880fepIH46YlcwfhyFJ Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:7oy880fepIH46YlcwfhyFJ Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:0FGUQRHYmxcQ9U3a6DVHE2 Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:0FGUQRHYmxcQ9U3a6DVHE2 Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4CNL4GBNTdVIU5Nk6hB4LC Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:4CNL4GBNTdVIU5Nk6hB4LC Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4gzc5PFLNN0M8TWwGj5PnF Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:4gzc5PFLNN0M8TWwGj5PnF Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4Pjv2kNzpuUtMVdoSqegnq Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:4Pjv2kNzpuUtMVdoSqegnq Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:4oneNquOUM0AzuFEhEWiGE Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:4oneNquOUM0AzuFEhEWiGE Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:5jbqwoIn1xcbVmVjDd8ZB6 Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:5jbqwoIn1xcbVmVjDd8ZB6 Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:0rEmsXJxxrgD0cEqY7dUP2 Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:0rEmsXJxxrgD0cEqY7dUP2 Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:6JVMr3TcokCtjVafRK0VdZ Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:6JVMr3TcokCtjVafRK0VdZ Dec 07 20:11:54 volumio volumio[1124]: info: Adding Item to queue: spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj Dec 07 20:11:54 volumio volumio[1124]: info: Using cached record of: spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj Dec 07 20:11:54 volumio volumio[1124]: info: CoreStateMachine::stop Dec 07 20:11:54 volumio volumio[1124]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 20:11:54 volumio volumio[1124]: info: CoreCommandRouter::volumioPushQueue Dec 07 20:11:54 volumio volumio[1124]: info: CorePlayQueue::saveQueue Dec 07 20:11:54 volumio volumio[1124]: info: CoreStateMachine::play index undefined Dec 07 20:11:54 volumio volumio[1124]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 20:11:54 volumio volumio[1124]: info: CoreStateMachine::updateTrackBlock Dec 07 20:11:54 volumio volumio[1124]: info: CorePlayQueue::getTrackBlock Dec 07 20:11:54 volumio volumio[1124]: info: CorePlayQueue::getTrack 39 Dec 07 20:11:54 volumio volumio[1124]: info: CoreStateMachine::startPlaybackTimer Dec 07 20:11:54 volumio volumio[1124]: info: CorePlayQueue::getTrack 39 Dec 07 20:11:54 volumio volumio[1124]: info: [1765138314877] ControllerSpotify::clearAddPlayTrack Dec 07 20:11:54 volumio volumio[1124]: info: Sending Spotify command with payload to local API: /player/play Dec 07 20:11:54 volumio volumio[1124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 07 20:11:54 volumio go-librespot[1574]: time="2025-12-07T20:11:54Z" level=debug msg="pause track at 11987ms" Dec 07 20:11:54 volumio volumio[1124]: info: touch_display: Setting screensaver timeout to 120 seconds. Dec 07 20:11:54 volumio go-librespot[1574]: time="2025-12-07T20:11:54Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=trace msg="emitting websocket event: paused" Dec 07 20:11:55 volumio volumio[1124]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","uri":"spotify:track:2Mgd0DNZQjCTUwgNXxw6Lj","play_origin":"go-librespot"}} Dec 07 20:11:55 volumio volumio[1124]: SPOTIFY: PUSH STATE SPOTIFY Dec 07 20:11:55 volumio volumio[1124]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 07 20:11:55 volumio volumio[1124]: info: CoreCommandRouter::servicePushState Dec 07 20:11:55 volumio volumio[1124]: info: CorePlayQueue::getTrack 39 Dec 07 20:11:55 volumio volumio[1124]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 07 20:11:55 volumio volumio[1124]: verbose: CURRENT POSITION 39 Dec 07 20:11:55 volumio volumio[1124]: info: CoreStateMachine::syncState stateService pause Dec 07 20:11:55 volumio volumio[1124]: info: CoreStateMachine::syncState currentStatus stop Dec 07 20:11:55 volumio volumio[1124]: info: CoreStateMachine::pushState Dec 07 20:11:55 volumio volumio[1124]: info: CorePlayQueue::getTrack 39 Dec 07 20:11:55 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 20:11:55 volumio volumio[1124]: info: CoreCommandRouter::volumioPushState Dec 07 20:11:55 volumio volumio[1124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=debug msg="resolved context of track" uri="spotify:track:46iQAzV1N16XiQcXjYOETT" Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:46iQAzV1N16XiQcXjYOETT" Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:46iQAzV1N16XiQcXjYOETT" Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=trace msg="emitting websocket event: will_play" Dec 07 20:11:55 volumio volumio[1124]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:46iQAzV1N16XiQcXjYOETT","uri":"spotify:track:46iQAzV1N16XiQcXjYOETT","play_origin":"go-librespot"}} Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=debug msg="selected format OGG_VORBIS_320 (242426be3989ccd884e48aa67e5d2f942bd15e78)" uri="spotify:track:46iQAzV1N16XiQcXjYOETT" Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=debug msg="requested aes key for file 242426be3989ccd884e48aa67e5d2f942bd15e78, gid: 46iQAzV1N16XiQcXjYOETT" Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=trace msg="found 2 cdn urls" uri="spotify:track:46iQAzV1N16XiQcXjYOETT" Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=debug msg="fetched first chunk of 19, total size is 9455496 bytes" uri="spotify:track:46iQAzV1N16XiQcXjYOETT" Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" 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" Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=info msg="loaded track \"She Caught the Katy and Left Me a Mule to Ride\" (paused: false, position: 0ms, duration: 206986ms, prefetched: false)" uri="spotify:track:46iQAzV1N16XiQcXjYOETT" Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:46iQAzV1N16XiQcXjYOETT" Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:46iQAzV1N16XiQcXjYOETT" Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=trace msg="scheduling prefetch in 177s" Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=trace msg="emitting websocket event: metadata" Dec 07 20:11:55 volumio volumio[1124]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:46iQAzV1N16XiQcXjYOETT","name":"She Caught the Katy and Left Me a Mule to Ride","artist_names":["Taj Mahal"],"album_name":"Pure... Guitar Heroes","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","position":0,"duration":206986,"release_date":"year:2010 month:12 day:10","track_number":6,"disc_number":3}} Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:46iQAzV1N16XiQcXjYOETT" Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 07 20:11:55 volumio go-librespot[1574]: time="2025-12-07T20:11:55Z" level=trace msg="emitting websocket event: playing" Dec 07 20:11:55 volumio volumio[1124]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:46iQAzV1N16XiQcXjYOETT","uri":"spotify:track:46iQAzV1N16XiQcXjYOETT","resume":false,"play_origin":"go-librespot"}} Dec 07 20:11:55 volumio volumio[1124]: SPOTIFY: PUSH STATE SPOTIFY Dec 07 20:11:55 volumio volumio[1124]: SPOTIFY: {"status":"play","service":"spop","title":"She Caught the Katy and Left Me a Mule to Ride","artist":"Taj Mahal","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","uri":"spotify:track:46iQAzV1N16XiQcXjYOETT","trackType":"spotify","seek":0,"duration":206,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 07 20:11:55 volumio volumio[1124]: info: CoreCommandRouter::servicePushState Dec 07 20:11:55 volumio volumio[1124]: info: CorePlayQueue::getTrack 39 Dec 07 20:11:55 volumio volumio[1124]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"She Caught the Katy and Left Me a Mule to Ride","artist":"Taj Mahal","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","uri":"spotify:track:46iQAzV1N16XiQcXjYOETT","trackType":"spotify","seek":0,"duration":206,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 07 20:11:55 volumio volumio[1124]: verbose: CURRENT POSITION 39 Dec 07 20:11:55 volumio volumio[1124]: info: CoreStateMachine::syncState stateService play Dec 07 20:11:55 volumio volumio[1124]: info: CoreStateMachine::syncState currentStatus stop Dec 07 20:11:55 volumio volumio[1124]: SPOTIFY: PUSH STATE SPOTIFY Dec 07 20:11:55 volumio volumio[1124]: SPOTIFY: {"status":"play","service":"spop","title":"She Caught the Katy and Left Me a Mule to Ride","artist":"Taj Mahal","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","uri":"spotify:track:46iQAzV1N16XiQcXjYOETT","trackType":"spotify","seek":0,"duration":206,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 07 20:11:55 volumio volumio[1124]: info: CoreCommandRouter::servicePushState Dec 07 20:11:55 volumio volumio[1124]: info: CorePlayQueue::getTrack 39 Dec 07 20:11:55 volumio volumio[1124]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"She Caught the Katy and Left Me a Mule to Ride","artist":"Taj Mahal","album":"Pure... Guitar Heroes","albumart":"https://i.scdn.co/image/ab67616d00001e02e15c257226c56421f74fe43d","uri":"spotify:track:46iQAzV1N16XiQcXjYOETT","trackType":"spotify","seek":0,"duration":206,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 07 20:11:55 volumio volumio[1124]: verbose: CURRENT POSITION 39 Dec 07 20:11:55 volumio volumio[1124]: info: CoreStateMachine::syncState stateService play Dec 07 20:11:55 volumio volumio[1124]: info: CoreStateMachine::syncState currentStatus play Dec 07 20:11:55 volumio volumio[1124]: info: Received an update from plugin. extracting info from payload Dec 07 20:11:55 volumio volumio[1124]: info: CoreStateMachine::pushState Dec 07 20:11:55 volumio volumio[1124]: info: CorePlayQueue::getTrack 39 Dec 07 20:11:55 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 20:11:55 volumio volumio[1124]: info: CoreCommandRouter::volumioPushState Dec 07 20:11:55 volumio volumio[1124]: info: CoreStateMachine::pushState Dec 07 20:11:55 volumio volumio[1124]: info: CorePlayQueue::getTrack 39 Dec 07 20:11:55 volumio volumio[1124]: info: CoreCommandRouter::volumioPushState Dec 07 20:11:55 volumio volumio[1124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 07 20:11:55 volumio volumio[1124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 07 20:11:55 volumio volumio[1124]: info: touch_display: Setting screensaver timeout to 0 seconds. Dec 07 20:12:04 volumio go-librespot[1574]: time="2025-12-07T20:12:04Z" level=trace msg="sent dealer ping" Dec 07 20:12:04 volumio go-librespot[1574]: time="2025-12-07T20:12:04Z" level=trace msg="received dealer pong" Dec 07 20:12:06 volumio go-librespot[1574]: time="2025-12-07T20:12:06Z" level=debug msg="fetched chunk 4/18, size: 524288" uri="spotify:track:46iQAzV1N16XiQcXjYOETT" Dec 07 20:12:18 volumio go-librespot[1574]: time="2025-12-07T20:12:18Z" level=debug msg="fetched chunk 5/18, size: 524288" uri="spotify:track:46iQAzV1N16XiQcXjYOETT" Dec 07 20:12:29 volumio go-librespot[1574]: time="2025-12-07T20:12:29Z" level=debug msg="fetched chunk 6/18, size: 524288" uri="spotify:track:46iQAzV1N16XiQcXjYOETT" Dec 07 20:12:34 volumio go-librespot[1574]: time="2025-12-07T20:12:34Z" level=trace msg="sent dealer ping" Dec 07 20:12:34 volumio go-librespot[1574]: time="2025-12-07T20:12:34Z" level=trace msg="received dealer pong" Dec 07 20:12:40 volumio go-librespot[1574]: time="2025-12-07T20:12:40Z" level=debug msg="fetched chunk 7/18, size: 524288" uri="spotify:track:46iQAzV1N16XiQcXjYOETT" Dec 07 20:12:51 volumio go-librespot[1574]: time="2025-12-07T20:12:51Z" level=debug msg="fetched chunk 8/18, size: 524288" uri="spotify:track:46iQAzV1N16XiQcXjYOETT" Dec 07 20:12:54 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Dec 07 20:12:54 volumio volumio[1124]: info: In handleBrowseUri, curUri=spotify:artist:7rf08eiRVNitesaNgy41tG Dec 07 20:12:55 volumio volumio[1124]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 20:12:55 volumio volumio[1124]: TypeError: Cannot read properties of undefined (reading 'url') Dec 07 20:12:55 volumio volumio[1124]: at /data/plugins/music_service/spop/index.js:2449:60 Dec 07 20:12:55 volumio volumio[1124]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Dec 07 20:12:55 volumio volumio[1124]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 20:12:56 volumio sudo[6007]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-07 20:11' Dec 07 20:12:56 volumio sudo[6007]: 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="3a3cfe435f8bb2bc94a920662e91a4ef35bc8e7c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="8bcc10c3dbcbcb349e9887dc0527d54876b32688" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Dec 2 11:51:19 UTC 2025" VOLUMIO_VERSION="4.072" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e5001581b220b096097cf8f46a54d4f1"