Feb 23 22:13:05 volumiocala go-librespot[1661]: time="2026-02-23T22:13:05+02:00" level=trace msg="sent dealer ping" Feb 23 22:13:05 volumiocala go-librespot[1661]: time="2026-02-23T22:13:05+02:00" level=trace msg="received dealer pong" Feb 23 22:13:10 volumiocala systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1027. Feb 23 22:13:10 volumiocala systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 23 22:13:10 volumiocala systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 23 22:13:10 volumiocala upmpdcli[27185]: Could not open config: /tmp/upmpdcli.conf Feb 23 22:13:10 volumiocala systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 23 22:13:10 volumiocala systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 23 22:13:11 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume43 Feb 23 22:13:11 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:11 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:11 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:11 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:11 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Feb 23 22:13:11 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 41 Feb 23 22:13:11 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 43 Feb 23 22:13:11 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 23 22:13:11 volumiocala volumio[1206]: info: Setting Spotify Volume from Volumio: 43 Feb 23 22:13:12 volumiocala volumio[1206]: SPOTIFY: SETTING SPOTIFY VOLUME 43 Feb 23 22:13:12 volumiocala volumio[1206]: info: Sending Spotify command with payload to local API: /player/volume Feb 23 22:13:12 volumiocala go-librespot[1661]: time="2026-02-23T22:13:12+02:00" level=debug msg="update volume requested to 28180/65535" Feb 23 22:13:13 volumiocala go-librespot[1661]: time="2026-02-23T22:13:13+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Feb 23 22:13:13 volumiocala go-librespot[1661]: time="2026-02-23T22:13:13+02:00" level=trace msg="emitting websocket event: volume" Feb 23 22:13:13 volumiocala volumio[1206]: SPOTIFY: received: {"type":"volume","data":{"value":43,"max":100}} Feb 23 22:13:13 volumiocala volumio[1206]: SPOTIFY: RECEIVED SPOTIFY VOLUME 43 Feb 23 22:13:13 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume44 Feb 23 22:13:13 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:13 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:13 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:13 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:13 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Feb 23 22:13:13 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 43 Feb 23 22:13:13 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 44 Feb 23 22:13:13 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 23 22:13:14 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume45 Feb 23 22:13:14 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:14 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:14 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:14 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:14 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Feb 23 22:13:14 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 43 Feb 23 22:13:14 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 45 Feb 23 22:13:14 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 23 22:13:14 volumiocala volumio[1206]: info: Setting Spotify Volume from Volumio: 45 Feb 23 22:13:14 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume46 Feb 23 22:13:14 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:14 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:14 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:14 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:14 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Feb 23 22:13:14 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 45 Feb 23 22:13:14 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 46 Feb 23 22:13:14 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 23 22:13:14 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume47 Feb 23 22:13:14 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:14 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:14 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:14 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:14 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 47 Feb 23 22:13:14 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 45 Feb 23 22:13:14 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 47 Feb 23 22:13:14 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 23 22:13:14 volumiocala volumio[1206]: info: Setting Spotify Volume from Volumio: 47 Feb 23 22:13:15 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume48 Feb 23 22:13:15 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:15 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:15 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:15 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:15 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 48 Feb 23 22:13:15 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 47 Feb 23 22:13:15 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 48 Feb 23 22:13:15 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 23 22:13:15 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume49 Feb 23 22:13:15 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:15 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:15 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:15 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:15 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 49 Feb 23 22:13:15 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 47 Feb 23 22:13:15 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 49 Feb 23 22:13:15 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 23 22:13:15 volumiocala volumio[1206]: info: Setting Spotify Volume from Volumio: 49 Feb 23 22:13:15 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume50 Feb 23 22:13:15 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:15 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:15 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:15 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:15 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Feb 23 22:13:15 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 49 Feb 23 22:13:15 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 50 Feb 23 22:13:15 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 23 22:13:16 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume51 Feb 23 22:13:16 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:16 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:16 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:16 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:16 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Feb 23 22:13:16 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 49 Feb 23 22:13:16 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 51 Feb 23 22:13:16 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 23 22:13:16 volumiocala volumio[1206]: info: Setting Spotify Volume from Volumio: 51 Feb 23 22:13:16 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume52 Feb 23 22:13:16 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:16 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:16 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:16 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:16 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Feb 23 22:13:16 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 51 Feb 23 22:13:16 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 52 Feb 23 22:13:16 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 23 22:13:16 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume53 Feb 23 22:13:16 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:16 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:16 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:16 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:16 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53 Feb 23 22:13:16 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 51 Feb 23 22:13:16 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 53 Feb 23 22:13:16 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 23 22:13:16 volumiocala volumio[1206]: info: Setting Spotify Volume from Volumio: 53 Feb 23 22:13:16 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume54 Feb 23 22:13:16 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:16 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:16 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:16 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:16 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 54 Feb 23 22:13:16 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 53 Feb 23 22:13:16 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 54 Feb 23 22:13:16 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 23 22:13:17 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume55 Feb 23 22:13:17 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:17 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:17 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:17 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:17 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Feb 23 22:13:17 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 53 Feb 23 22:13:17 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 55 Feb 23 22:13:17 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 23 22:13:17 volumiocala volumio[1206]: info: Setting Spotify Volume from Volumio: 55 Feb 23 22:13:17 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume56 Feb 23 22:13:17 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:17 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:17 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:17 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:17 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Feb 23 22:13:17 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 55 Feb 23 22:13:17 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 56 Feb 23 22:13:17 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 23 22:13:17 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume57 Feb 23 22:13:17 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:17 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:17 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:17 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:17 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 23 22:13:17 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 55 Feb 23 22:13:17 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 57 Feb 23 22:13:17 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 23 22:13:17 volumiocala volumio[1206]: info: Setting Spotify Volume from Volumio: 57 Feb 23 22:13:18 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume58 Feb 23 22:13:18 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:18 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:18 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:18 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:18 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 23 22:13:18 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 57 Feb 23 22:13:18 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 58 Feb 23 22:13:18 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 23 22:13:19 volumiocala volumio[1206]: SPOTIFY: SETTING SPOTIFY VOLUME 57 Feb 23 22:13:19 volumiocala volumio[1206]: info: Sending Spotify command with payload to local API: /player/volume Feb 23 22:13:19 volumiocala go-librespot[1661]: time="2026-02-23T22:13:19+02:00" level=debug msg="update volume requested to 37354/65535" Feb 23 22:13:19 volumiocala go-librespot[1661]: time="2026-02-23T22:13:19+02:00" level=trace msg="received accesspoint ping" Feb 23 22:13:19 volumiocala go-librespot[1661]: time="2026-02-23T22:13:19+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Feb 23 22:13:19 volumiocala go-librespot[1661]: time="2026-02-23T22:13:19+02:00" level=trace msg="emitting websocket event: volume" Feb 23 22:13:19 volumiocala volumio[1206]: SPOTIFY: received: {"type":"volume","data":{"value":57,"max":100}} Feb 23 22:13:19 volumiocala volumio[1206]: SPOTIFY: RECEIVED SPOTIFY VOLUME 57 Feb 23 22:13:19 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume59 Feb 23 22:13:19 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:19 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:19 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:19 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:19 volumiocala go-librespot[1661]: time="2026-02-23T22:13:19+02:00" level=trace msg="received accesspoint pong ack" Feb 23 22:13:19 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 59 Feb 23 22:13:19 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 57 Feb 23 22:13:19 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 59 Feb 23 22:13:19 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 23 22:13:19 volumiocala volumio[1206]: info: Setting Spotify Volume from Volumio: 59 Feb 23 22:13:21 volumiocala volumio[1206]: SPOTIFY: SETTING SPOTIFY VOLUME 59 Feb 23 22:13:21 volumiocala volumio[1206]: info: Sending Spotify command with payload to local API: /player/volume Feb 23 22:13:21 volumiocala go-librespot[1661]: time="2026-02-23T22:13:21+02:00" level=debug msg="update volume requested to 38665/65535" Feb 23 22:13:21 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume58 Feb 23 22:13:21 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:21 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:21 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:21 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:21 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 23 22:13:21 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 59 Feb 23 22:13:21 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 58 Feb 23 22:13:21 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 23 22:13:21 volumiocala go-librespot[1661]: time="2026-02-23T22:13:21+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Feb 23 22:13:21 volumiocala go-librespot[1661]: time="2026-02-23T22:13:21+02:00" level=trace msg="emitting websocket event: volume" Feb 23 22:13:21 volumiocala volumio[1206]: SPOTIFY: received: {"type":"volume","data":{"value":59,"max":100}} Feb 23 22:13:21 volumiocala volumio[1206]: SPOTIFY: RECEIVED SPOTIFY VOLUME 59 Feb 23 22:13:21 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume57 Feb 23 22:13:21 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:21 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:21 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:21 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:21 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 23 22:13:21 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 59 Feb 23 22:13:21 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 57 Feb 23 22:13:21 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 23 22:13:21 volumiocala volumio[1206]: info: Setting Spotify Volume from Volumio: 57 Feb 23 22:13:21 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume56 Feb 23 22:13:21 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:21 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:21 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:21 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:21 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Feb 23 22:13:21 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 57 Feb 23 22:13:21 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 56 Feb 23 22:13:21 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 23 22:13:22 volumiocala volumio[1206]: info: VolumeController::SetAlsaVolume55 Feb 23 22:13:22 volumiocala volumio[1206]: info: CoreStateMachine::pushState Feb 23 22:13:22 volumiocala volumio[1206]: info: CorePlayQueue::getTrack 9 Feb 23 22:13:22 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 22:13:22 volumiocala volumio[1206]: info: CoreCommandRouter::volumioPushState Feb 23 22:13:22 volumiocala volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Feb 23 22:13:22 volumiocala volumio[1206]: SPOTIFY: SPOTIFY VOLUME 57 Feb 23 22:13:22 volumiocala volumio[1206]: SPOTIFY: VOLUMIO VOLUME 55 Feb 23 22:13:22 volumiocala volumio[1206]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 23 22:13:22 volumiocala volumio[1206]: info: Setting Spotify Volume from Volumio: 55 Feb 23 22:13:23 volumiocala volumio[1206]: SPOTIFY: SETTING SPOTIFY VOLUME 55 Feb 23 22:13:23 volumiocala volumio[1206]: info: Sending Spotify command with payload to local API: /player/volume Feb 23 22:13:23 volumiocala go-librespot[1661]: time="2026-02-23T22:13:23+02:00" level=debug msg="update volume requested to 36044/65535" Feb 23 22:13:23 volumiocala go-librespot[1661]: time="2026-02-23T22:13:23+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Feb 23 22:13:23 volumiocala go-librespot[1661]: time="2026-02-23T22:13:23+02:00" level=trace msg="emitting websocket event: volume" Feb 23 22:13:23 volumiocala volumio[1206]: SPOTIFY: received: {"type":"volume","data":{"value":55,"max":100}} Feb 23 22:13:23 volumiocala volumio[1206]: SPOTIFY: RECEIVED SPOTIFY VOLUME 55 Feb 23 22:13:25 volumiocala systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1028. Feb 23 22:13:25 volumiocala systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 23 22:13:25 volumiocala systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 23 22:13:25 volumiocala upmpdcli[27236]: Could not open config: /tmp/upmpdcli.conf Feb 23 22:13:25 volumiocala systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 23 22:13:25 volumiocala systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 23 22:13:35 volumiocala go-librespot[1661]: time="2026-02-23T22:13:35+02:00" level=trace msg="sent dealer ping" Feb 23 22:13:35 volumiocala go-librespot[1661]: time="2026-02-23T22:13:35+02:00" level=trace msg="received dealer pong" Feb 23 22:13:41 volumiocala systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1029. Feb 23 22:13:41 volumiocala systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 23 22:13:41 volumiocala systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 23 22:13:41 volumiocala upmpdcli[27253]: Could not open config: /tmp/upmpdcli.conf Feb 23 22:13:41 volumiocala systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 23 22:13:41 volumiocala systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 23 22:13:56 volumiocala systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1030. Feb 23 22:13:56 volumiocala systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 23 22:13:56 volumiocala systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 23 22:13:56 volumiocala upmpdcli[27283]: Could not open config: /tmp/upmpdcli.conf Feb 23 22:13:56 volumiocala systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 23 22:13:56 volumiocala systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 23 22:14:05 volumiocala go-librespot[1661]: time="2026-02-23T22:14:05+02:00" level=trace msg="sent dealer ping" Feb 23 22:14:05 volumiocala go-librespot[1661]: time="2026-02-23T22:14:05+02:00" level=trace msg="received dealer pong" Feb 23 22:14:11 volumiocala systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1031. Feb 23 22:14:11 volumiocala systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 23 22:14:11 volumiocala systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 23 22:14:11 volumiocala upmpdcli[27312]: Could not open config: /tmp/upmpdcli.conf Feb 23 22:14:11 volumiocala systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 23 22:14:11 volumiocala systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 23 22:14:26 volumiocala systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Feb 23 22:14:26 volumiocala systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1032. Feb 23 22:14:26 volumiocala systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 23 22:14:26 volumiocala systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 23 22:14:26 volumiocala upmpdcli[27344]: Could not open config: /tmp/upmpdcli.conf Feb 23 22:14:26 volumiocala systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 23 22:14:26 volumiocala systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 23 22:14:27 volumiocala systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 23 22:14:27 volumiocala systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 23 22:14:35 volumiocala go-librespot[1661]: time="2026-02-23T22:14:35+02:00" level=trace msg="sent dealer ping" Feb 23 22:14:35 volumiocala go-librespot[1661]: time="2026-02-23T22:14:35+02:00" level=trace msg="received dealer pong" Feb 23 22:14:38 volumiocala volumio[1206]: Searching plugin music_service/mpd Feb 23 22:14:38 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , search Feb 23 22:14:39 volumiocala volumio[1206]: Cannot compose Albumart path Feb 23 22:14:39 volumiocala volumio[1206]: Cannot compose Albumart path Feb 23 22:14:39 volumiocala volumio[1206]: info: All search sources collected, pushing search results Feb 23 22:14:40 volumiocala volumio[1206]: Searching plugin music_service/mpd Feb 23 22:14:40 volumiocala volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , search Feb 23 22:14:41 volumiocala volumio[1206]: info: All search sources collected, pushing search results Feb 23 22:14:41 volumiocala volumio[1206]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 22:14:41 volumiocala volumio[1206]: TypeError: Cannot read properties of null (reading 'slice') Feb 23 22:14:41 volumiocala volumio[1206]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Feb 23 22:14:41 volumiocala volumio[1206]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Feb 23 22:14:41 volumiocala volumio[1206]: at Object.onceWrapper (node:events:629:26) Feb 23 22:14:41 volumiocala volumio[1206]: at ClientRequest.emit (node:events:514:28) Feb 23 22:14:41 volumiocala volumio[1206]: at HTTPParser.parserOnIncomingClient [as onIncoming] (node:_http_client:693:27) Feb 23 22:14:41 volumiocala volumio[1206]: at HTTPParser.parserOnHeadersComplete (node:_http_common:119:17) Feb 23 22:14:41 volumiocala volumio[1206]: at TLSSocket.socketOnData (node:_http_client:535:22) Feb 23 22:14:41 volumiocala volumio[1206]: at TLSSocket.emit (node:events:514:28) Feb 23 22:14:41 volumiocala volumio[1206]: at addChunk (node:internal/streams/readable:343:12) Feb 23 22:14:41 volumiocala volumio[1206]: at readableAddChunk (node:internal/streams/readable:316:9) Feb 23 22:14:41 volumiocala volumio[1206]: at Readable.push (node:internal/streams/readable:253:10) Feb 23 22:14:41 volumiocala volumio[1206]: at TLSWrap.onStreamRead (node:internal/stream_base_commons:190:23) Feb 23 22:14:41 volumiocala volumio[1206]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 22:14:42 volumiocala sudo[27398]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-23 22:13' Feb 23 22:14:42 volumiocala sudo[27398]: 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"