Mar 24 19:49:11 volumio go-librespot[1408]: time="2026-03-24T19:49:11+01:00" level=debug msg="fetched chunk 8/35, size: 524288" uri="spotify:track:3uikQKO7o4usH0Cppu2zW0" Mar 24 19:49:23 volumio go-librespot[1408]: time="2026-03-24T19:49:23+01:00" level=trace msg="sent dealer ping" Mar 24 19:49:23 volumio go-librespot[1408]: time="2026-03-24T19:49:23+01:00" level=debug msg="fetched chunk 9/35, size: 524288" uri="spotify:track:3uikQKO7o4usH0Cppu2zW0" Mar 24 19:49:23 volumio go-librespot[1408]: time="2026-03-24T19:49:23+01:00" level=trace msg="received dealer pong" Mar 24 19:49:36 volumio go-librespot[1408]: time="2026-03-24T19:49:36+01:00" level=debug msg="fetched chunk 10/35, size: 524288" uri="spotify:track:3uikQKO7o4usH0Cppu2zW0" Mar 24 19:49:36 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Mar 24 19:49:36 volumio dbus-daemon[578]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.78' (uid=0 pid=5446 comm="timedatectl show --property=NTPSynchronized --valu") Mar 24 19:49:36 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... Mar 24 19:49:36 volumio dbus-daemon[578]: [system] Successfully activated service 'org.freedesktop.timedate1' Mar 24 19:49:36 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. Mar 24 19:49:36 volumio setdatetime-helper.sh[5445]: Time is already synchronized. Mar 24 19:49:36 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Mar 24 19:49:36 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Mar 24 19:49:48 volumio go-librespot[1408]: time="2026-03-24T19:49:48+01:00" level=debug msg="fetched chunk 11/35, size: 524288" uri="spotify:track:3uikQKO7o4usH0Cppu2zW0" Mar 24 19:49:53 volumio go-librespot[1408]: time="2026-03-24T19:49:53+01:00" level=trace msg="sent dealer ping" Mar 24 19:49:53 volumio go-librespot[1408]: time="2026-03-24T19:49:53+01:00" level=trace msg="received dealer pong" Mar 24 19:49:59 volumio go-librespot[1408]: time="2026-03-24T19:49:59+01:00" level=debug msg="fetched chunk 12/35, size: 524288" uri="spotify:track:3uikQKO7o4usH0Cppu2zW0" Mar 24 19:50:04 volumio wpa_supplicant[1003]: wlan0: WPA: Group rekeying completed with a0:2d:13:50:fa:95 [GTK=CCMP] Mar 24 19:50:06 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. Mar 24 19:50:10 volumio go-librespot[1408]: time="2026-03-24T19:50:10+01:00" level=debug msg="fetched chunk 13/35, size: 524288" uri="spotify:track:3uikQKO7o4usH0Cppu2zW0" Mar 24 19:50:11 volumio volumio[1098]: info: VolumeController::SetAlsaVolume73 Mar 24 19:50:11 volumio volumio[1098]: info: CoreStateMachine::pushState Mar 24 19:50:11 volumio volumio[1098]: info: CorePlayQueue::getTrack 10 Mar 24 19:50:11 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 19:50:11 volumio volumio[1098]: info: CoreCommandRouter::volumioPushState Mar 24 19:50:11 volumio volumio[1098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 Mar 24 19:50:11 volumio volumio[1098]: SPOTIFY: SPOTIFY VOLUME 86 Mar 24 19:50:11 volumio volumio[1098]: SPOTIFY: VOLUMIO VOLUME 73 Mar 24 19:50:11 volumio volumio[1098]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 24 19:50:11 volumio volumio[1098]: info: Setting Spotify Volume from Volumio: 73 Mar 24 19:50:11 volumio volumio[1098]: info: VolumeController::SetAlsaVolume67 Mar 24 19:50:11 volumio volumio[1098]: info: CoreStateMachine::pushState Mar 24 19:50:11 volumio volumio[1098]: info: CorePlayQueue::getTrack 10 Mar 24 19:50:11 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 19:50:11 volumio volumio[1098]: info: CoreCommandRouter::volumioPushState Mar 24 19:50:11 volumio volumio[1098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 67 Mar 24 19:50:11 volumio volumio[1098]: SPOTIFY: SPOTIFY VOLUME 73 Mar 24 19:50:11 volumio volumio[1098]: SPOTIFY: VOLUMIO VOLUME 67 Mar 24 19:50:11 volumio volumio[1098]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 24 19:50:11 volumio volumio[1098]: info: Setting Spotify Volume from Volumio: 67 Mar 24 19:50:12 volumio volumio[1098]: info: VolumeController::SetAlsaVolume66 Mar 24 19:50:12 volumio volumio[1098]: info: CoreStateMachine::pushState Mar 24 19:50:12 volumio volumio[1098]: info: CorePlayQueue::getTrack 10 Mar 24 19:50:12 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 19:50:12 volumio volumio[1098]: info: CoreCommandRouter::volumioPushState Mar 24 19:50:12 volumio volumio[1098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Mar 24 19:50:12 volumio volumio[1098]: SPOTIFY: SPOTIFY VOLUME 67 Mar 24 19:50:12 volumio volumio[1098]: SPOTIFY: VOLUMIO VOLUME 66 Mar 24 19:50:12 volumio volumio[1098]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 24 19:50:13 volumio volumio[1098]: SPOTIFY: SETTING SPOTIFY VOLUME 67 Mar 24 19:50:13 volumio volumio[1098]: info: Sending Spotify command with payload to local API: /player/volume Mar 24 19:50:13 volumio go-librespot[1408]: time="2026-03-24T19:50:13+01:00" level=debug msg="update volume requested to 43908/65535" Mar 24 19:50:13 volumio go-librespot[1408]: time="2026-03-24T19:50:13+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 24 19:50:13 volumio go-librespot[1408]: time="2026-03-24T19:50:13+01:00" level=trace msg="emitting websocket event: volume" Mar 24 19:50:13 volumio volumio[1098]: SPOTIFY: received: {"type":"volume","data":{"value":67,"max":100}} Mar 24 19:50:13 volumio volumio[1098]: SPOTIFY: RECEIVED SPOTIFY VOLUME 67 Mar 24 19:50:15 volumio volumio[1098]: info: Preload queue cleared Mar 24 19:50:15 volumio volumio[1098]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 24 19:50:15 volumio volumio[1098]: info: CoreStateMachine::ClearQueue Mar 24 19:50:15 volumio volumio[1098]: info: CoreStateMachine::stop Mar 24 19:50:15 volumio volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 19:50:15 volumio volumio[1098]: info: CoreStateMachine::stPlaybackTimer Mar 24 19:50:15 volumio volumio[1098]: info: CoreStateMachine::updateTrackBlock Mar 24 19:50:15 volumio volumio[1098]: info: CorePlayQueue::getTrackBlock Mar 24 19:50:15 volumio volumio[1098]: info: CoreStateMachine::pushState Mar 24 19:50:15 volumio volumio[1098]: info: CorePlayQueue::getTrack 10 Mar 24 19:50:15 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 19:50:15 volumio volumio[1098]: info: CoreCommandRouter::volumioPushState Mar 24 19:50:15 volumio volumio[1098]: info: CoreStateMachine::serviceStop Mar 24 19:50:15 volumio volumio[1098]: info: CorePlayQueue::getTrack 10 Mar 24 19:50:15 volumio volumio[1098]: info: CoreCommandRouter::serviceStop Mar 24 19:50:15 volumio volumio[1098]: info: Spotify Stop Mar 24 19:50:15 volumio volumio[1098]: SPOTIFY: SPOTIFY STOP Mar 24 19:50:15 volumio volumio[1098]: SPOTIFY: {"status":"play","position":10,"title":"Son Of A Gun - Red Jerry / JX Mix","artist":"JX","album":"Son Of A Gun '95","albumart":"https://i.scdn.co/image/ab67616d0000b2730036cbc499344eb0a6438a09","uri":"spotify:track:3uikQKO7o4usH0Cppu2zW0","trackType":"spotify","codec":"ogg","seek":124125,"duration":455,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":66,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Mar 24 19:50:15 volumio volumio[1098]: info: Sending Spotify command to local API: /player/pause Mar 24 19:50:15 volumio volumio[1098]: info: CorePlayQueue::clearPlayQueue Mar 24 19:50:15 volumio volumio[1098]: info: CorePlayQueue::saveQueue Mar 24 19:50:15 volumio volumio[1098]: info: CoreCommandRouter::volumioPushQueue Mar 24 19:50:15 volumio volumio[1098]: info: CoreStateMachine::addQueueItems Mar 24 19:50:15 volumio volumio[1098]: info: CorePlayQueue::addQueueItems Mar 24 19:50:15 volumio volumio[1098]: info: Preload queue cleared Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4bPISajsmjQCxxMxGjBptX Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:4bPISajsmjQCxxMxGjBptX Mar 24 19:50:15 volumio volumio[1098]: info: CoreCommandRouter::volumioPushQueue Mar 24 19:50:15 volumio volumio[1098]: info: CorePlayQueue::saveQueue Mar 24 19:50:15 volumio volumio[1098]: info: CoreStateMachine::updateTrackBlock Mar 24 19:50:15 volumio volumio[1098]: info: CorePlayQueue::getTrackBlock Mar 24 19:50:15 volumio volumio[1098]: info: CoreCommandRouter::volumioPlay Mar 24 19:50:15 volumio volumio[1098]: info: CoreStateMachine::play index 0 Mar 24 19:50:15 volumio volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 19:50:15 volumio volumio[1098]: info: CoreStateMachine::addQueueItems Mar 24 19:50:15 volumio volumio[1098]: info: CorePlayQueue::addQueueItems Mar 24 19:50:15 volumio volumio[1098]: info: Preload queue cleared Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:5tPb2lVWoAVpXb2uyeym0I Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:5tPb2lVWoAVpXb2uyeym0I Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:2NzbyKz5nIunufVMli0Nqz Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:2NzbyKz5nIunufVMli0Nqz Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:1cQld05IcUDw3RCFt7uymW Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:1cQld05IcUDw3RCFt7uymW Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4Vucb0U4wsbbuzAiy61KUl Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:4Vucb0U4wsbbuzAiy61KUl Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:3mcbwkZCEAWEU2MBpje159 Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:3mcbwkZCEAWEU2MBpje159 Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:6MTsfDyLSejmtQtyD2ORr2 Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:6MTsfDyLSejmtQtyD2ORr2 Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:59NraMJsLaMCVtwXTSia8i Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:59NraMJsLaMCVtwXTSia8i Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:7fZBQnc0zXwVybgCIrQQil Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:7fZBQnc0zXwVybgCIrQQil Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:2YuUy4hBCVm4L5IRHu0iVl Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:2YuUy4hBCVm4L5IRHu0iVl Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:3uikQKO7o4usH0Cppu2zW0 Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:3uikQKO7o4usH0Cppu2zW0 Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:2FQrifJ1N335Ljm3TjTVVf Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:2FQrifJ1N335Ljm3TjTVVf Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:5ZLUm9eab8y3tqQ1OhQSHI Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:5ZLUm9eab8y3tqQ1OhQSHI Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4aB1eZWam3I3WkzzZxlGVo Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:4aB1eZWam3I3WkzzZxlGVo Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:3x3oEFoQzTwqrMLj6Zufgf Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:3x3oEFoQzTwqrMLj6Zufgf Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4KfSdst7rW39C0sfhArdrz Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:4KfSdst7rW39C0sfhArdrz Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:31MOjWj3CT3dCQsMV2b8Wu Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:31MOjWj3CT3dCQsMV2b8Wu Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:3lGyt8enqenwyqXihI6AVr Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:3lGyt8enqenwyqXihI6AVr Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:2u8MGAiS2hBVE7GZzTZLQI Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:2u8MGAiS2hBVE7GZzTZLQI Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:31TXxq8gfgYyrYClnYY48m Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:31TXxq8gfgYyrYClnYY48m Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: ytmusic/video@explodeTrackData:o=%7B%22type%22%3A%22video%22%2C%22title%22%3A%22Take%20Control%22%2C%22artist%22%3A%22Bexxie%20%26%20Towera%22%2C%22album%22%3A%22%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FjtxeGK5Hwm0%2Fsddefault.jpg%3Fsqp%3D-oaymwEWCJADEOEBIAQqCghqEJQEGHgg6AJIWg%26rs%3DAMzJL3mXjNk7Be4ktO3B0Ej_4SpilOWkKw%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22jtxeGK5Hwm0%22%2C%22playlistId%22%3A%22RDCLAK5uy_lGiQTUU4XxGV7l9L5YJ3sV0zomDirmZTM%22%2C%22params%22%3A%228gECGAM%253D%22%2C%22playlistSetVideoId%22%3A%222B6EFA1B1F897EAC%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_OMV%22%7D%2C%22autoplayContext%22%3A%7B%22fetchEndpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22playlistId%22%3A%22RDCLAK5uy_lGiQTUU4XxGV7l9L5YJ3sV0zomDirmZTM%22%2C%22params%22%3A%228gECGAM%253D%22%2C%22videoId%22%3A%22wu3tmq_QPLo%22%7D%7D%7D%7D Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: ytmusic/video@explodeTrackData:o=%7B%22type%22%3A%22video%22%2C%22title%22%3A%22Take%20Control%22%2C%22artist%22%3A%22Bexxie%20%26%20Towera%22%2C%22album%22%3A%22%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FjtxeGK5Hwm0%2Fsddefault.jpg%3Fsqp%3D-oaymwEWCJADEOEBIAQqCghqEJQEGHgg6AJIWg%26rs%3DAMzJL3mXjNk7Be4ktO3B0Ej_4SpilOWkKw%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22jtxeGK5Hwm0%22%2C%22playlistId%22%3A%22RDCLAK5uy_lGiQTUU4XxGV7l9L5YJ3sV0zomDirmZTM%22%2C%22params%22%3A%228gECGAM%253D%22%2C%22playlistSetVideoId%22%3A%222B6EFA1B1F897EAC%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_OMV%22%7D%2C%22autoplayContext%22%3A%7B%22fetchEndpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22playlistId%22%3A%22RDCLAK5uy_lGiQTUU4XxGV7l9L5YJ3sV0zomDirmZTM%22%2C%22params%22%3A%228gECGAM%253D%22%2C%22videoId%22%3A%22wu3tmq_QPLo%22%7D%7D%7D%7D Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:0svl7cK07gK1ia5ainczU5 Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:0svl7cK07gK1ia5ainczU5 Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:2JyoTSZozy8aQmEOLw2nA7 Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:2JyoTSZozy8aQmEOLw2nA7 Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4OTw5splgMdlYklwHMHxLK Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:4OTw5splgMdlYklwHMHxLK Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:0u6JFVn0KHHlidZxNL9gVE Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:0u6JFVn0KHHlidZxNL9gVE Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:0u6JFVn0KHHlidZxNL9gVE Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:0u6JFVn0KHHlidZxNL9gVE Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:3Jnxngdff0lVu2rza1GVx6 Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:3Jnxngdff0lVu2rza1GVx6 Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:2dpO3NteNWUDL2S9e0t0Mi Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:2dpO3NteNWUDL2S9e0t0Mi Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4v2rkl1mC3zVAz0nXMx9r4 Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:4v2rkl1mC3zVAz0nXMx9r4 Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4feNlb6HlpBrW36SsXoUfh Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:4feNlb6HlpBrW36SsXoUfh Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:6kSSORnF2vhzDpGftPXNWz Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:6kSSORnF2vhzDpGftPXNWz Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:6ObOQwjP7hycMhlYbSJuvk Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:6ObOQwjP7hycMhlYbSJuvk Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:1fhx6MlQPiT6FKa6IolKZh Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:1fhx6MlQPiT6FKa6IolKZh Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4VxTzYm00mg82MuoT35Ja7 Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:4VxTzYm00mg82MuoT35Ja7 Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:6x6bkynh0Yfkgl3ygOEF3X Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:6x6bkynh0Yfkgl3ygOEF3X Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4A0rGm3Op4EjzNT4mCn6Na Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:4A0rGm3Op4EjzNT4mCn6Na Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:5rzS6Q74tWi0EJijvxNMF9 Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:5rzS6Q74tWi0EJijvxNMF9 Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:07QwNQfpAirTUv7zkEKI2N Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:07QwNQfpAirTUv7zkEKI2N Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:0OUd9wYBep0wPt3Gck95sB Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:0OUd9wYBep0wPt3Gck95sB Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4paPZYcTcMQmY6hX9JFfiC Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:4paPZYcTcMQmY6hX9JFfiC Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:55lijDD6OAjLFFUHU9tcDm Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:55lijDD6OAjLFFUHU9tcDm Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:3TWpz0iK17gFlxWlIs3MIQ Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:3TWpz0iK17gFlxWlIs3MIQ Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4wqIXeDppYSMXaWsnTzpzT Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:4wqIXeDppYSMXaWsnTzpzT Mar 24 19:50:15 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4paPZYcTcMQmY6hX9JFfiC Mar 24 19:50:15 volumio volumio[1098]: info: Using cached record of: spotify:track:4paPZYcTcMQmY6hX9JFfiC Mar 24 19:50:15 volumio volumio[1098]: info: CoreStateMachine::stop Mar 24 19:50:15 volumio volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 19:50:15 volumio volumio[1098]: info: CoreCommandRouter::volumioPushQueue Mar 24 19:50:15 volumio volumio[1098]: info: CorePlayQueue::saveQueue Mar 24 19:50:15 volumio volumio[1098]: info: CoreStateMachine::play index undefined Mar 24 19:50:15 volumio volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 19:50:15 volumio volumio[1098]: info: CoreStateMachine::updateTrackBlock Mar 24 19:50:15 volumio volumio[1098]: info: CorePlayQueue::getTrackBlock Mar 24 19:50:15 volumio volumio[1098]: info: CorePlayQueue::getTrack 0 Mar 24 19:50:15 volumio volumio[1098]: info: CoreStateMachine::startPlaybackTimer Mar 24 19:50:15 volumio volumio[1098]: info: CorePlayQueue::getTrack 0 Mar 24 19:50:15 volumio volumio[1098]: info: [1774378215638] ControllerSpotify::clearAddPlayTrack Mar 24 19:50:15 volumio volumio[1098]: info: Sending Spotify command with payload to local API: /player/play Mar 24 19:50:15 volumio volumio[1098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Mar 24 19:50:15 volumio volumio[1098]: SPOTIFY: SPOTIFY VOLUME 67 Mar 24 19:50:15 volumio volumio[1098]: SPOTIFY: VOLUMIO VOLUME 66 Mar 24 19:50:15 volumio volumio[1098]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 24 19:50:15 volumio go-librespot[1408]: time="2026-03-24T19:50:15+01:00" level=debug msg="pause track at 127279ms" Mar 24 19:50:15 volumio volumio[1098]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 24 19:50:15 volumio go-librespot[1408]: time="2026-03-24T19:50:15+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 19:50:15 volumio go-librespot[1408]: time="2026-03-24T19:50:15+01:00" level=debug msg="resolved context of track" uri="spotify:track:4bPISajsmjQCxxMxGjBptX" Mar 24 19:50:15 volumio go-librespot[1408]: time="2026-03-24T19:50:15+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:4bPISajsmjQCxxMxGjBptX" Mar 24 19:50:15 volumio go-librespot[1408]: time="2026-03-24T19:50:15+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:4bPISajsmjQCxxMxGjBptX" Mar 24 19:50:15 volumio go-librespot[1408]: time="2026-03-24T19:50:15+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 19:50:15 volumio go-librespot[1408]: time="2026-03-24T19:50:15+01:00" level=trace msg="emitting websocket event: will_play" Mar 24 19:50:15 volumio volumio[1098]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:4bPISajsmjQCxxMxGjBptX","uri":"spotify:track:4bPISajsmjQCxxMxGjBptX","play_origin":"go-librespot"}} Mar 24 19:50:15 volumio go-librespot[1408]: time="2026-03-24T19:50:15+01:00" level=debug msg="selected format OGG_VORBIS_320 (dc853656e1857c45fb19b26658dc2dda39be01c0)" uri="spotify:track:4bPISajsmjQCxxMxGjBptX" Mar 24 19:50:15 volumio go-librespot[1408]: time="2026-03-24T19:50:15+01:00" level=debug msg="requested aes key for file dc853656e1857c45fb19b26658dc2dda39be01c0, gid: 4bPISajsmjQCxxMxGjBptX" Mar 24 19:50:15 volumio go-librespot[1408]: time="2026-03-24T19:50:15+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:4bPISajsmjQCxxMxGjBptX" Mar 24 19:50:16 volumio go-librespot[1408]: time="2026-03-24T19:50:16+01:00" level=debug msg="fetched first chunk of 33, total size is 16901622 bytes" uri="spotify:track:4bPISajsmjQCxxMxGjBptX" Mar 24 19:50:16 volumio go-librespot[1408]: time="2026-03-24T19:50:16+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Mar 24 19:50:16 volumio go-librespot[1408]: time="2026-03-24T19:50:16+01:00" level=info msg="loaded track \"Listen To My Heart\" (paused: false, position: 0ms, duration: 425625ms, prefetched: false)" uri="spotify:track:4bPISajsmjQCxxMxGjBptX" Mar 24 19:50:16 volumio go-librespot[1408]: time="2026-03-24T19:50:16+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 19:50:16 volumio go-librespot[1408]: time="2026-03-24T19:50:16+01:00" level=trace msg="scheduling prefetch in 396s" Mar 24 19:50:16 volumio go-librespot[1408]: time="2026-03-24T19:50:16+01:00" level=trace msg="emitting websocket event: metadata" Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4bPISajsmjQCxxMxGjBptX","name":"Listen To My Heart","artist_names":["Offer Nissim"],"album_name":"OFFER NISSIM","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02befbb6070dda1974e51beee7","position":0,"duration":425625,"release_date":"year:2024 month:6 day:2","track_number":11,"disc_number":1}} Mar 24 19:50:16 volumio go-librespot[1408]: time="2026-03-24T19:50:16+01:00" level=debug msg="fetched chunk 1/32, size: 524288" uri="spotify:track:4bPISajsmjQCxxMxGjBptX" Mar 24 19:50:16 volumio go-librespot[1408]: time="2026-03-24T19:50:16+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 19:50:16 volumio go-librespot[1408]: time="2026-03-24T19:50:16+01:00" level=trace msg="emitting websocket event: paused" Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:4bPISajsmjQCxxMxGjBptX","uri":"spotify:track:4bPISajsmjQCxxMxGjBptX","play_origin":"go-librespot"}} Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: {"status":"pause","service":"spop","title":"Listen To My Heart","artist":"Offer Nissim","album":"OFFER NISSIM","albumart":"https://i.scdn.co/image/ab67616d00001e02befbb6070dda1974e51beee7","uri":"spotify:track:4bPISajsmjQCxxMxGjBptX","trackType":"spotify","seek":0,"duration":425,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 24 19:50:16 volumio volumio[1098]: info: CoreCommandRouter::servicePushState Mar 24 19:50:16 volumio volumio[1098]: info: CorePlayQueue::getTrack 0 Mar 24 19:50:16 volumio volumio[1098]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Listen To My Heart","artist":"Offer Nissim","album":"OFFER NISSIM","albumart":"https://i.scdn.co/image/ab67616d00001e02befbb6070dda1974e51beee7","uri":"spotify:track:4bPISajsmjQCxxMxGjBptX","trackType":"spotify","seek":0,"duration":425,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 24 19:50:16 volumio volumio[1098]: verbose: CURRENT POSITION 0 Mar 24 19:50:16 volumio volumio[1098]: info: CoreStateMachine::syncState stateService pause Mar 24 19:50:16 volumio volumio[1098]: info: CoreStateMachine::syncState currentStatus stop Mar 24 19:50:16 volumio volumio[1098]: info: CoreStateMachine::pushState Mar 24 19:50:16 volumio volumio[1098]: info: CorePlayQueue::getTrack 0 Mar 24 19:50:16 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 19:50:16 volumio volumio[1098]: info: CoreCommandRouter::volumioPushState Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: SPOTIFY VOLUME 67 Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: VOLUMIO VOLUME 66 Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 24 19:50:16 volumio go-librespot[1408]: time="2026-03-24T19:50:16+01:00" level=debug msg="fetched chunk 3/32, size: 524288" uri="spotify:track:4bPISajsmjQCxxMxGjBptX" Mar 24 19:50:16 volumio go-librespot[1408]: time="2026-03-24T19:50:16+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 19:50:16 volumio go-librespot[1408]: time="2026-03-24T19:50:16+01:00" level=debug msg="fetched chunk 2/32, size: 524288" uri="spotify:track:4bPISajsmjQCxxMxGjBptX" Mar 24 19:50:16 volumio go-librespot[1408]: time="2026-03-24T19:50:16+01:00" level=trace msg="emitting websocket event: playing" Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:4bPISajsmjQCxxMxGjBptX","uri":"spotify:track:4bPISajsmjQCxxMxGjBptX","resume":false,"play_origin":"go-librespot"}} Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: {"status":"play","service":"spop","title":"Listen To My Heart","artist":"Offer Nissim","album":"OFFER NISSIM","albumart":"https://i.scdn.co/image/ab67616d00001e02befbb6070dda1974e51beee7","uri":"spotify:track:4bPISajsmjQCxxMxGjBptX","trackType":"spotify","seek":0,"duration":425,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 24 19:50:16 volumio volumio[1098]: info: CoreCommandRouter::servicePushState Mar 24 19:50:16 volumio volumio[1098]: info: CorePlayQueue::getTrack 0 Mar 24 19:50:16 volumio volumio[1098]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Listen To My Heart","artist":"Offer Nissim","album":"OFFER NISSIM","albumart":"https://i.scdn.co/image/ab67616d00001e02befbb6070dda1974e51beee7","uri":"spotify:track:4bPISajsmjQCxxMxGjBptX","trackType":"spotify","seek":0,"duration":425,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 24 19:50:16 volumio volumio[1098]: verbose: CURRENT POSITION 0 Mar 24 19:50:16 volumio volumio[1098]: info: CoreStateMachine::syncState stateService play Mar 24 19:50:16 volumio volumio[1098]: info: CoreStateMachine::syncState currentStatus stop Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: {"status":"play","service":"spop","title":"Listen To My Heart","artist":"Offer Nissim","album":"OFFER NISSIM","albumart":"https://i.scdn.co/image/ab67616d00001e02befbb6070dda1974e51beee7","uri":"spotify:track:4bPISajsmjQCxxMxGjBptX","trackType":"spotify","seek":0,"duration":425,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 24 19:50:16 volumio volumio[1098]: info: CoreCommandRouter::servicePushState Mar 24 19:50:16 volumio volumio[1098]: info: CorePlayQueue::getTrack 0 Mar 24 19:50:16 volumio volumio[1098]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Listen To My Heart","artist":"Offer Nissim","album":"OFFER NISSIM","albumart":"https://i.scdn.co/image/ab67616d00001e02befbb6070dda1974e51beee7","uri":"spotify:track:4bPISajsmjQCxxMxGjBptX","trackType":"spotify","seek":0,"duration":425,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 24 19:50:16 volumio volumio[1098]: verbose: CURRENT POSITION 0 Mar 24 19:50:16 volumio volumio[1098]: info: CoreStateMachine::syncState stateService play Mar 24 19:50:16 volumio volumio[1098]: info: CoreStateMachine::syncState currentStatus play Mar 24 19:50:16 volumio volumio[1098]: info: Received an update from plugin. extracting info from payload Mar 24 19:50:16 volumio volumio[1098]: info: CoreStateMachine::pushState Mar 24 19:50:16 volumio volumio[1098]: info: CorePlayQueue::getTrack 0 Mar 24 19:50:16 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 19:50:16 volumio volumio[1098]: info: CoreCommandRouter::volumioPushState Mar 24 19:50:16 volumio volumio[1098]: info: CoreStateMachine::pushState Mar 24 19:50:16 volumio volumio[1098]: info: CorePlayQueue::getTrack 0 Mar 24 19:50:16 volumio volumio[1098]: info: CoreCommandRouter::volumioPushState Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: SPOTIFY VOLUME 67 Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: VOLUMIO VOLUME 66 Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: SPOTIFY VOLUME 67 Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: VOLUMIO VOLUME 66 Mar 24 19:50:16 volumio volumio[1098]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 24 19:50:19 volumio volumio[1098]: info: Preload queue cleared Mar 24 19:50:19 volumio volumio[1098]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::ClearQueue Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::stop Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::stPlaybackTimer Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::updateTrackBlock Mar 24 19:50:19 volumio volumio[1098]: info: CorePlayQueue::getTrackBlock Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::pushState Mar 24 19:50:19 volumio volumio[1098]: info: CorePlayQueue::getTrack 0 Mar 24 19:50:19 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 19:50:19 volumio volumio[1098]: info: CoreCommandRouter::volumioPushState Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::serviceStop Mar 24 19:50:19 volumio volumio[1098]: info: CorePlayQueue::getTrack 0 Mar 24 19:50:19 volumio volumio[1098]: info: CoreCommandRouter::serviceStop Mar 24 19:50:19 volumio volumio[1098]: info: Spotify Stop Mar 24 19:50:19 volumio volumio[1098]: SPOTIFY: SPOTIFY STOP Mar 24 19:50:19 volumio volumio[1098]: SPOTIFY: {"status":"play","position":0,"title":"Listen To My Heart","artist":"Offer Nissim","album":"OFFER NISSIM","albumart":"https://i.scdn.co/image/ab67616d0000b273befbb6070dda1974e51beee7","uri":"spotify:track:4bPISajsmjQCxxMxGjBptX","trackType":"spotify","codec":"ogg","seek":0,"duration":425,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":66,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Mar 24 19:50:19 volumio volumio[1098]: info: Sending Spotify command to local API: /player/pause Mar 24 19:50:19 volumio volumio[1098]: info: CorePlayQueue::clearPlayQueue Mar 24 19:50:19 volumio volumio[1098]: info: CorePlayQueue::saveQueue Mar 24 19:50:19 volumio volumio[1098]: info: CoreCommandRouter::volumioPushQueue Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::addQueueItems Mar 24 19:50:19 volumio volumio[1098]: info: CorePlayQueue::addQueueItems Mar 24 19:50:19 volumio volumio[1098]: info: Preload queue cleared Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4bPISajsmjQCxxMxGjBptX Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:4bPISajsmjQCxxMxGjBptX Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:5tPb2lVWoAVpXb2uyeym0I Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:5tPb2lVWoAVpXb2uyeym0I Mar 24 19:50:19 volumio volumio[1098]: info: CoreCommandRouter::volumioPushQueue Mar 24 19:50:19 volumio volumio[1098]: info: CorePlayQueue::saveQueue Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::updateTrackBlock Mar 24 19:50:19 volumio volumio[1098]: info: CorePlayQueue::getTrackBlock Mar 24 19:50:19 volumio volumio[1098]: info: CoreCommandRouter::volumioPlay Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::play index 1 Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::addQueueItems Mar 24 19:50:19 volumio volumio[1098]: info: CorePlayQueue::addQueueItems Mar 24 19:50:19 volumio volumio[1098]: info: Preload queue cleared Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:2NzbyKz5nIunufVMli0Nqz Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:2NzbyKz5nIunufVMli0Nqz Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:1cQld05IcUDw3RCFt7uymW Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:1cQld05IcUDw3RCFt7uymW Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4Vucb0U4wsbbuzAiy61KUl Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:4Vucb0U4wsbbuzAiy61KUl Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:3mcbwkZCEAWEU2MBpje159 Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:3mcbwkZCEAWEU2MBpje159 Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:6MTsfDyLSejmtQtyD2ORr2 Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:6MTsfDyLSejmtQtyD2ORr2 Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:59NraMJsLaMCVtwXTSia8i Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:59NraMJsLaMCVtwXTSia8i Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:7fZBQnc0zXwVybgCIrQQil Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:7fZBQnc0zXwVybgCIrQQil Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:2YuUy4hBCVm4L5IRHu0iVl Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:2YuUy4hBCVm4L5IRHu0iVl Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:3uikQKO7o4usH0Cppu2zW0 Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:3uikQKO7o4usH0Cppu2zW0 Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:2FQrifJ1N335Ljm3TjTVVf Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:2FQrifJ1N335Ljm3TjTVVf Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:5ZLUm9eab8y3tqQ1OhQSHI Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:5ZLUm9eab8y3tqQ1OhQSHI Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4aB1eZWam3I3WkzzZxlGVo Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:4aB1eZWam3I3WkzzZxlGVo Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:3x3oEFoQzTwqrMLj6Zufgf Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:3x3oEFoQzTwqrMLj6Zufgf Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4KfSdst7rW39C0sfhArdrz Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:4KfSdst7rW39C0sfhArdrz Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:31MOjWj3CT3dCQsMV2b8Wu Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:31MOjWj3CT3dCQsMV2b8Wu Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:3lGyt8enqenwyqXihI6AVr Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:3lGyt8enqenwyqXihI6AVr Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:2u8MGAiS2hBVE7GZzTZLQI Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:2u8MGAiS2hBVE7GZzTZLQI Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:31TXxq8gfgYyrYClnYY48m Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:31TXxq8gfgYyrYClnYY48m Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: ytmusic/video@explodeTrackData:o=%7B%22type%22%3A%22video%22%2C%22title%22%3A%22Take%20Control%22%2C%22artist%22%3A%22Bexxie%20%26%20Towera%22%2C%22album%22%3A%22%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FjtxeGK5Hwm0%2Fsddefault.jpg%3Fsqp%3D-oaymwEWCJADEOEBIAQqCghqEJQEGHgg6AJIWg%26rs%3DAMzJL3mXjNk7Be4ktO3B0Ej_4SpilOWkKw%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22jtxeGK5Hwm0%22%2C%22playlistId%22%3A%22RDCLAK5uy_lGiQTUU4XxGV7l9L5YJ3sV0zomDirmZTM%22%2C%22params%22%3A%228gECGAM%253D%22%2C%22playlistSetVideoId%22%3A%222B6EFA1B1F897EAC%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_OMV%22%7D%2C%22autoplayContext%22%3A%7B%22fetchEndpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22playlistId%22%3A%22RDCLAK5uy_lGiQTUU4XxGV7l9L5YJ3sV0zomDirmZTM%22%2C%22params%22%3A%228gECGAM%253D%22%2C%22videoId%22%3A%22wu3tmq_QPLo%22%7D%7D%7D%7D Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: ytmusic/video@explodeTrackData:o=%7B%22type%22%3A%22video%22%2C%22title%22%3A%22Take%20Control%22%2C%22artist%22%3A%22Bexxie%20%26%20Towera%22%2C%22album%22%3A%22%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FjtxeGK5Hwm0%2Fsddefault.jpg%3Fsqp%3D-oaymwEWCJADEOEBIAQqCghqEJQEGHgg6AJIWg%26rs%3DAMzJL3mXjNk7Be4ktO3B0Ej_4SpilOWkKw%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22jtxeGK5Hwm0%22%2C%22playlistId%22%3A%22RDCLAK5uy_lGiQTUU4XxGV7l9L5YJ3sV0zomDirmZTM%22%2C%22params%22%3A%228gECGAM%253D%22%2C%22playlistSetVideoId%22%3A%222B6EFA1B1F897EAC%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_OMV%22%7D%2C%22autoplayContext%22%3A%7B%22fetchEndpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22playlistId%22%3A%22RDCLAK5uy_lGiQTUU4XxGV7l9L5YJ3sV0zomDirmZTM%22%2C%22params%22%3A%228gECGAM%253D%22%2C%22videoId%22%3A%22wu3tmq_QPLo%22%7D%7D%7D%7D Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:0svl7cK07gK1ia5ainczU5 Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:0svl7cK07gK1ia5ainczU5 Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:2JyoTSZozy8aQmEOLw2nA7 Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:2JyoTSZozy8aQmEOLw2nA7 Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4OTw5splgMdlYklwHMHxLK Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:4OTw5splgMdlYklwHMHxLK Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:0u6JFVn0KHHlidZxNL9gVE Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:0u6JFVn0KHHlidZxNL9gVE Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:0u6JFVn0KHHlidZxNL9gVE Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:0u6JFVn0KHHlidZxNL9gVE Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:3Jnxngdff0lVu2rza1GVx6 Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:3Jnxngdff0lVu2rza1GVx6 Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:2dpO3NteNWUDL2S9e0t0Mi Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:2dpO3NteNWUDL2S9e0t0Mi Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4v2rkl1mC3zVAz0nXMx9r4 Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:4v2rkl1mC3zVAz0nXMx9r4 Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4feNlb6HlpBrW36SsXoUfh Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:4feNlb6HlpBrW36SsXoUfh Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:6kSSORnF2vhzDpGftPXNWz Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:6kSSORnF2vhzDpGftPXNWz Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:6ObOQwjP7hycMhlYbSJuvk Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:6ObOQwjP7hycMhlYbSJuvk Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:1fhx6MlQPiT6FKa6IolKZh Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:1fhx6MlQPiT6FKa6IolKZh Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4VxTzYm00mg82MuoT35Ja7 Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:4VxTzYm00mg82MuoT35Ja7 Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:6x6bkynh0Yfkgl3ygOEF3X Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:6x6bkynh0Yfkgl3ygOEF3X Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4A0rGm3Op4EjzNT4mCn6Na Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:4A0rGm3Op4EjzNT4mCn6Na Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:5rzS6Q74tWi0EJijvxNMF9 Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:5rzS6Q74tWi0EJijvxNMF9 Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:07QwNQfpAirTUv7zkEKI2N Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:07QwNQfpAirTUv7zkEKI2N Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:0OUd9wYBep0wPt3Gck95sB Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:0OUd9wYBep0wPt3Gck95sB Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4paPZYcTcMQmY6hX9JFfiC Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:4paPZYcTcMQmY6hX9JFfiC Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:55lijDD6OAjLFFUHU9tcDm Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:55lijDD6OAjLFFUHU9tcDm Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:3TWpz0iK17gFlxWlIs3MIQ Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:3TWpz0iK17gFlxWlIs3MIQ Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4wqIXeDppYSMXaWsnTzpzT Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:4wqIXeDppYSMXaWsnTzpzT Mar 24 19:50:19 volumio volumio[1098]: info: Adding Item to queue: spotify:track:4paPZYcTcMQmY6hX9JFfiC Mar 24 19:50:19 volumio volumio[1098]: info: Using cached record of: spotify:track:4paPZYcTcMQmY6hX9JFfiC Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::stop Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 19:50:19 volumio volumio[1098]: info: CoreCommandRouter::volumioPushQueue Mar 24 19:50:19 volumio volumio[1098]: info: CorePlayQueue::saveQueue Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::play index undefined Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::updateTrackBlock Mar 24 19:50:19 volumio volumio[1098]: info: CorePlayQueue::getTrackBlock Mar 24 19:50:19 volumio volumio[1098]: info: CorePlayQueue::getTrack 1 Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::startPlaybackTimer Mar 24 19:50:19 volumio volumio[1098]: info: CorePlayQueue::getTrack 1 Mar 24 19:50:19 volumio volumio[1098]: info: [1774378219270] ControllerSpotify::clearAddPlayTrack Mar 24 19:50:19 volumio volumio[1098]: info: Sending Spotify command with payload to local API: /player/play Mar 24 19:50:19 volumio volumio[1098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Mar 24 19:50:19 volumio volumio[1098]: SPOTIFY: SPOTIFY VOLUME 67 Mar 24 19:50:19 volumio volumio[1098]: SPOTIFY: VOLUMIO VOLUME 66 Mar 24 19:50:19 volumio volumio[1098]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=debug msg="pause track at 3284ms" Mar 24 19:50:19 volumio volumio[1098]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=debug msg="resolved context of track" uri="spotify:track:5tPb2lVWoAVpXb2uyeym0I" Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:5tPb2lVWoAVpXb2uyeym0I" Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:5tPb2lVWoAVpXb2uyeym0I" Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=trace msg="emitting websocket event: will_play" Mar 24 19:50:19 volumio volumio[1098]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:5tPb2lVWoAVpXb2uyeym0I","uri":"spotify:track:5tPb2lVWoAVpXb2uyeym0I","play_origin":"go-librespot"}} Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=debug msg="selected format OGG_VORBIS_320 (54cbbb0164480002cd6b6a664e2fddaf79fd0665)" uri="spotify:track:5tPb2lVWoAVpXb2uyeym0I" Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=debug msg="requested aes key for file 54cbbb0164480002cd6b6a664e2fddaf79fd0665, gid: 5tPb2lVWoAVpXb2uyeym0I" Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:5tPb2lVWoAVpXb2uyeym0I" Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=debug msg="fetched first chunk of 26, total size is 13231244 bytes" uri="spotify:track:5tPb2lVWoAVpXb2uyeym0I" Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=info msg="loaded track \"Beautiful People - Seth Hills Remix Extended\" (paused: false, position: 0ms, duration: 304218ms, prefetched: false)" uri="spotify:track:5tPb2lVWoAVpXb2uyeym0I" Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=trace msg="scheduling prefetch in 274s" Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=trace msg="emitting websocket event: metadata" Mar 24 19:50:19 volumio volumio[1098]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5tPb2lVWoAVpXb2uyeym0I","name":"Beautiful People - Seth Hills Remix Extended","artist_names":["David Guetta","Sia","Seth Hills"],"album_name":"Beautiful People (Seth Hills Remix)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02811cf6ae4e875264d918bd73","position":0,"duration":304218,"release_date":"year:2025 month:3 day:28","track_number":2,"disc_number":1}} Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=debug msg="fetched chunk 2/25, size: 524288" uri="spotify:track:5tPb2lVWoAVpXb2uyeym0I" Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=debug msg="fetched chunk 1/25, size: 524288" uri="spotify:track:5tPb2lVWoAVpXb2uyeym0I" Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=trace msg="emitting websocket event: paused" Mar 24 19:50:19 volumio volumio[1098]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:5tPb2lVWoAVpXb2uyeym0I","uri":"spotify:track:5tPb2lVWoAVpXb2uyeym0I","play_origin":"go-librespot"}} Mar 24 19:50:19 volumio volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 19:50:19 volumio volumio[1098]: SPOTIFY: {"status":"pause","service":"spop","title":"Beautiful People - Seth Hills Remix Extended","artist":"David Guetta, Sia, Seth Hills","album":"Beautiful People (Seth Hills Remix)","albumart":"https://i.scdn.co/image/ab67616d00001e02811cf6ae4e875264d918bd73","uri":"spotify:track:5tPb2lVWoAVpXb2uyeym0I","trackType":"spotify","seek":0,"duration":304,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 24 19:50:19 volumio volumio[1098]: info: CoreCommandRouter::servicePushState Mar 24 19:50:19 volumio volumio[1098]: info: CorePlayQueue::getTrack 1 Mar 24 19:50:19 volumio volumio[1098]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Beautiful People - Seth Hills Remix Extended","artist":"David Guetta, Sia, Seth Hills","album":"Beautiful People (Seth Hills Remix)","albumart":"https://i.scdn.co/image/ab67616d00001e02811cf6ae4e875264d918bd73","uri":"spotify:track:5tPb2lVWoAVpXb2uyeym0I","trackType":"spotify","seek":0,"duration":304,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 24 19:50:19 volumio volumio[1098]: verbose: CURRENT POSITION 1 Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::syncState stateService pause Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::syncState currentStatus stop Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::pushState Mar 24 19:50:19 volumio volumio[1098]: info: CorePlayQueue::getTrack 1 Mar 24 19:50:19 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 19:50:19 volumio volumio[1098]: info: CoreCommandRouter::volumioPushState Mar 24 19:50:19 volumio volumio[1098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Mar 24 19:50:19 volumio volumio[1098]: SPOTIFY: SPOTIFY VOLUME 67 Mar 24 19:50:19 volumio volumio[1098]: SPOTIFY: VOLUMIO VOLUME 66 Mar 24 19:50:19 volumio volumio[1098]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=trace msg="emitting websocket event: playing" Mar 24 19:50:19 volumio volumio[1098]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:5tPb2lVWoAVpXb2uyeym0I","uri":"spotify:track:5tPb2lVWoAVpXb2uyeym0I","resume":false,"play_origin":"go-librespot"}} Mar 24 19:50:19 volumio volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 19:50:19 volumio volumio[1098]: SPOTIFY: {"status":"play","service":"spop","title":"Beautiful People - Seth Hills Remix Extended","artist":"David Guetta, Sia, Seth Hills","album":"Beautiful People (Seth Hills Remix)","albumart":"https://i.scdn.co/image/ab67616d00001e02811cf6ae4e875264d918bd73","uri":"spotify:track:5tPb2lVWoAVpXb2uyeym0I","trackType":"spotify","seek":0,"duration":304,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 24 19:50:19 volumio volumio[1098]: info: CoreCommandRouter::servicePushState Mar 24 19:50:19 volumio volumio[1098]: info: CorePlayQueue::getTrack 1 Mar 24 19:50:19 volumio volumio[1098]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Beautiful People - Seth Hills Remix Extended","artist":"David Guetta, Sia, Seth Hills","album":"Beautiful People (Seth Hills Remix)","albumart":"https://i.scdn.co/image/ab67616d00001e02811cf6ae4e875264d918bd73","uri":"spotify:track:5tPb2lVWoAVpXb2uyeym0I","trackType":"spotify","seek":0,"duration":304,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 24 19:50:19 volumio volumio[1098]: verbose: CURRENT POSITION 1 Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::syncState stateService play Mar 24 19:50:19 volumio volumio[1098]: info: CoreStateMachine::syncState currentStatus stop Mar 24 19:50:19 volumio go-librespot[1408]: time="2026-03-24T19:50:19+01:00" level=debug msg="fetched chunk 3/25, size: 524288" uri="spotify:track:5tPb2lVWoAVpXb2uyeym0I" Mar 24 19:50:20 volumio volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 19:50:20 volumio volumio[1098]: SPOTIFY: {"status":"play","service":"spop","title":"Beautiful People - Seth Hills Remix Extended","artist":"David Guetta, Sia, Seth Hills","album":"Beautiful People (Seth Hills Remix)","albumart":"https://i.scdn.co/image/ab67616d00001e02811cf6ae4e875264d918bd73","uri":"spotify:track:5tPb2lVWoAVpXb2uyeym0I","trackType":"spotify","seek":0,"duration":304,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 24 19:50:20 volumio volumio[1098]: info: CoreCommandRouter::servicePushState Mar 24 19:50:20 volumio volumio[1098]: info: CorePlayQueue::getTrack 1 Mar 24 19:50:20 volumio volumio[1098]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Beautiful People - Seth Hills Remix Extended","artist":"David Guetta, Sia, Seth Hills","album":"Beautiful People (Seth Hills Remix)","albumart":"https://i.scdn.co/image/ab67616d00001e02811cf6ae4e875264d918bd73","uri":"spotify:track:5tPb2lVWoAVpXb2uyeym0I","trackType":"spotify","seek":0,"duration":304,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 24 19:50:20 volumio volumio[1098]: verbose: CURRENT POSITION 1 Mar 24 19:50:20 volumio volumio[1098]: info: CoreStateMachine::syncState stateService play Mar 24 19:50:20 volumio volumio[1098]: info: CoreStateMachine::syncState currentStatus play Mar 24 19:50:20 volumio volumio[1098]: info: Received an update from plugin. extracting info from payload Mar 24 19:50:20 volumio volumio[1098]: info: CoreStateMachine::pushState Mar 24 19:50:20 volumio volumio[1098]: info: CorePlayQueue::getTrack 1 Mar 24 19:50:20 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 19:50:20 volumio volumio[1098]: info: CoreCommandRouter::volumioPushState Mar 24 19:50:20 volumio volumio[1098]: info: CoreStateMachine::pushState Mar 24 19:50:20 volumio volumio[1098]: info: CorePlayQueue::getTrack 1 Mar 24 19:50:20 volumio volumio[1098]: info: CoreCommandRouter::volumioPushState Mar 24 19:50:20 volumio volumio[1098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Mar 24 19:50:20 volumio volumio[1098]: SPOTIFY: SPOTIFY VOLUME 67 Mar 24 19:50:20 volumio volumio[1098]: SPOTIFY: VOLUMIO VOLUME 66 Mar 24 19:50:20 volumio volumio[1098]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 24 19:50:20 volumio volumio[1098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Mar 24 19:50:20 volumio volumio[1098]: SPOTIFY: SPOTIFY VOLUME 67 Mar 24 19:50:20 volumio volumio[1098]: SPOTIFY: VOLUMIO VOLUME 66 Mar 24 19:50:20 volumio volumio[1098]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 24 19:50:23 volumio go-librespot[1408]: time="2026-03-24T19:50:23+01:00" level=trace msg="sent dealer ping" Mar 24 19:50:23 volumio go-librespot[1408]: time="2026-03-24T19:50:23+01:00" level=trace msg="received dealer pong" Mar 24 19:50:33 volumio go-librespot[1408]: time="2026-03-24T19:50:33+01:00" level=debug msg="fetched chunk 4/25, size: 524288" uri="spotify:track:5tPb2lVWoAVpXb2uyeym0I" Mar 24 19:50:34 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Mar 24 19:50:34 volumio volumio[1098]: info: In handleBrowseUri, curUri=spotify Mar 24 19:50:34 volumio volumio[1098]: info: Preload queue cleared Mar 24 19:50:34 volumio volumio[1098]: info: Preload queue cleared Mar 24 19:50:34 volumio volumio[1098]: info: Preload queue cleared Mar 24 19:50:34 volumio volumio[1098]: info: Preload queue cleared Mar 24 19:50:35 volumio wpa_supplicant[1003]: RRM: Ignoring radio measurement request: Not RRM network Mar 24 19:50:36 volumio volumio[1098]: info: VolumeController::SetAlsaVolume49 Mar 24 19:50:36 volumio volumio[1098]: info: CoreStateMachine::pushState Mar 24 19:50:36 volumio volumio[1098]: info: CorePlayQueue::getTrack 1 Mar 24 19:50:36 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 19:50:36 volumio volumio[1098]: info: CoreCommandRouter::volumioPushState Mar 24 19:50:36 volumio volumio[1098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 49 Mar 24 19:50:36 volumio volumio[1098]: SPOTIFY: SPOTIFY VOLUME 67 Mar 24 19:50:36 volumio volumio[1098]: SPOTIFY: VOLUMIO VOLUME 49 Mar 24 19:50:36 volumio volumio[1098]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 24 19:50:36 volumio volumio[1098]: info: Setting Spotify Volume from Volumio: 49 Mar 24 19:50:38 volumio volumio[1098]: SPOTIFY: SETTING SPOTIFY VOLUME 49 Mar 24 19:50:38 volumio volumio[1098]: info: Sending Spotify command with payload to local API: /player/volume Mar 24 19:50:38 volumio go-librespot[1408]: time="2026-03-24T19:50:38+01:00" level=debug msg="update volume requested to 32112/65535" Mar 24 19:50:38 volumio go-librespot[1408]: time="2026-03-24T19:50:38+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 24 19:50:38 volumio go-librespot[1408]: time="2026-03-24T19:50:38+01:00" level=trace msg="emitting websocket event: volume" Mar 24 19:50:38 volumio volumio[1098]: SPOTIFY: received: {"type":"volume","data":{"value":49,"max":100}} Mar 24 19:50:38 volumio volumio[1098]: SPOTIFY: RECEIVED SPOTIFY VOLUME 49 Mar 24 19:50:43 volumio volumio[1098]: Searching plugin music_service/spop Mar 24 19:50:43 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 24 19:50:44 volumio volumio[1098]: info: All search sources collected, pushing search results Mar 24 19:50:44 volumio wpa_supplicant[1003]: RRM: Ignoring radio measurement request: Not RRM network Mar 24 19:50:44 volumio volumio[1098]: Searching plugin music_service/spop Mar 24 19:50:44 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 24 19:50:45 volumio volumio[1098]: info: All search sources collected, pushing search results Mar 24 19:50:45 volumio go-librespot[1408]: time="2026-03-24T19:50:45+01:00" level=debug msg="fetched chunk 5/25, size: 524288" uri="spotify:track:5tPb2lVWoAVpXb2uyeym0I" Mar 24 19:50:46 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Mar 24 19:50:46 volumio volumio[1098]: info: In handleBrowseUri, curUri=spotify:artist:2OURkpZLgkMVDOIlXisjn6 Mar 24 19:50:46 volumio volumio[1098]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 19:50:46 volumio volumio[1098]: TypeError: Cannot read properties of undefined (reading 'url') Mar 24 19:50:46 volumio volumio[1098]: at /data/plugins/music_service/spop/index.js:2449:60 Mar 24 19:50:46 volumio volumio[1098]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Mar 24 19:50:46 volumio volumio[1098]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 19:50:47 volumio sudo[5575]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 19:49' Mar 24 19:50:47 volumio sudo[5575]: 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="1da895bfdbb6eb90d965df32a25a3568df7c84ed" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu May 29 13:12:59 UTC 2025" VOLUMIO_VERSION="4.004" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2df63d74196e499fa1e34fb765df1cca"