Feb 09 07:34:00 volumio volumio[30202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:34:00 volumio volumio[30202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:34:00 volumio volumio[30202]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 09 07:34:00 volumio volumio[30202]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 09 07:34:00 volumio volumio[30202]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 09 07:34:00 volumio volumio[30202]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 09 07:34:00 volumio volumio[30202]: info: CoreCommandRouter::volumioGetBrowseSources Feb 09 07:34:00 volumio volumio[30202]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 07:34:01 volumio volumio[30202]: info: CoreCommandRouter::volumioGetState Feb 09 07:34:01 volumio volumio[30202]: info: CorePlayQueue::getTrack 0 Feb 09 07:34:02 volumio volumio[30202]: error: MyVolumio Plugin failed to authenticate in a timely fashion Feb 09 07:34:02 volumio volumio[30202]: info: Completed starting MyVolumio Plugin Feb 09 07:34:02 volumio volumio[30202]: [Metrics] CommandRouter: 54s 31.21ms Feb 09 07:34:02 volumio volumio[30202]: info: CoreCommandRouter::volumiosetStartupVolume Feb 09 07:34:02 volumio volumio[30202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 07:34:02 volumio volumio[30202]: info: VolumeController:: Setting startup Volume 75 Feb 09 07:34:02 volumio volumio[30202]: info: VolumeController::SetAlsaVolume75 Feb 09 07:34:02 volumio volumio[30202]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 07:34:02 volumio volumio[30202]: info: CoreCommandRouter::Close All Modals sent Feb 09 07:34:02 volumio volumio[30202]: info: CoreCommandRouter::Close All Modals sent Feb 09 07:34:02 volumio volumio[30202]: info: CoreStateMachine::pushState Feb 09 07:34:02 volumio volumio[30202]: info: CorePlayQueue::getTrack 0 Feb 09 07:34:02 volumio volumio[30202]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 07:34:02 volumio volumio[30202]: info: CoreCommandRouter::volumioPushState Feb 09 07:34:02 volumio volumio[30202]: info: FusionDsp - Volumio is not playing Feb 09 07:34:02 volumio volumio[30202]: info: FusionDsp - Clipped samples monitor stopped Feb 09 07:34:02 volumio volumio[30202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Feb 09 07:34:02 volumio volumio[30202]: SPOTIFY: SPOTIFY VOLUME 98 Feb 09 07:34:02 volumio volumio[30202]: SPOTIFY: VOLUMIO VOLUME 75 Feb 09 07:34:02 volumio volumio[30202]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 09 07:34:02 volumio volumio[30202]: info: Setting Spotify Volume from Volumio: 75 Feb 09 07:34:02 volumio volumio[30202]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Feb 09 07:34:02 volumio volumio[30202]: info: FusionDsp - ---- read samplerate from file: 44100 Feb 09 07:34:02 volumio volumio[30202]: info: camilladsp stopping service pid 30549... Feb 09 07:34:03 volumio volumio[30202]: grep: /proc/30549/cmdline: binary file matches Feb 09 07:34:03 volumio volumio[30202]: grep: /proc/30549/cmdline: binary file matches Feb 09 07:34:03 volumio volumio[30202]: grep: /proc/30549/cmdline: binary file matches Feb 09 07:34:03 volumio volumio[30202]: grep: /proc/30549/cmdline: binary file matches Feb 09 07:34:03 volumio volumio[30202]: grep: /proc/30549/cmdline: binary file matches Feb 09 07:34:03 volumio volumio[30202]: info: camilladsp service terminated, instance 1 Feb 09 07:34:03 volumio volumio[30202]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 09 07:34:03 volumio volumio[30202]: info: FusionDsp - else 1 -2.5 Feb 09 07:34:03 volumio volumio[30202]: info: camilladsp service started and running in background, instance 1 Feb 09 07:34:03 volumio volumio[30202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Feb 09 07:34:03 volumio volumio[30202]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 09 07:34:03 volumio volumio[30202]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Feb 09 07:34:04 volumio volumio[30202]: SPOTIFY: SETTING SPOTIFY VOLUME 75 Feb 09 07:34:04 volumio volumio[30202]: info: Sending Spotify command with payload to local API: /player/volume Feb 09 07:34:05 volumio go-librespot[30501]: time="2026-02-09T07:34:05-07:00" level=debug msg="update volume requested to 49151/65535" Feb 09 07:34:05 volumio go-librespot[30501]: time="2026-02-09T07:34:05-07:00" level=debug msg="put connect state because VOLUME_CHANGED" Feb 09 07:34:05 volumio go-librespot[30501]: time="2026-02-09T07:34:05-07:00" level=trace msg="emitting websocket event: volume" Feb 09 07:34:06 volumio volumio[30202]: SPOTIFY: received: {"type":"volume","data":{"value":75,"max":100}} Feb 09 07:34:06 volumio volumio[30202]: SPOTIFY: RECEIVED SPOTIFY VOLUME 75 Feb 09 07:34:07 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5326. Feb 09 07:34:07 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 09 07:34:07 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 09 07:34:07 volumio upmpdcli[30828]: Could not open config: /tmp/upmpdcli.conf Feb 09 07:34:07 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:34:07 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 09 07:34:09 volumio volumio[30202]: info: BOOT COMPLETED Feb 09 07:34:22 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5327. Feb 09 07:34:22 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 09 07:34:22 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 09 07:34:22 volumio upmpdcli[30861]: Could not open config: /tmp/upmpdcli.conf Feb 09 07:34:22 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:34:22 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 09 07:34:23 volumio go-librespot[30501]: time="2026-02-09T07:34:23-07:00" level=trace msg="sent dealer ping" Feb 09 07:34:23 volumio go-librespot[30501]: time="2026-02-09T07:34:23-07:00" level=trace msg="received dealer pong" Feb 09 07:34:24 volumio volumio[30202]: info: [squeezelite_mc] Server discovered: {"ip":"10.0.0.32","name":"Lyrion Music Server (Docker)","ver":"9.0.3","uuid":"015d9de8-02dd-43d0-b236-569f127b3a48","jsonPort":"9000","cliPort":"9090"} Feb 09 07:34:31 volumio volumio[30202]: info: [squeezelite_mc] Notification listener started Feb 09 07:34:31 volumio volumio[30202]: info: [squeezelite_mc] Getting players connected to Lyrion Music Server (Docker) (10.0.0.32) Feb 09 07:34:34 volumio volumio[30202]: info: [squeezelite_mc] Players connected to Lyrion Music Server (Docker) (10.0.0.32): [{"id":"b8:27:eb:0d:4f:88","uuid":null,"ip":"10.0.0.21","name":"volumio","server":{"ip":"10.0.0.32","name":"Lyrion Music Server (Docker)","ver":"9.0.3","uuid":"015d9de8-02dd-43d0-b236-569f127b3a48","jsonPort":"9000","cliPort":"9090"}},{"id":"b8:27:eb:58:3b:c2","uuid":null,"ip":"10.0.0.73","name":"ropiGenelecSQZ","server":{"ip":"10.0.0.32","name":"Lyrion Music Server (Docker)","ver":"9.0.3","uuid":"015d9de8-02dd-43d0-b236-569f127b3a48","jsonPort":"9000","cliPort":"9090"}}] Feb 09 07:34:34 volumio volumio[30202]: info: [squeezelite_mc] Player found: {"id":"b8:27:eb:0d:4f:88","uuid":null,"ip":"10.0.0.21","name":"volumio","server":{"ip":"10.0.0.32","name":"Lyrion Music Server (Docker)","ver":"9.0.3","uuid":"015d9de8-02dd-43d0-b236-569f127b3a48","jsonPort":"9000","cliPort":"9090"}} Feb 09 07:34:38 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5328. Feb 09 07:34:38 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 09 07:34:38 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 09 07:34:38 volumio upmpdcli[30877]: Could not open config: /tmp/upmpdcli.conf Feb 09 07:34:38 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:34:38 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 09 07:34:42 volumio wpa_supplicant[1108]: wlan0: WNM: Preferred List Available Feb 09 07:34:43 volumio wpa_supplicant[1108]: wlan0: Trying to associate with c6:4f:d5:fc:10:c2 (SSID='HerculeWiFi' freq=5785 MHz) Feb 09 07:34:43 volumio dhcpcd[717]: wlan0: carrier lost - roaming Feb 09 07:34:43 volumio dhcpcd[717]: wlan0: changing route to 10.0.0.0/24 Feb 09 07:34:43 volumio dhcpcd[717]: wlan0: changing default route via 10.0.0.1 Feb 09 07:34:43 volumio kernel: ieee80211 phy0: brcmf_p2p_send_action_frame: Unknown Frame: category 0xa, action 0x8 Feb 09 07:34:43 volumio wpa_supplicant[1108]: wlan0: Associated with c6:4f:d5:fc:10:c2 Feb 09 07:34:43 volumio wpa_supplicant[1108]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Feb 09 07:34:43 volumio wpa_supplicant[1108]: wlan0: WPA: Key negotiation completed with c6:4f:d5:fc:10:c2 [PTK=CCMP GTK=CCMP] Feb 09 07:34:43 volumio wpa_supplicant[1108]: wlan0: CTRL-EVENT-CONNECTED - Connection to c6:4f:d5:fc:10:c2 completed [id=0 id_str=] Feb 09 07:34:43 volumio dhcpcd[717]: wlan0: carrier acquired Feb 09 07:34:43 volumio dhcpcd[717]: wlan0: IAID eb:0d:4f:88 Feb 09 07:34:43 volumio dhcpcd[717]: wlan0: using static address 10.0.0.21/24 Feb 09 07:34:43 volumio dhcpcd[717]: wlan0: changing route to 10.0.0.0/24 Feb 09 07:34:43 volumio dhcpcd[717]: wlan0: changing default route via 10.0.0.1 Feb 09 07:34:43 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Feb 09 07:34:43 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Feb 09 07:34:43 volumio systemd[1]: welcome.service: Deactivated successfully. Feb 09 07:34:43 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Feb 09 07:34:43 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Feb 09 07:34:43 volumio dhcpcd[717]: wlan0: soliciting an IPv6 router Feb 09 07:34:43 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Feb 09 07:34:43 volumio welcome[30927]: Resolved ip:[1] 10.0.0.21 Feb 09 07:34:43 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Feb 09 07:34:43 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Feb 09 07:34:53 volumio go-librespot[30501]: time="2026-02-09T07:34:53-07:00" level=trace msg="sent dealer ping" Feb 09 07:34:53 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5329. Feb 09 07:34:53 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 09 07:34:53 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 09 07:34:53 volumio upmpdcli[30946]: Could not open config: /tmp/upmpdcli.conf Feb 09 07:34:53 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:34:53 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 09 07:34:57 volumio volumio[30202]: error: [squeezelite_mc] Error in getting Squeezelite's sync master: fetch failed TypeError: fetch failed Feb 09 07:34:57 volumio volumio[30202]: at Object.fetch (node:internal/deps/undici/undici:11576:11) Feb 09 07:34:57 volumio volumio[30202]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Feb 09 07:34:57 volumio volumio[30202]: at async sendRpcRequest (/data/plugins/music_service/squeezelite_mc/dist/lib/RPC.js:23:26) Feb 09 07:34:57 volumio volumio[30202]: at async PlayerStatusMonitor._PlayerStatusMonitor_getPlayerSyncMaster (/data/plugins/music_service/squeezelite_mc/dist/lib/PlayerStatusMonitor.js:167:24) Feb 09 07:34:57 volumio volumio[30202]: at async PlayerStatusMonitor.start (/data/plugins/music_service/squeezelite_mc/dist/lib/PlayerStatusMonitor.js:42:72) Feb 09 07:34:57 volumio volumio[30202]: at async /data/plugins/music_service/squeezelite_mc/dist/index.js:740:17 Feb 09 07:35:05 volumio go-librespot[30501]: time="2026-02-09T07:35:05-07:00" level=trace msg="received dealer pong" Feb 09 07:35:07 volumio volumio[30202]: info: [squeezelite_mc] 'client' notification received from Lyrion Music Server (Docker) (10.0.0.32); type is 'null' Feb 09 07:35:08 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5330. Feb 09 07:35:08 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 09 07:35:08 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 09 07:35:08 volumio upmpdcli[30962]: Could not open config: /tmp/upmpdcli.conf Feb 09 07:35:08 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 09 07:35:08 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 09 07:35:09 volumio volumio[30202]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 07:35:09 volumio volumio[30202]: TypeError: fetch failed Feb 09 07:35:09 volumio volumio[30202]: at Object.fetch (node:internal/deps/undici/undici:11576:11) Feb 09 07:35:09 volumio volumio[30202]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Feb 09 07:35:09 volumio volumio[30202]: at async sendRpcRequest (/data/plugins/music_service/squeezelite_mc/dist/lib/RPC.js:23:26) Feb 09 07:35:09 volumio volumio[30202]: at async PlayerStatusMonitor._PlayerStatusMonitor_getStatusAndEmit (/data/plugins/music_service/squeezelite_mc/dist/lib/PlayerStatusMonitor.js:124:26) Feb 09 07:35:09 volumio volumio[30202]: at async PlayerStatusMonitor.start (/data/plugins/music_service/squeezelite_mc/dist/lib/PlayerStatusMonitor.js:46:9) Feb 09 07:35:09 volumio volumio[30202]: at async /data/plugins/music_service/squeezelite_mc/dist/index.js:740:17 { Feb 09 07:35:09 volumio volumio[30202]: cause: ConnectTimeoutError: Connect Timeout Error Feb 09 07:35:09 volumio volumio[30202]: at onConnectTimeout (node:internal/deps/undici/undici:8522:28) Feb 09 07:35:09 volumio volumio[30202]: at node:internal/deps/undici/undici:8480:50 Feb 09 07:35:09 volumio volumio[30202]: at Immediate._onImmediate (node:internal/deps/undici/undici:8511:13) Feb 09 07:35:09 volumio volumio[30202]: at process.processImmediate (node:internal/timers:478:21) { Feb 09 07:35:09 volumio volumio[30202]: code: 'UND_ERR_CONNECT_TIMEOUT' Feb 09 07:35:09 volumio volumio[30202]: } Feb 09 07:35:09 volumio volumio[30202]: } Feb 09 07:35:09 volumio volumio[30202]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 07:35:10 volumio sudo[30977]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 07:34' Feb 09 07:35:10 volumio sudo[30977]: 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"