Sep 17 19:08:02 volumio go-librespot[1447]: time="2025-09-17T19:08:02+02:00" level=debug msg="fetched chunk 9/14, size: 524288" uri="spotify:track:0EuGL7IijmuB9XMJEbHwiu" Sep 17 19:08:07 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Sep 17 19:08:07 volumio dbus-daemon[575]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.105' (uid=0 pid=7236 comm="timedatectl show --property=NTPSynchronized --valu") Sep 17 19:08:07 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... Sep 17 19:08:07 volumio go-librespot[1447]: time="2025-09-17T19:08:07+02:00" level=trace msg="sent dealer ping" Sep 17 19:08:07 volumio go-librespot[1447]: time="2025-09-17T19:08:07+02:00" level=trace msg="received dealer pong" Sep 17 19:08:07 volumio dbus-daemon[575]: [system] Successfully activated service 'org.freedesktop.timedate1' Sep 17 19:08:07 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. Sep 17 19:08:07 volumio setdatetime-helper.sh[7235]: Time is already synchronized. Sep 17 19:08:07 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Sep 17 19:08:07 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Sep 17 19:08:08 volumio volumio[1102]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Sep 17 19:08:08 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Sep 17 19:08:08 volumio volumio[1102]: info: CoreCommandRouter::volumioGetState Sep 17 19:08:08 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:08:08 volumio volumio[1102]: info: Restoring Previous Volume level: 70 false false Sep 17 19:08:08 volumio volumio[1102]: info: Volume configurations have been set Sep 17 19:08:08 volumio volumio[1102]: info: CoreCommandRouter::volumioUpdateVolumeSettings Sep 17 19:08:08 volumio volumio[1102]: info: Updating Volume Controller Parameters: Device: 1 Name: Headphones Mixer: PCM Max Vol: 80 Vol Curve; logarithmic Vol Steps: 1 Sep 17 19:08:08 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Sep 17 19:08:08 volumio volumio[1102]: info: Disabling external Volume Control Sep 17 19:08:08 volumio volumio[1102]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 17 19:08:09 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Sep 17 19:08:09 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 17 19:08:09 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 17 19:08:09 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 17 19:08:09 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 17 19:08:09 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 17 19:08:09 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 17 19:08:09 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 17 19:08:09 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 17 19:08:09 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 17 19:08:09 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Sep 17 19:08:09 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 17 19:08:09 volumio volumio[1102]: info: VolumeController:: Volume=70 Mute =false Sep 17 19:08:09 volumio volumio[1102]: info: CoreStateMachine::pushState Sep 17 19:08:09 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:08:09 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 19:08:09 volumio volumio[1102]: info: CoreCommandRouter::volumioPushState Sep 17 19:08:09 volumio volumio[1102]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Sep 17 19:08:13 volumio volumio[1102]: info: VolumeController::SetAlsaVolume96 Sep 17 19:08:13 volumio volumio[1102]: info: CoreStateMachine::pushState Sep 17 19:08:13 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:08:13 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 19:08:13 volumio volumio[1102]: info: CoreCommandRouter::volumioPushState Sep 17 19:08:13 volumio volumio[1102]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Sep 17 19:08:13 volumio volumio[1102]: SPOTIFY: SPOTIFY VOLUME 70 Sep 17 19:08:13 volumio volumio[1102]: SPOTIFY: VOLUMIO VOLUME 80 Sep 17 19:08:13 volumio volumio[1102]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 17 19:08:13 volumio volumio[1102]: info: Setting Spotify Volume from Volumio: 80 Sep 17 19:08:13 volumio volumio[1102]: info: VolumeController::SetAlsaVolume70 Sep 17 19:08:13 volumio volumio[1102]: info: CoreStateMachine::pushState Sep 17 19:08:13 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:08:13 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 19:08:13 volumio volumio[1102]: info: CoreCommandRouter::volumioPushState Sep 17 19:08:13 volumio volumio[1102]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Sep 17 19:08:13 volumio volumio[1102]: SPOTIFY: SPOTIFY VOLUME 80 Sep 17 19:08:13 volumio volumio[1102]: SPOTIFY: VOLUMIO VOLUME 70 Sep 17 19:08:13 volumio volumio[1102]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 17 19:08:13 volumio volumio[1102]: info: Setting Spotify Volume from Volumio: 70 Sep 17 19:08:14 volumio volumio[1102]: SPOTIFY: SETTING SPOTIFY VOLUME 70 Sep 17 19:08:14 volumio volumio[1102]: info: Sending Spotify command with payload to local API: /player/volume Sep 17 19:08:14 volumio go-librespot[1447]: time="2025-09-17T19:08:14+02:00" level=debug msg="update volume requested to 45874/65535" Sep 17 19:08:15 volumio go-librespot[1447]: time="2025-09-17T19:08:15+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 17 19:08:15 volumio go-librespot[1447]: time="2025-09-17T19:08:15+02:00" level=trace msg="emitting websocket event: volume" Sep 17 19:08:15 volumio volumio[1102]: SPOTIFY: received: {"type":"volume","data":{"value":70,"max":100}} Sep 17 19:08:15 volumio volumio[1102]: SPOTIFY: RECEIVED SPOTIFY VOLUME 70 Sep 17 19:08:16 volumio go-librespot[1447]: time="2025-09-17T19:08:16+02:00" level=debug msg="fetched chunk 10/14, size: 524288" uri="spotify:track:0EuGL7IijmuB9XMJEbHwiu" Sep 17 19:08:16 volumio volumio[1102]: info: VolumeController::SetAlsaVolume82 Sep 17 19:08:16 volumio volumio[1102]: info: CoreStateMachine::pushState Sep 17 19:08:16 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:08:16 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 19:08:16 volumio volumio[1102]: info: CoreCommandRouter::volumioPushState Sep 17 19:08:16 volumio volumio[1102]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Sep 17 19:08:16 volumio volumio[1102]: SPOTIFY: SPOTIFY VOLUME 70 Sep 17 19:08:16 volumio volumio[1102]: SPOTIFY: VOLUMIO VOLUME 80 Sep 17 19:08:16 volumio volumio[1102]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 17 19:08:16 volumio volumio[1102]: info: Setting Spotify Volume from Volumio: 80 Sep 17 19:08:16 volumio volumio[1102]: info: VolumeController::SetAlsaVolume83 Sep 17 19:08:16 volumio volumio[1102]: info: CoreStateMachine::pushState Sep 17 19:08:16 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:08:16 volumio volumio[1102]: info: CoreCommandRouter::volumioPushState Sep 17 19:08:16 volumio volumio[1102]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Sep 17 19:08:18 volumio volumio[1102]: SPOTIFY: SETTING SPOTIFY VOLUME 80 Sep 17 19:08:18 volumio volumio[1102]: info: Sending Spotify command with payload to local API: /player/volume Sep 17 19:08:18 volumio volumio[1102]: error: Failed to send command to Spotify local API: /player/volume: Error: Bad Request Sep 17 19:08:18 volumio volumio[1102]: info: VolumeController::SetAlsaVolume97 Sep 17 19:08:18 volumio volumio[1102]: info: CoreStateMachine::pushState Sep 17 19:08:18 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:08:18 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 19:08:18 volumio volumio[1102]: info: CoreCommandRouter::volumioPushState Sep 17 19:08:18 volumio volumio[1102]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Sep 17 19:08:28 volumio go-librespot[1447]: time="2025-09-17T19:08:28+02:00" level=debug msg="fetched chunk 11/14, size: 524288" uri="spotify:track:0EuGL7IijmuB9XMJEbHwiu" Sep 17 19:08:32 volumio volumio[1102]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::volumioGetState Sep 17 19:08:32 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:08:32 volumio volumio[1102]: info: Restoring Previous Volume level: 80 false false Sep 17 19:08:32 volumio volumio[1102]: info: Volume configurations have been set Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::volumioUpdateVolumeSettings Sep 17 19:08:32 volumio volumio[1102]: info: Updating Volume Controller Parameters: Device: 1 Name: Headphones Mixer: PCM Max Vol: 90 Vol Curve; logarithmic Vol Steps: 1 Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Sep 17 19:08:32 volumio volumio[1102]: info: Disabling external Volume Control Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 17 19:08:32 volumio volumio[1102]: info: VolumeController:: Volume=80 Mute =false Sep 17 19:08:32 volumio volumio[1102]: info: CoreStateMachine::pushState Sep 17 19:08:32 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 19:08:32 volumio volumio[1102]: info: CoreCommandRouter::volumioPushState Sep 17 19:08:32 volumio volumio[1102]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Sep 17 19:08:32 volumio volumio[1102]: SPOTIFY: SPOTIFY VOLUME 80 Sep 17 19:08:32 volumio volumio[1102]: SPOTIFY: VOLUMIO VOLUME 80 Sep 17 19:08:32 volumio volumio[1102]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 17 19:08:36 volumio volumio[1102]: info: VolumeController::SetAlsaVolume91 Sep 17 19:08:36 volumio volumio[1102]: info: CoreStateMachine::pushState Sep 17 19:08:36 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:08:36 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 19:08:36 volumio volumio[1102]: info: CoreCommandRouter::volumioPushState Sep 17 19:08:36 volumio volumio[1102]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Sep 17 19:08:36 volumio volumio[1102]: SPOTIFY: SPOTIFY VOLUME 80 Sep 17 19:08:36 volumio volumio[1102]: SPOTIFY: VOLUMIO VOLUME 90 Sep 17 19:08:36 volumio volumio[1102]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 17 19:08:36 volumio volumio[1102]: info: Setting Spotify Volume from Volumio: 90 Sep 17 19:08:36 volumio volumio[1102]: info: VolumeController::SetAlsaVolume80 Sep 17 19:08:36 volumio volumio[1102]: info: CoreStateMachine::pushState Sep 17 19:08:36 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:08:36 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 19:08:36 volumio volumio[1102]: info: CoreCommandRouter::volumioPushState Sep 17 19:08:36 volumio volumio[1102]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Sep 17 19:08:36 volumio volumio[1102]: SPOTIFY: SPOTIFY VOLUME 90 Sep 17 19:08:36 volumio volumio[1102]: SPOTIFY: VOLUMIO VOLUME 80 Sep 17 19:08:36 volumio volumio[1102]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 17 19:08:36 volumio volumio[1102]: info: Setting Spotify Volume from Volumio: 80 Sep 17 19:08:37 volumio go-librespot[1447]: time="2025-09-17T19:08:37+02:00" level=trace msg="sent dealer ping" Sep 17 19:08:37 volumio go-librespot[1447]: time="2025-09-17T19:08:37+02:00" level=trace msg="received dealer pong" Sep 17 19:08:37 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. Sep 17 19:08:37 volumio go-librespot[1447]: time="2025-09-17T19:08:37+02:00" level=trace msg="received accesspoint ping" Sep 17 19:08:37 volumio go-librespot[1447]: time="2025-09-17T19:08:37+02:00" level=trace msg="received accesspoint pong ack" Sep 17 19:08:38 volumio volumio[1102]: SPOTIFY: SETTING SPOTIFY VOLUME 80 Sep 17 19:08:38 volumio volumio[1102]: info: Sending Spotify command with payload to local API: /player/volume Sep 17 19:08:38 volumio go-librespot[1447]: time="2025-09-17T19:08:38+02:00" level=debug msg="update volume requested to 52428/65535" Sep 17 19:08:38 volumio go-librespot[1447]: time="2025-09-17T19:08:38+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 17 19:08:38 volumio go-librespot[1447]: time="2025-09-17T19:08:38+02:00" level=trace msg="emitting websocket event: volume" Sep 17 19:08:38 volumio volumio[1102]: SPOTIFY: received: {"type":"volume","data":{"value":80,"max":100}} Sep 17 19:08:38 volumio volumio[1102]: SPOTIFY: RECEIVED SPOTIFY VOLUME 80 Sep 17 19:08:38 volumio volumio[1102]: info: VolumeController::SetAlsaVolume92 Sep 17 19:08:38 volumio volumio[1102]: info: CoreStateMachine::pushState Sep 17 19:08:38 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:08:38 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 19:08:38 volumio volumio[1102]: info: CoreCommandRouter::volumioPushState Sep 17 19:08:38 volumio volumio[1102]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Sep 17 19:08:38 volumio volumio[1102]: SPOTIFY: SPOTIFY VOLUME 80 Sep 17 19:08:38 volumio volumio[1102]: SPOTIFY: VOLUMIO VOLUME 90 Sep 17 19:08:38 volumio volumio[1102]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 17 19:08:38 volumio volumio[1102]: info: Setting Spotify Volume from Volumio: 90 Sep 17 19:08:40 volumio volumio[1102]: info: VolumeController::SetAlsaVolume94 Sep 17 19:08:40 volumio volumio[1102]: info: CoreStateMachine::pushState Sep 17 19:08:40 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:08:40 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 19:08:40 volumio volumio[1102]: info: CoreCommandRouter::volumioPushState Sep 17 19:08:40 volumio volumio[1102]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Sep 17 19:08:40 volumio volumio[1102]: SPOTIFY: SETTING SPOTIFY VOLUME 90 Sep 17 19:08:40 volumio volumio[1102]: info: Sending Spotify command with payload to local API: /player/volume Sep 17 19:08:40 volumio volumio[1102]: error: Failed to send command to Spotify local API: /player/volume: Error: Bad Request Sep 17 19:08:40 volumio volumio[1102]: info: VolumeController::SetAlsaVolume97 Sep 17 19:08:40 volumio volumio[1102]: info: CoreStateMachine::pushState Sep 17 19:08:40 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:08:40 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 19:08:40 volumio volumio[1102]: info: CoreCommandRouter::volumioPushState Sep 17 19:08:40 volumio volumio[1102]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Sep 17 19:08:40 volumio volumio[1102]: info: VolumeController::SetAlsaVolume100 Sep 17 19:08:40 volumio volumio[1102]: info: CoreStateMachine::pushState Sep 17 19:08:40 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:08:40 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 19:08:40 volumio volumio[1102]: info: CoreCommandRouter::volumioPushState Sep 17 19:08:40 volumio volumio[1102]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Sep 17 19:08:41 volumio go-librespot[1447]: time="2025-09-17T19:08:41+02:00" level=debug msg="fetched chunk 12/14, size: 524288" uri="spotify:track:0EuGL7IijmuB9XMJEbHwiu" Sep 17 19:08:48 volumio volumio[1102]: info: CoreCommandRouter::volumioGetState Sep 17 19:08:48 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:08:52 volumio go-librespot[1447]: time="2025-09-17T19:08:52+02:00" level=debug msg="fetched chunk 13/14, size: 524288" uri="spotify:track:0EuGL7IijmuB9XMJEbHwiu" Sep 17 19:09:04 volumio go-librespot[1447]: time="2025-09-17T19:09:04+02:00" level=debug msg="fetched chunk 14/14, size: 472148" uri="spotify:track:0EuGL7IijmuB9XMJEbHwiu" Sep 17 19:09:07 volumio go-librespot[1447]: time="2025-09-17T19:09:07+02:00" level=trace msg="sent dealer ping" Sep 17 19:09:07 volumio go-librespot[1447]: time="2025-09-17T19:09:07+02:00" level=trace msg="received dealer pong" Sep 17 19:09:08 volumio volumio[1102]: info: Preload queue cleared Sep 17 19:09:08 volumio volumio[1102]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::ClearQueue Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::stop Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::stPlaybackTimer Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::updateTrackBlock Sep 17 19:09:08 volumio volumio[1102]: info: CorePlayQueue::getTrackBlock Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::pushState Sep 17 19:09:08 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:09:08 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 19:09:08 volumio volumio[1102]: info: CoreCommandRouter::volumioPushState Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::serviceStop Sep 17 19:09:08 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:09:08 volumio volumio[1102]: info: CoreCommandRouter::serviceStop Sep 17 19:09:08 volumio volumio[1102]: info: Spotify Stop Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: SPOTIFY STOP Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: {"status":"play","position":9,"title":"Let's Go!","artist":"Armağan Oruç","album":"Let's Go!","albumart":"https://i.scdn.co/image/ab67616d0000b273a13482f8a66bf5247bfc0618","uri":"spotify:track:0EuGL7IijmuB9XMJEbHwiu","trackType":"spotify","codec":"ogg","seek":111266,"duration":188,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":"90","dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Sep 17 19:09:08 volumio volumio[1102]: info: Sending Spotify command to local API: /player/pause Sep 17 19:09:08 volumio volumio[1102]: info: CorePlayQueue::clearPlayQueue Sep 17 19:09:08 volumio volumio[1102]: info: CorePlayQueue::saveQueue Sep 17 19:09:08 volumio volumio[1102]: info: CoreCommandRouter::volumioPushQueue Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::addQueueItems Sep 17 19:09:08 volumio volumio[1102]: info: CorePlayQueue::addQueueItems Sep 17 19:09:08 volumio volumio[1102]: info: Preload queue cleared Sep 17 19:09:08 volumio volumio[1102]: info: Adding Item to queue: spotify:track:3nYfUQdzDLz69L63qnwVCB Sep 17 19:09:08 volumio volumio[1102]: info: Exploding uri spotify:track:3nYfUQdzDLz69L63qnwVCB in service spop Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: EXPLODING URI:spotify:track:3nYfUQdzDLz69L63qnwVCB Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=debug msg="pause track at 138843ms" Sep 17 19:09:08 volumio volumio[1102]: info: touch_display: Setting screensaver timeout to 0 seconds. Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=trace msg="emitting websocket event: paused" Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:0EuGL7IijmuB9XMJEbHwiu","play_origin":"go-librespot"}} Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: PUSH STATE SPOTIFY Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: {"status":"pause","service":"spop","title":"Let's Go!","artist":"Armağan Oruç","album":"Let's Go!","albumart":"https://i.scdn.co/image/ab67616d00001e02a13482f8a66bf5247bfc0618","uri":"spotify:track:0EuGL7IijmuB9XMJEbHwiu","trackType":"spotify","seek":138001,"duration":188,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 17 19:09:08 volumio volumio[1102]: info: CoreCommandRouter::servicePushState Sep 17 19:09:08 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:09:08 volumio volumio[1102]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Let's Go!","artist":"Armağan Oruç","album":"Let's Go!","albumart":"https://i.scdn.co/image/ab67616d00001e02a13482f8a66bf5247bfc0618","uri":"spotify:track:0EuGL7IijmuB9XMJEbHwiu","trackType":"spotify","seek":138001,"duration":188,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 17 19:09:08 volumio volumio[1102]: verbose: CURRENT POSITION 9 Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::syncState stateService pause Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::syncState currentStatus stop Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::pushState Sep 17 19:09:08 volumio volumio[1102]: info: CorePlayQueue::getTrack 9 Sep 17 19:09:08 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 19:09:08 volumio volumio[1102]: info: CoreCommandRouter::volumioPushState Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3nYfUQdzDLz69L63qnwVCB","service":"spop","name":"Bir Güle Kandım - Armageddon Turk Remix","artist":"Nilüfer","album":"Bir Güle Kandım (Armageddon Turk Remix)","type":"song","duration":181,"albumart":"https://i.scdn.co/image/ab67616d0000b273a050924dd862c7eaacd64a76","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 17 19:09:08 volumio volumio[1102]: info: CoreCommandRouter::volumioPushQueue Sep 17 19:09:08 volumio volumio[1102]: info: CorePlayQueue::saveQueue Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::updateTrackBlock Sep 17 19:09:08 volumio volumio[1102]: info: CorePlayQueue::getTrackBlock Sep 17 19:09:08 volumio volumio[1102]: info: CoreCommandRouter::volumioPlay Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::play index 0 Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::addQueueItems Sep 17 19:09:08 volumio volumio[1102]: info: CorePlayQueue::addQueueItems Sep 17 19:09:08 volumio volumio[1102]: info: Preload queue cleared Sep 17 19:09:08 volumio volumio[1102]: info: Adding Item to queue: spotify:track:2pt41XKgycdBxDa1lfCROi Sep 17 19:09:08 volumio volumio[1102]: info: Exploding uri spotify:track:2pt41XKgycdBxDa1lfCROi in service spop Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: EXPLODING URI:spotify:track:2pt41XKgycdBxDa1lfCROi Sep 17 19:09:08 volumio volumio[1102]: info: Adding Item to queue: spotify:track:1tET394Eqxaa9suIWhD4qN Sep 17 19:09:08 volumio volumio[1102]: info: Exploding uri spotify:track:1tET394Eqxaa9suIWhD4qN in service spop Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: EXPLODING URI:spotify:track:1tET394Eqxaa9suIWhD4qN Sep 17 19:09:08 volumio volumio[1102]: info: Adding Item to queue: spotify:track:4cutUX0B5hkboZMDDIiOAV Sep 17 19:09:08 volumio volumio[1102]: info: Exploding uri spotify:track:4cutUX0B5hkboZMDDIiOAV in service spop Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: EXPLODING URI:spotify:track:4cutUX0B5hkboZMDDIiOAV Sep 17 19:09:08 volumio volumio[1102]: info: Adding Item to queue: spotify:track:7hk9mxuxglA8dBz0MrmAzv Sep 17 19:09:08 volumio volumio[1102]: info: Exploding uri spotify:track:7hk9mxuxglA8dBz0MrmAzv in service spop Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: EXPLODING URI:spotify:track:7hk9mxuxglA8dBz0MrmAzv Sep 17 19:09:08 volumio volumio[1102]: info: Adding Item to queue: spotify:track:0UpASzybhdcF8RUUH197Rv Sep 17 19:09:08 volumio volumio[1102]: info: Exploding uri spotify:track:0UpASzybhdcF8RUUH197Rv in service spop Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: EXPLODING URI:spotify:track:0UpASzybhdcF8RUUH197Rv Sep 17 19:09:08 volumio volumio[1102]: info: Adding Item to queue: spotify:track:7dVyiiyf7XCdxqqSuP1926 Sep 17 19:09:08 volumio volumio[1102]: info: Exploding uri spotify:track:7dVyiiyf7XCdxqqSuP1926 in service spop Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: EXPLODING URI:spotify:track:7dVyiiyf7XCdxqqSuP1926 Sep 17 19:09:08 volumio volumio[1102]: info: Adding Item to queue: spotify:track:3wFt3HT5Xbk5aRhbTmQzBc Sep 17 19:09:08 volumio volumio[1102]: info: Exploding uri spotify:track:3wFt3HT5Xbk5aRhbTmQzBc in service spop Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: EXPLODING URI:spotify:track:3wFt3HT5Xbk5aRhbTmQzBc Sep 17 19:09:08 volumio volumio[1102]: info: Adding Item to queue: spotify:track:6ulVLIHdYI25RvXAHYdS5m Sep 17 19:09:08 volumio volumio[1102]: info: Exploding uri spotify:track:6ulVLIHdYI25RvXAHYdS5m in service spop Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: EXPLODING URI:spotify:track:6ulVLIHdYI25RvXAHYdS5m Sep 17 19:09:08 volumio volumio[1102]: info: Adding Item to queue: spotify:track:3RYknC8PTnTRsCuLJDJWYR Sep 17 19:09:08 volumio volumio[1102]: info: Exploding uri spotify:track:3RYknC8PTnTRsCuLJDJWYR in service spop Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: EXPLODING URI:spotify:track:3RYknC8PTnTRsCuLJDJWYR Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::stop Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::play index undefined Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 17 19:09:08 volumio volumio[1102]: info: CorePlayQueue::getTrack 0 Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::startPlaybackTimer Sep 17 19:09:08 volumio volumio[1102]: info: CorePlayQueue::getTrack 0 Sep 17 19:09:08 volumio volumio[1102]: info: [1758128948235] ControllerSpotify::clearAddPlayTrack Sep 17 19:09:08 volumio volumio[1102]: info: Sending Spotify command with payload to local API: /player/play Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=debug msg="resolved context of track" uri="spotify:track:3nYfUQdzDLz69L63qnwVCB" Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:3nYfUQdzDLz69L63qnwVCB" Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:3nYfUQdzDLz69L63qnwVCB" Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=trace msg="emitting websocket event: will_play" Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3nYfUQdzDLz69L63qnwVCB","play_origin":"go-librespot"}} Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1tET394Eqxaa9suIWhD4qN","service":"spop","name":"Gamzedeyim Deva Bulmam","artist":"Armageddon Turk","album":"Anadolu Lo-fi","type":"song","duration":186,"albumart":"https://i.scdn.co/image/ab67616d0000b27397bd55f273347c262d776dea","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2pt41XKgycdBxDa1lfCROi","service":"spop","name":"Şaka Yaptım - Armageddon Turk 'Arada' Mix","artist":"Gülden Karaböcek","album":"Arada (Orijinal Film Müzikleri)","type":"song","duration":174,"albumart":"https://i.scdn.co/image/ab67616d0000b2737760c0b665cb09c5dc4da4cf","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7dVyiiyf7XCdxqqSuP1926","service":"spop","name":"Hey Onbeşli","artist":"Armageddon Turk","album":"Anadolu Lo-fi","type":"song","duration":140,"albumart":"https://i.scdn.co/image/ab67616d0000b27397bd55f273347c262d776dea","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=debug msg="selected format OGG_VORBIS_320 (cec5e47496d6cf087ab4b20906417f4ad4ee10b5)" uri="spotify:track:3nYfUQdzDLz69L63qnwVCB" Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=debug msg="requested aes key for file cec5e47496d6cf087ab4b20906417f4ad4ee10b5, gid: 3nYfUQdzDLz69L63qnwVCB" Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3wFt3HT5Xbk5aRhbTmQzBc","service":"spop","name":"Üsküdar'a Giderken","artist":"Armageddon Turk","album":"Anadolu Lo-fi","type":"song","duration":154,"albumart":"https://i.scdn.co/image/ab67616d0000b27397bd55f273347c262d776dea","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0UpASzybhdcF8RUUH197Rv","service":"spop","name":"Ihanetten Geri Kalan - Armageddon Turk Mix","artist":"Sezen Aksu","album":"Biraz Pop Biraz Sezen (Remix)","type":"song","duration":219,"albumart":"https://i.scdn.co/image/ab67616d0000b273ba3ac456fb97b0e0a8fe2e2f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6ulVLIHdYI25RvXAHYdS5m","service":"spop","name":"O Yar Gelir","artist":"Armageddon Turk","album":"Anadolu Lo-fi","type":"song","duration":166,"albumart":"https://i.scdn.co/image/ab67616d0000b27397bd55f273347c262d776dea","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7hk9mxuxglA8dBz0MrmAzv","service":"spop","name":"Burçak Tarlası","artist":"Armageddon Turk","album":"Anadolu Lo-fi","type":"song","duration":155,"albumart":"https://i.scdn.co/image/ab67616d0000b27397bd55f273347c262d776dea","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:3nYfUQdzDLz69L63qnwVCB" Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4cutUX0B5hkboZMDDIiOAV","service":"spop","name":"Hadi O Zaman - Armageddon Turk Remix","artist":"Nazan Öncel","album":"Hadi O Zaman (Armageddon Turk Remix)","type":"song","duration":236,"albumart":"https://i.scdn.co/image/ab67616d0000b273ae874fa2ede843ee65b4ab2b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3RYknC8PTnTRsCuLJDJWYR","service":"spop","name":"Dere Geliyor Dere","artist":"Armageddon Turk","album":"Anadolu Lo-fi","type":"song","duration":147,"albumart":"https://i.scdn.co/image/ab67616d0000b27397bd55f273347c262d776dea","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 17 19:09:08 volumio volumio[1102]: info: CoreCommandRouter::volumioPushQueue Sep 17 19:09:08 volumio volumio[1102]: info: CorePlayQueue::saveQueue Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::updateTrackBlock Sep 17 19:09:08 volumio volumio[1102]: info: CorePlayQueue::getTrackBlock Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=debug msg="fetched first chunk of 16, total size is 8181420 bytes" uri="spotify:track:3nYfUQdzDLz69L63qnwVCB" Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02: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" Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=info msg="loaded track \"Bir Güle Kandım - Armageddon Turk Remix\" (paused: false, position: 0ms, duration: 181200ms, prefetched: false)" uri="spotify:track:3nYfUQdzDLz69L63qnwVCB" Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=trace msg="scheduling prefetch in 151s" Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=trace msg="emitting websocket event: metadata" Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3nYfUQdzDLz69L63qnwVCB","name":"Bir Güle Kandım - Armageddon Turk Remix","artist_names":["Nilüfer","Armageddon Turk"],"album_name":"Bir Güle Kandım (Armageddon Turk Remix)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02a050924dd862c7eaacd64a76","position":0,"duration":181200,"release_date":"year:2025 month:9 day:1","track_number":1,"disc_number":1}} Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=trace msg="emitting websocket event: playing" Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:3nYfUQdzDLz69L63qnwVCB","resume":false,"play_origin":"go-librespot"}} Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: PUSH STATE SPOTIFY Sep 17 19:09:08 volumio volumio[1102]: SPOTIFY: {"status":"play","service":"spop","title":"Bir Güle Kandım - Armageddon Turk Remix","artist":"Nilüfer, Armageddon Turk","album":"Bir Güle Kandım (Armageddon Turk Remix)","albumart":"https://i.scdn.co/image/ab67616d00001e02a050924dd862c7eaacd64a76","uri":"spotify:track:3nYfUQdzDLz69L63qnwVCB","trackType":"spotify","seek":0,"duration":181,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 17 19:09:08 volumio volumio[1102]: info: CoreCommandRouter::servicePushState Sep 17 19:09:08 volumio volumio[1102]: info: CorePlayQueue::getTrack 0 Sep 17 19:09:08 volumio volumio[1102]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Bir Güle Kandım - Armageddon Turk Remix","artist":"Nilüfer, Armageddon Turk","album":"Bir Güle Kandım (Armageddon Turk Remix)","albumart":"https://i.scdn.co/image/ab67616d00001e02a050924dd862c7eaacd64a76","uri":"spotify:track:3nYfUQdzDLz69L63qnwVCB","trackType":"spotify","seek":0,"duration":181,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 17 19:09:08 volumio volumio[1102]: verbose: CURRENT POSITION 0 Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::syncState stateService play Sep 17 19:09:08 volumio volumio[1102]: info: CoreStateMachine::syncState currentStatus stop Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:3nYfUQdzDLz69L63qnwVCB" Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:3nYfUQdzDLz69L63qnwVCB" Sep 17 19:09:08 volumio go-librespot[1447]: time="2025-09-17T19:09:08+02:00" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:3nYfUQdzDLz69L63qnwVCB" Sep 17 19:09:09 volumio volumio[1102]: SPOTIFY: PUSH STATE SPOTIFY Sep 17 19:09:09 volumio volumio[1102]: SPOTIFY: {"status":"play","service":"spop","title":"Bir Güle Kandım - Armageddon Turk Remix","artist":"Nilüfer, Armageddon Turk","album":"Bir Güle Kandım (Armageddon Turk Remix)","albumart":"https://i.scdn.co/image/ab67616d00001e02a050924dd862c7eaacd64a76","uri":"spotify:track:3nYfUQdzDLz69L63qnwVCB","trackType":"spotify","seek":0,"duration":181,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 17 19:09:09 volumio volumio[1102]: info: CoreCommandRouter::servicePushState Sep 17 19:09:09 volumio volumio[1102]: info: CorePlayQueue::getTrack 0 Sep 17 19:09:09 volumio volumio[1102]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Bir Güle Kandım - Armageddon Turk Remix","artist":"Nilüfer, Armageddon Turk","album":"Bir Güle Kandım (Armageddon Turk Remix)","albumart":"https://i.scdn.co/image/ab67616d00001e02a050924dd862c7eaacd64a76","uri":"spotify:track:3nYfUQdzDLz69L63qnwVCB","trackType":"spotify","seek":0,"duration":181,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 17 19:09:09 volumio volumio[1102]: verbose: CURRENT POSITION 0 Sep 17 19:09:09 volumio volumio[1102]: info: CoreStateMachine::syncState stateService play Sep 17 19:09:09 volumio volumio[1102]: info: CoreStateMachine::syncState currentStatus play Sep 17 19:09:09 volumio volumio[1102]: info: Received an update from plugin. extracting info from payload Sep 17 19:09:09 volumio volumio[1102]: info: CoreStateMachine::pushState Sep 17 19:09:09 volumio volumio[1102]: info: CorePlayQueue::getTrack 0 Sep 17 19:09:09 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 19:09:09 volumio volumio[1102]: info: CoreCommandRouter::volumioPushState Sep 17 19:09:09 volumio volumio[1102]: info: CoreStateMachine::pushState Sep 17 19:09:09 volumio volumio[1102]: info: CorePlayQueue::getTrack 0 Sep 17 19:09:09 volumio volumio[1102]: info: CoreCommandRouter::volumioPushState Sep 17 19:09:09 volumio volumio[1102]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Sep 17 19:09:09 volumio volumio[1102]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Sep 17 19:09:20 volumio go-librespot[1447]: time="2025-09-17T19:09:20+02:00" level=debug msg="fetched chunk 4/15, size: 524288" uri="spotify:track:3nYfUQdzDLz69L63qnwVCB" Sep 17 19:09:26 volumio volumio[1102]: Searching plugin music_service/spop Sep 17 19:09:26 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: spop , search Sep 17 19:09:27 volumio volumio[1102]: info: All search sources collected, pushing search results Sep 17 19:09:32 volumio go-librespot[1447]: time="2025-09-17T19:09:32+02:00" level=debug msg="fetched chunk 5/15, size: 524288" uri="spotify:track:3nYfUQdzDLz69L63qnwVCB" Sep 17 19:09:32 volumio volumio[1102]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Sep 17 19:09:32 volumio volumio[1102]: info: In handleBrowseUri, curUri=spotify:artist:0gsNjh6PB3ruHmBl1Sib3K Sep 17 19:09:33 volumio volumio[1102]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 17 19:09:33 volumio volumio[1102]: TypeError: Cannot read properties of undefined (reading 'url') Sep 17 19:09:33 volumio volumio[1102]: at /data/plugins/music_service/spop/index.js:2449:60 Sep 17 19:09:33 volumio volumio[1102]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Sep 17 19:09:33 volumio volumio[1102]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 17 19:09:35 volumio sudo[7412]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-09-17 19:08' Sep 17 19:09:35 volumio sudo[7412]: 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"