Apr 03 02:49:03 volumio volumio[21499]: error: MyVolumio Plugin failed to start in a timely fashion Apr 03 02:49:03 volumio volumio[21499]: [Metrics] CommandRouter: 22s 912.18ms Apr 03 02:49:03 volumio volumio[21499]: info: CoreCommandRouter::volumiosetStartupVolume Apr 03 02:49:03 volumio volumio[21499]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 02:49:04 volumio volumio[21499]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 03 02:49:04 volumio volumio[21499]: info: CoreCommandRouter::Close All Modals sent Apr 03 02:49:04 volumio volumio[21499]: info: CoreCommandRouter::Close All Modals sent Apr 03 02:49:04 volumio volumio[21499]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Apr 03 02:49:04 volumio volumio[21499]: ALSA lib confmisc.c:165:(snd_config_get_card) Cannot get card index for C20 Apr 03 02:49:04 volumio volumio[21499]: aplay: main:831: audio open error: No such device Apr 03 02:49:05 volumio volumio[21499]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 03 02:49:05 volumio volumio[21499]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 03 02:49:05 volumio volumio[21499]: info: CoreCommandRouter::executeOnPlugin: raat , onStop Apr 03 02:49:05 volumio volumio[21499]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 03 02:49:06 volumio volumiossh-tunnel[21472]: ssh: Could not resolve hostname us2.myvolumio.org: Device or resource busy Apr 03 02:49:06 volumio autossh[27212]: ssh exited with error status 255; restarting ssh Apr 03 02:49:06 volumio autossh[27212]: starting ssh (count 65) Apr 03 02:49:06 volumio autossh[27212]: ssh child pid is 21782 Apr 03 02:49:11 volumio volumio[21499]: info: BOOT COMPLETED Apr 03 02:49:11 volumio volumio[21499]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo ENOTFOUND oauth-performer.prod.vlmapi.io Apr 03 02:49:11 volumio go-librespot[21680]: time="2026-04-03T02:49:11-07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Apr 03 02:49:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 03 02:49:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 03 02:49:13 volumio volumio[21499]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 03 02:49:13 volumio volumio[21499]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 03 02:49:13 volumio volumio[21499]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 03 02:49:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Apr 03 02:49:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 03 02:49:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 03 02:49:14 volumio go-librespot[21801]: go-librespot daemon starting... Apr 03 02:49:14 volumio go-librespot[21802]: time="2026-04-03T02:49:14-07:00" level=info msg="running go-librespot 0.6.2" Apr 03 02:49:14 volumio go-librespot[21802]: time="2026-04-03T02:49:14-07:00" level=debug msg="app state loaded" Apr 03 02:49:14 volumio go-librespot[21802]: time="2026-04-03T02:49:14-07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 03 02:49:21 volumio volumio[21499]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.096&uuid=468505faa19c9a74fad43c86a61e1fe3" http://updates.volumio.org/downloader-v1/track-device Apr 03 02:49:21 volumio volumio[21499]: % Total % Received % Xferd Average Speed Time Time Time Current Apr 03 02:49:21 volumio volumio[21499]: Dload Upload Total Spent Left Speed Apr 03 02:49:21 volumio volumio[21499]: [2.2K blob data] Apr 03 02:49:21 volumio volumio[21499]: retrying in 5 seconds, trial 0 Apr 03 02:49:21 volumio volumio[21499]: info: Volumio Calling Home Apr 03 02:49:34 volumio volumiossh-tunnel[21782]: ssh: Could not resolve hostname us2.myvolumio.org: Device or resource busy Apr 03 02:49:34 volumio autossh[27212]: ssh exited with error status 255; restarting ssh Apr 03 02:49:36 volumio autossh[27212]: starting ssh (count 66) Apr 03 02:49:36 volumio autossh[27212]: ssh child pid is 21844 Apr 03 02:49:42 volumio go-librespot[21802]: time="2026-04-03T02:49:42-07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Apr 03 02:49:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 03 02:49:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 03 02:49:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Apr 03 02:49:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 03 02:49:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 03 02:49:46 volumio go-librespot[21860]: go-librespot daemon starting... Apr 03 02:49:46 volumio go-librespot[21861]: time="2026-04-03T02:49:46-07:00" level=info msg="running go-librespot 0.6.2" Apr 03 02:49:46 volumio go-librespot[21861]: time="2026-04-03T02:49:46-07:00" level=debug msg="app state loaded" Apr 03 02:49:46 volumio go-librespot[21861]: time="2026-04-03T02:49:46-07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 03 02:49:59 volumio volumio[21499]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.096&uuid=468505faa19c9a74fad43c86a61e1fe3" http://updates.volumio.org/downloader-v1/track-device Apr 03 02:49:59 volumio volumio[21499]: % Total % Received % Xferd Average Speed Time Time Time Current Apr 03 02:49:59 volumio volumio[21499]: Dload Upload Total Spent Left Speed Apr 03 02:49:59 volumio volumio[21499]: [2.2K blob data] Apr 03 02:49:59 volumio volumio[21499]: retrying in 5 seconds, trial 1 Apr 03 02:49:59 volumio volumio[21499]: info: Volumio Calling Home Apr 03 02:50:04 volumio volumiossh-tunnel[21844]: ssh: Could not resolve hostname us2.myvolumio.org: Device or resource busy Apr 03 02:50:04 volumio autossh[27212]: ssh exited with error status 255; restarting ssh Apr 03 02:50:12 volumio volumio[21499]: info: Discovery: adding e2dc7818-f466-4fa9-8571-fc8bdae77f54 Apr 03 02:50:12 volumio volumio[21499]: info: Discovery: Found device Volumio Apr 03 02:50:12 volumio volumio[21499]: info: CoreCommandRouter::volumioGetState Apr 03 02:50:12 volumio volumio[21499]: info: CorePlayQueue::getTrack 0 Apr 03 02:50:12 volumio go-librespot[21861]: time="2026-04-03T02:50:12-07:00" level=debug msg="new websocket client" Apr 03 02:50:12 volumio volumio[21499]: info: Connection to go-librespot Websocket established Apr 03 02:50:12 volumio autossh[27212]: starting ssh (count 67) Apr 03 02:50:12 volumio autossh[27212]: ssh child pid is 21922 Apr 03 02:50:12 volumio volumio[21499]: info: Discovery: this is already registered, e2dc7818-f466-4fa9-8571-fc8bdae77f54 Apr 03 02:50:12 volumio volumio[21499]: info: Discovery: Found device Volumio Apr 03 02:50:12 volumio volumio[21499]: info: CoreCommandRouter::volumioGetState Apr 03 02:50:12 volumio volumio[21499]: info: CorePlayQueue::getTrack 0 Apr 03 02:50:12 volumio volumiossh-tunnel[21922]: Warning: Permanently added '[us2.myvolumio.org]:2222' (RSA) to the list of known hosts. Apr 03 02:50:12 volumio volumiossh-tunnel[21922]: Warning: remote port forwarding failed for listen port 8091 Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 03 02:50:13 volumio volumio[21499]: info: Adding plugin bluetooth to MyMusic Plugins Apr 03 02:50:13 volumio volumio[21499]: info: Adding plugin multiroom to MyMusic Plugins Apr 03 02:50:13 volumio volumio[21499]: info: Adding plugin metavolumio to MyMusic Plugins Apr 03 02:50:13 volumio volumio[21499]: info: Adding plugin cd_controller to MyMusic Plugins Apr 03 02:50:13 volumio volumio[21499]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 03 02:50:13 volumio volumio[21499]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 03 02:50:13 volumio volumio[21499]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 03 02:50:13 volumio volumio[21499]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 03 02:50:13 volumio volumio[21499]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 03 02:50:13 volumio volumio[21499]: info: Starting MyVolumio Remote Streaming Endpoints Apr 03 02:50:13 volumio volumio[21499]: info: MyVolumio login type: Token Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 03 02:50:13 volumio volumio[21499]: info: Streaming services startup Apr 03 02:50:13 volumio volumio[21499]: info: Starting Streaming Daemon Apr 03 02:50:13 volumio sudo[21924]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 03 02:50:13 volumio sudo[21924]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 03 02:50:13 volumio volumio[21499]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 03 02:50:13 volumio sudo[21924]: pam_unix(sudo:session): session closed for user root Apr 03 02:50:13 volumio volumio[21499]: error: Cannot start Volumio Streaming Daemon Apr 03 02:50:13 volumio volumio[21499]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 03 02:50:13 volumio volumio[21499]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 03 02:50:13 volumio volumio[21499]: info: Volumio called home Apr 03 02:50:13 volumio volumio[21499]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Apr 03 02:50:14 volumio go-librespot[21861]: time="2026-04-03T02:50:14-07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Apr 03 02:50:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 03 02:50:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 03 02:50:14 volumio volumio[21499]: info: Connection to go-librespot Websocket closed Apr 03 02:50:14 volumio volumio[21499]: error: MyVolumio Custom Token format not valid, refreshing it Apr 03 02:50:14 volumio volumio[21499]: info: MyVolumio login type: Token Apr 03 02:50:14 volumio volumio[21499]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 03 02:50:15 volumio volumio[21499]: info: Getting Spotify volume Apr 03 02:50:15 volumio volumio[21499]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 03 02:50:15 volumio volumio[21499]: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 03 02:50:15 volumio volumio[21499]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 03 02:50:15 volumio volumio[21499]: errno: -111, Apr 03 02:50:15 volumio volumio[21499]: code: 'ECONNREFUSED', Apr 03 02:50:15 volumio volumio[21499]: syscall: 'connect', Apr 03 02:50:15 volumio volumio[21499]: address: '127.0.0.1', Apr 03 02:50:15 volumio volumio[21499]: port: 9879, Apr 03 02:50:15 volumio volumio[21499]: response: undefined Apr 03 02:50:15 volumio volumio[21499]: } Apr 03 02:50:15 volumio volumio[21499]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 03 02:50:15 volumio sudo[21945]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-03 02:49' Apr 03 02:50:15 volumio sudo[21945]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"