Dez 29 18:40:00 volumiokueche volumio[4328]: error: MyVolumio Plugin failed to start in a timely fashion Dez 29 18:40:00 volumiokueche volumio[4328]: [Metrics] CommandRouter: 23s 950.14ms Dez 29 18:40:00 volumiokueche volumio[4328]: info: CoreCommandRouter::volumiosetStartupVolume Dez 29 18:40:00 volumiokueche volumio[4328]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dez 29 18:40:00 volumiokueche volumio[4328]: info: VolumeController:: Setting startup Volume 20 Dez 29 18:40:00 volumiokueche volumio[4328]: info: VolumeController::SetAlsaVolume20 Dez 29 18:40:00 volumiokueche volumio[4328]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dez 29 18:40:00 volumiokueche volumio[4328]: info: CoreCommandRouter::Close All Modals sent Dez 29 18:40:00 volumiokueche volumio[4328]: info: CoreCommandRouter::Close All Modals sent Dez 29 18:40:00 volumiokueche volumio[4328]: info: CoreStateMachine::pushState Dez 29 18:40:00 volumiokueche volumio[4328]: info: CorePlayQueue::getTrack 0 Dez 29 18:40:00 volumiokueche volumio[4328]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dez 29 18:40:00 volumiokueche volumio[4328]: info: CoreCommandRouter::volumioPushState Dez 29 18:40:00 volumiokueche volumio[4328]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Dez 29 18:40:00 volumiokueche volumio[4328]: info: FusionDsp - ---- read samplerate from file: 44100 Dez 29 18:40:00 volumiokueche volumio[4328]: info: camilladsp stopping service pid 4627... Dez 29 18:40:01 volumiokueche volumio[4328]: grep: /proc/4627/cmdline: binary file matches Dez 29 18:40:01 volumiokueche volumio[4328]: info: camilladsp service terminated, instance 1 Dez 29 18:40:01 volumiokueche volumio[4328]: info: FusionDsp - If filter freq >samplerate/2 then disable it Dez 29 18:40:01 volumiokueche volumio[4328]: info: camilladsp service started and running in background, instance 1 Dez 29 18:40:01 volumiokueche volumio[4328]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dez 29 18:40:01 volumiokueche volumio[4328]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dez 29 18:40:01 volumiokueche volumio[4328]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dez 29 18:40:04 volumiokueche systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 46511. Dez 29 18:40:04 volumiokueche systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dez 29 18:40:04 volumiokueche systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dez 29 18:40:04 volumiokueche upmpdcli[4706]: Could not open config: /tmp/upmpdcli.conf Dez 29 18:40:04 volumiokueche systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dez 29 18:40:04 volumiokueche systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dez 29 18:40:07 volumiokueche volumio[4328]: info: BOOT COMPLETED Dez 29 18:40:09 volumiokueche volumio[4328]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dez 29 18:40:09 volumiokueche volumio[4328]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dez 29 18:40:09 volumiokueche volumio[4328]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dez 29 18:40:10 volumiokueche go-librespot[4591]: time="2025-12-29T18:40:10+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)" Dez 29 18:40:10 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dez 29 18:40:10 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dez 29 18:40:13 volumiokueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dez 29 18:40:13 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dez 29 18:40:13 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dez 29 18:40:13 volumiokueche go-librespot[4729]: go-librespot daemon starting... Dez 29 18:40:13 volumiokueche go-librespot[4730]: time="2025-12-29T18:40:13+01:00" level=info msg="running go-librespot 0.4.0" Dez 29 18:40:13 volumiokueche go-librespot[4730]: time="2025-12-29T18:40:13+01:00" level=debug msg="app state loaded" Dez 29 18:40:13 volumiokueche go-librespot[4730]: time="2025-12-29T18:40:13+01:00" level=debug msg="stored credentials not found" Dez 29 18:40:13 volumiokueche go-librespot[4730]: time="2025-12-29T18:40:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dez 29 18:40:20 volumiokueche systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 46512. Dez 29 18:40:20 volumiokueche systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dez 29 18:40:20 volumiokueche systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dez 29 18:40:20 volumiokueche upmpdcli[4750]: Could not open config: /tmp/upmpdcli.conf Dez 29 18:40:20 volumiokueche systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dez 29 18:40:20 volumiokueche systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dez 29 18:40:35 volumiokueche volumio[4328]: info: Discovery: adding 422ee0ea-1eb7-489a-bb07-c7aaf66f374c Dez 29 18:40:35 volumiokueche volumio[4328]: info: Discovery: Found device VolumioKueche Dez 29 18:40:35 volumiokueche volumio[4328]: info: CoreCommandRouter::volumioGetState Dez 29 18:40:35 volumiokueche volumio[4328]: info: CorePlayQueue::getTrack 0 Dez 29 18:40:35 volumiokueche volumio[4328]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dez 29 18:40:35 volumiokueche volumio[4328]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dez 29 18:40:35 volumiokueche volumio[4328]: info: Discovery: this is already registered, 422ee0ea-1eb7-489a-bb07-c7aaf66f374c Dez 29 18:40:35 volumiokueche volumio[4328]: info: Discovery: Found device VolumioKueche Dez 29 18:40:35 volumiokueche volumio[4328]: info: CoreCommandRouter::volumioGetState Dez 29 18:40:35 volumiokueche volumio[4328]: info: CorePlayQueue::getTrack 0 Dez 29 18:40:35 volumiokueche systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 46513. Dez 29 18:40:35 volumiokueche systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dez 29 18:40:35 volumiokueche systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dez 29 18:40:35 volumiokueche upmpdcli[4770]: Could not open config: /tmp/upmpdcli.conf Dez 29 18:40:35 volumiokueche systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dez 29 18:40:35 volumiokueche systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dez 29 18:40:43 volumiokueche go-librespot[4730]: time="2025-12-29T18:40:43+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)" Dez 29 18:40:43 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dez 29 18:40:43 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dez 29 18:40:45 volumiokueche volumio[4328]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.073&uuid=1d9366eec880e287c27d0027ac70ae00" http://updates.volumio.org/downloader-v1/track-device Dez 29 18:40:45 volumiokueche volumio[4328]: % Total % Received % Xferd Average Speed Time Time Time Current Dez 29 18:40:45 volumiokueche volumio[4328]: Dload Upload Total Spent Left Speed Dez 29 18:40:45 volumiokueche volumio[4328]: [4.4K blob data] Dez 29 18:40:45 volumiokueche volumio[4328]: retrying in 5 seconds, trial 0 Dez 29 18:40:45 volumiokueche volumio[4328]: info: Volumio Calling Home Dez 29 18:40:46 volumiokueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dez 29 18:40:46 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dez 29 18:40:46 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dez 29 18:40:46 volumiokueche go-librespot[4792]: go-librespot daemon starting... Dez 29 18:40:46 volumiokueche go-librespot[4793]: time="2025-12-29T18:40:46+01:00" level=info msg="running go-librespot 0.4.0" Dez 29 18:40:46 volumiokueche go-librespot[4793]: time="2025-12-29T18:40:46+01:00" level=debug msg="app state loaded" Dez 29 18:40:46 volumiokueche go-librespot[4793]: time="2025-12-29T18:40:46+01:00" level=debug msg="stored credentials not found" Dez 29 18:40:46 volumiokueche go-librespot[4793]: time="2025-12-29T18:40:46+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dez 29 18:40:50 volumiokueche systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 46514. Dez 29 18:40:50 volumiokueche systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dez 29 18:40:50 volumiokueche systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dez 29 18:40:50 volumiokueche upmpdcli[4814]: Could not open config: /tmp/upmpdcli.conf Dez 29 18:40:50 volumiokueche systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dez 29 18:40:50 volumiokueche systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dez 29 18:41:05 volumiokueche systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 46515. Dez 29 18:41:05 volumiokueche systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dez 29 18:41:05 volumiokueche systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dez 29 18:41:05 volumiokueche upmpdcli[4832]: Could not open config: /tmp/upmpdcli.conf Dez 29 18:41:05 volumiokueche systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dez 29 18:41:05 volumiokueche systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dez 29 18:41:16 volumiokueche volumio[4328]: info: CoreCommandRouter::volumioGetState Dez 29 18:41:16 volumiokueche volumio[4328]: info: CorePlayQueue::getTrack 0 Dez 29 18:41:16 volumiokueche volumio[4328]: info: [jellyfin-poller] Polled http://yggdrasil.lan:8096: offline Dez 29 18:41:16 volumiokueche volumio[4328]: error: FusionDsp - Reload WebSocket error: [object Object] Dez 29 18:41:16 volumiokueche go-librespot[4793]: time="2025-12-29T18:41:16+01:00" level=debug msg="new websocket client" Dez 29 18:41:16 volumiokueche volumio[4328]: info: Connection to go-librespot Websocket established Dez 29 18:41:16 volumiokueche go-librespot[4793]: time="2025-12-29T18:41:16+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)" Dez 29 18:41:16 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dez 29 18:41:16 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dez 29 18:41:16 volumiokueche volumio[4328]: info: Connection to go-librespot Websocket closed Dez 29 18:41:19 volumiokueche volumio[4328]: info: Getting Spotify volume Dez 29 18:41:19 volumiokueche volumio[4328]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dez 29 18:41:19 volumiokueche volumio[4328]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dez 29 18:41:19 volumiokueche volumio[4328]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dez 29 18:41:19 volumiokueche volumio[4328]: errno: -111, Dez 29 18:41:19 volumiokueche volumio[4328]: code: 'ECONNREFUSED', Dez 29 18:41:19 volumiokueche volumio[4328]: syscall: 'connect', Dez 29 18:41:19 volumiokueche volumio[4328]: address: '127.0.0.1', Dez 29 18:41:19 volumiokueche volumio[4328]: port: 9879, Dez 29 18:41:19 volumiokueche volumio[4328]: response: undefined Dez 29 18:41:19 volumiokueche volumio[4328]: } Dez 29 18:41:19 volumiokueche volumio[4328]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dez 29 18:41:20 volumiokueche sudo[4877]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-29 18:40' Dez 29 18:41:20 volumiokueche sudo[4877]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"