Jul 04 12:26:00 volumio2 dhcpcd[871]: eth0: probing for an IPv4LL address Jul 04 12:26:00 volumio2 dbus-daemon[1480]: [session uid=0 pid=1478] Activating service name='org.freedesktop.Notifications' requested by ':1.3' (uid=0 pid=1505 comm="/usr/lib/chromium/chromium --show-component-extens") Jul 04 12:26:00 volumio2 dbus-daemon[1480]: [session uid=0 pid=1478] Activating service name='org.xfce.Xfconf' requested by ':1.5' (uid=0 pid=1877 comm="/usr/lib/x86_64-linux-gnu/xfce4/notifyd/xfce4-noti") Jul 04 12:26:00 volumio2 dbus-daemon[1480]: [session uid=0 pid=1478] Successfully activated service 'org.xfce.Xfconf' Jul 04 12:26:00 volumio2 volumio[1122]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 04 12:26:00 volumio2 volumio[1122]: info: Discovery: Getting this device information Jul 04 12:26:00 volumio2 volumio[1122]: info: CoreCommandRouter::volumioGetState Jul 04 12:26:00 volumio2 volumio[1122]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:00 volumio2 volumio[1122]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 04 12:26:00 volumio2 xfce4-notifyd[1877]: AT-SPI: Error retrieving accessibility bus address: org.freedesktop.DBus.Error.ServiceUnknown: The name org.a11y.Bus was not provided by any .service files Jul 04 12:26:00 volumio2 dbus-daemon[1480]: [session uid=0 pid=1478] Successfully activated service 'org.freedesktop.Notifications' Jul 04 12:26:01 volumio2 mpd[1773]: 2025-07-04T12:26:01 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 04 12:26:01 volumio2 systemd[1]: Started mpd.service - Music Player Daemon. Jul 04 12:26:01 volumio2 sudo[1640]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:01 volumio2 sudo[1630]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:01 volumio2 sudo[1732]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:01 volumio2 volumio[1122]: info: Completed starting Core Plugins Jul 04 12:26:01 volumio2 volumio[1122]: info: ------------------------------------------- Jul 04 12:26:01 volumio2 volumio[1122]: info: ----- MyVolumio plugins startup ---- Jul 04 12:26:01 volumio2 volumio[1122]: info: ------------------------------------------- Jul 04 12:26:01 volumio2 volumio[1122]: info: [MyVolumio PluginManager] Fetching plans data.... Jul 04 12:26:01 volumio2 volumio[1122]: error: MPD error: The expression evaluated to a falsy value: Jul 04 12:26:01 volumio2 volumio[1122]: assert.ok(self.idling) Jul 04 12:26:01 volumio2 volumio[1122]: error: The expression evaluated to a falsy value: Jul 04 12:26:01 volumio2 volumio[1122]: assert.ok(self.idling) Jul 04 12:26:01 volumio2 volumio[1122]: error: MPD error: The expression evaluated to a falsy value: Jul 04 12:26:01 volumio2 volumio[1122]: assert.ok(self.idling) Jul 04 12:26:01 volumio2 volumio[1122]: error: The expression evaluated to a falsy value: Jul 04 12:26:01 volumio2 volumio[1122]: assert.ok(self.idling) Jul 04 12:26:01 volumio2 volumio[1122]: info: MPD running with PID1773 Jul 04 12:26:01 volumio2 volumio[1122]: ,establishing connection Jul 04 12:26:01 volumio2 volumio[1122]: error: updateQueue error: null Jul 04 12:26:01 volumio2 volumio[1122]: error: updateQueue error: null Jul 04 12:26:01 volumio2 volumio[1122]: error: [now-playing] API endpoint unsplash/getRandomPhoto returned error: TypeError: fetch failed Jul 04 12:26:01 volumio2 volumio[1122]: at Object.fetch (node:internal/deps/undici/undici:11576:11) Jul 04 12:26:01 volumio2 volumio[1122]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Jul 04 12:26:01 volumio2 volumio[1122]: at async doFetch (/data/plugins/user_interface/now_playing/dist/lib/api/UnsplashAPI.js:13:26) Jul 04 12:26:01 volumio2 volumio[1122]: at async UnsplashAPI.getRandomPhoto (/data/plugins/user_interface/now_playing/dist/lib/api/UnsplashAPI.js:31:28) Jul 04 12:26:01 volumio2 volumio[1122]: at async Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:116:28) Jul 04 12:26:01 volumio2 volumio[1122]: info: camilladsp service started and running in background, instance 1 Jul 04 12:26:01 volumio2 volumio[1122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:01 volumio2 volumio[1122]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 176400 192000 384000 768000 <-AAAAAAAAAAAAA Jul 04 12:26:01 volumio2 volumio[1122]: info: FusionDsp loaded Jul 04 12:26:01 volumio2 volumio[1122]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 04 12:26:01 volumio2 volumio[1122]: info: FusionDsp - Reporting Fusion DSP Enabled Jul 04 12:26:01 volumio2 volumio[1122]: info: Adding Signal Path Element [object Object] Jul 04 12:26:01 volumio2 volumio[1122]: info: Adding fusiondspeq DSP Signal Path Element Jul 04 12:26:01 volumio2 volumio[1122]: info: FusionDsp - ---- installed callbackRead Jul 04 12:26:01 volumio2 sudo[1941]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jul 04 12:26:01 volumio2 sudo[1941]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:01 volumio2 volumio[1122]: info: FusionDsp - File size found in array! Jul 04 12:26:01 volumio2 systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Jul 04 12:26:01 volumio2 volumio[1122]: info: [now-playing] Fetching API key... Jul 04 12:26:01 volumio2 sudo[1941]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:01 volumio2 volumio[1122]: error: [now-playing] Error fetching https://openweathermap.org: TypeError: fetch failed Jul 04 12:26:01 volumio2 volumio[1122]: at Object.fetch (node:internal/deps/undici/undici:11576:11) Jul 04 12:26:01 volumio2 volumio[1122]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Jul 04 12:26:01 volumio2 volumio[1122]: at async fetchPage (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:25:26) Jul 04 12:26:01 volumio2 volumio[1122]: at async doGet (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:118:22) Jul 04 12:26:01 volumio2 volumio[1122]: error: [now-playing] Caught error in callback of WeatherAPI.#getFetchPromise(): fetch failed Jul 04 12:26:01 volumio2 volumio[1122]: error: [now-playing] API endpoint weather/fetchInfo returned error: Error: Could not fetch weather: fetch failed Jul 04 12:26:01 volumio2 volumio[1122]: at WeatherAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/WeatherAPI.js:103:19) Jul 04 12:26:01 volumio2 volumio[1122]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Jul 04 12:26:01 volumio2 volumio[1122]: at async Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:116:28) Jul 04 12:26:01 volumio2 volumio[1122]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Jul 04 12:26:01 volumio2 volumio[1122]: error: FusionDsp - Reload WebSocket error: [object Object] Jul 04 12:26:01 volumio2 volumio[1122]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Jul 04 12:26:01 volumio2 volumio[1122]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Jul 04 12:26:02 volumio2 dhcpcd[826]: eth0: probing for an IPv4LL address Jul 04 12:26:02 volumio2 sh[822]: eth0: probing for an IPv4LL address Jul 04 12:26:02 volumio2 volumio[1122]: info: Listing playlists Jul 04 12:26:02 volumio2 volumio[1122]: info: CoreCommandRouter::volumioGetQueue Jul 04 12:26:02 volumio2 volumio[1122]: info: CoreStateMachine::getQueue Jul 04 12:26:02 volumio2 volumio[1122]: info: CorePlayQueue::getQueue Jul 04 12:26:02 volumio2 volumio[1122]: info: CoreCommandRouter::volumioGetVisibleSources Jul 04 12:26:02 volumio2 volumio[1122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 04 12:26:02 volumio2 volumio[1122]: info: CoreCommandRouter::volumioGetState Jul 04 12:26:02 volumio2 volumio[1122]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:02 volumio2 volumio[1122]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 12:26:02 volumio2 volumio[1122]: info: [now-playing] Fetch metadata (DefaultMetadataProvider): {"type":"song","name":"Unspoken","artist":"Four Tet","album":"Rounds","duration":"571","uri":"qobuz://song/9123142","service":""} Jul 04 12:26:02 volumio2 volumio[1122]: info: [now-playing] LRCLIB getLyrics(): song: "Unspoken" album: "Rounds" artist: "Four Tet" duration: "571" Jul 04 12:26:02 volumio2 volumio[1122]: info: [now-playing] LRCLIB getLyrics() API URL: https://lrclib.net/api/get?track_name=Unspoken&artist_name=Four+Tet&album_name=Rounds&duration=571 Jul 04 12:26:02 volumio2 volumio[1122]: error: [now-playing] Error fetching lyrics from LRCLIB (URL: https://lrclib.net/api/get?track_name=Unspoken&artist_name=Four+Tet&album_name=Rounds&duration=571): TypeError: fetch failed Jul 04 12:26:02 volumio2 volumio[1122]: at Object.fetch (node:internal/deps/undici/undici:11576:11) Jul 04 12:26:02 volumio2 volumio[1122]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Jul 04 12:26:02 volumio2 volumio[1122]: at async apiGet (/data/plugins/user_interface/now_playing/dist/lib/api/lrclib/index.js:16:26) Jul 04 12:26:02 volumio2 volumio[1122]: at async LRCLibAPI.getLyrics (/data/plugins/user_interface/now_playing/dist/lib/api/lrclib/index.js:33:24) Jul 04 12:26:02 volumio2 volumio[1122]: at async DefaultMetadataProvider.getSongInfo (/data/plugins/user_interface/now_playing/dist/lib/api/DefaultMetadataProvider.js:62:37) Jul 04 12:26:02 volumio2 volumio[1122]: at async /data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:135:40 Jul 04 12:26:02 volumio2 volumio[1122]: error: [now-playing] Error fetching from Genius: FetchError: request to https://genius.com/api/search/song?q=Unspoken+Four+Tet&per_page=20&page=1 failed, reason: getaddrinfo EBUSY genius.com Jul 04 12:26:02 volumio2 volumio[1122]: at ClientRequest. (/data/plugins/user_interface/now_playing/node_modules/node-fetch/lib/index.js:1501:11) Jul 04 12:26:02 volumio2 volumio[1122]: at ClientRequest.emit (node:events:514:28) Jul 04 12:26:02 volumio2 volumio[1122]: at TLSSocket.socketErrorListener (node:_http_client:495:9) Jul 04 12:26:02 volumio2 volumio[1122]: at TLSSocket.emit (node:events:514:28) Jul 04 12:26:02 volumio2 volumio[1122]: at emitErrorNT (node:internal/streams/destroy:151:8) Jul 04 12:26:02 volumio2 volumio[1122]: at emitErrorCloseNT (node:internal/streams/destroy:116:3) Jul 04 12:26:02 volumio2 volumio[1122]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) Jul 04 12:26:02 volumio2 volumio[1122]: error: [now-playing] Caught error in callback of MetdataAPI.#getFetchPromise(): request to https://genius.com/api/search/song?q=Unspoken+Four+Tet&per_page=20&page=1 failed, reason: getaddrinfo EBUSY genius.com Jul 04 12:26:02 volumio2 volumio[1122]: error: [now-playing] API endpoint metadata/fetchInfo returned error: Error: Could not fetch info: request to https://genius.com/api/search/song?q=Unspoken+Four+Tet&per_page=20&page=1 failed, reason: getaddrinfo EBUSY genius.com Jul 04 12:26:02 volumio2 volumio[1122]: at MetadataAPI._MetadataAPI_doFetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:180:15) Jul 04 12:26:02 volumio2 volumio[1122]: at async MetadataAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:52:36) Jul 04 12:26:02 volumio2 volumio[1122]: at async Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:116:28) Jul 04 12:26:02 volumio2 volumio[1122]: info: go-librespot daemon successfully initialized Jul 04 12:26:02 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jul 04 12:26:02 volumio2 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jul 04 12:26:02 volumio2 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jul 04 12:26:02 volumio2 go-librespot[1956]: go-librespot daemon starting... Jul 04 12:26:02 volumio2 go-librespot[1957]: time="2025-07-04T12:26:02+02:00" level=info msg="running go-librespot 0.2.0" Jul 04 12:26:02 volumio2 go-librespot[1957]: time="2025-07-04T12:26:02+02:00" level=debug msg="app state loaded" Jul 04 12:26:02 volumio2 go-librespot[1957]: time="2025-07-04T12:26:02+02:00" level=debug msg="stored credentials not found" Jul 04 12:26:02 volumio2 go-librespot[1957]: time="2025-07-04T12:26:02+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 04 12:26:03 volumio2 go-librespot[1957]: time="2025-07-04T12:26:03+02: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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 04 12:26:03 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 12:26:03 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 12:26:03 volumio2 kernel: platform USBC000:00: deferred probe pending: (reason unknown) Jul 04 12:26:04 volumio2 dhcpcd[871]: eth0: using IPv4LL address 169.254.110.249 Jul 04 12:26:04 volumio2 avahi-daemon[835]: Joining mDNS multicast group on interface eth0.IPv4 with address 169.254.110.249. Jul 04 12:26:04 volumio2 avahi-daemon[835]: New relevant interface eth0.IPv4 for mDNS. Jul 04 12:26:04 volumio2 avahi-daemon[835]: Registering new address record for 169.254.110.249 on eth0.IPv4. Jul 04 12:26:04 volumio2 dhcpcd[871]: eth0: adding route to 169.254.0.0/16 Jul 04 12:26:04 volumio2 dhcpcd[871]: eth0: adding default route Jul 04 12:26:04 volumio2 systemd[1]: welcome.service: Deactivated successfully. Jul 04 12:26:04 volumio2 systemd[1]: Stopped welcome.service - Show a welcome message on console. Jul 04 12:26:04 volumio2 systemd[1]: Stopping welcome.service - Show a welcome message on console... Jul 04 12:26:04 volumio2 systemd[1]: Starting welcome.service - Show a welcome message on console... Jul 04 12:26:04 volumio2 welcome[1976]: Resolved ip:[1] 169.254.110.249 Jul 04 12:26:04 volumio2 systemd[1]: Finished welcome.service - Show a welcome message on console. Jul 04 12:26:04 volumio2 systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jul 04 12:26:04 volumio2 systemd[1]: Started nmbd.service - Samba NMB Daemon. Jul 04 12:26:04 volumio2 systemd[1]: Starting winbind.service - Samba Winbind Daemon... Jul 04 12:26:05 volumio2 winbindd[1985]: [2025/07/04 12:26:05.114527, 0] ../../source3/winbindd/winbindd.c:1440(main) Jul 04 12:26:05 volumio2 winbindd[1985]: winbindd version 4.17.12-Debian started. Jul 04 12:26:05 volumio2 winbindd[1985]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Jul 04 12:26:05 volumio2 winbindd[1985]: [2025/07/04 12:26:05.120136, 0] ../../source3/winbindd/winbindd_cache.c:3117(initialize_winbindd_cache) Jul 04 12:26:05 volumio2 winbindd[1985]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jul 04 12:26:05 volumio2 systemd[1]: Started winbind.service - Samba Winbind Daemon. Jul 04 12:26:05 volumio2 systemd[1]: Starting smbd.service - Samba SMB Daemon... Jul 04 12:26:05 volumio2 smbd[1992]: [2025/07/04 12:26:05.300996, 0] ../../source3/smbd/server.c:1741(main) Jul 04 12:26:05 volumio2 smbd[1992]: smbd version 4.17.12-Debian started. Jul 04 12:26:05 volumio2 smbd[1992]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Jul 04 12:26:05 volumio2 systemd[1]: Started smbd.service - Samba SMB Daemon. Jul 04 12:26:05 volumio2 systemd[1]: Reached target multi-user.target - Multi-User System. Jul 04 12:26:05 volumio2 systemd[1]: Reached target graphical.target - Graphical Interface. Jul 04 12:26:05 volumio2 systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Jul 04 12:26:05 volumio2 systemd[1]: Started unclutter.service - Start unclutter-xfixes to hide mouse pointer. Jul 04 12:26:05 volumio2 unclutter-xfixes[2011]: Authorization required, but no authorization protocol specified Jul 04 12:26:05 volumio2 unclutter-xfixes[2011]: [src/util.c:5] ERROR: Received error: Failed to connect to the X server. Jul 04 12:26:05 volumio2 unclutter-xfixes[2011]: unclutter-xfixes: Failed to connect to the X server. Jul 04 12:26:05 volumio2 systemd[1]: unclutter.service: Main process exited, code=exited, status=1/FAILURE Jul 04 12:26:05 volumio2 systemd[1]: unclutter.service: Failed with result 'exit-code'. Jul 04 12:26:05 volumio2 systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Jul 04 12:26:05 volumio2 systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Jul 04 12:26:05 volumio2 systemd[1]: Startup finished in 11.320s (firmware) + 2.610s (loader) + 8.939s (kernel) + 15.399s (userspace) = 38.269s. Jul 04 12:26:05 volumio2 volumio[1122]: info: Initializing connection to go-librespot Websocket Jul 04 12:26:05 volumio2 volumio[1122]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 12:26:05 volumio2 ntpd[1305]: IO: Listen normally on 3 eth0 169.254.110.249:123 Jul 04 12:26:05 volumio2 ntpd[1305]: IO: new interface(s) found: waking up resolver Jul 04 12:26:05 volumio2 ntpd[1305]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Jul 04 12:26:05 volumio2 systemd[1]: unclutter.service: Scheduled restart job, restart counter is at 1. Jul 04 12:26:05 volumio2 systemd[1]: Stopped unclutter.service - Start unclutter-xfixes to hide mouse pointer. Jul 04 12:26:05 volumio2 systemd[1]: Started unclutter.service - Start unclutter-xfixes to hide mouse pointer. Jul 04 12:26:05 volumio2 unclutter-xfixes[2014]: Authorization required, but no authorization protocol specified Jul 04 12:26:05 volumio2 unclutter-xfixes[2014]: [src/util.c:5] ERROR: Received error: Failed to connect to the X server. Jul 04 12:26:05 volumio2 unclutter-xfixes[2014]: unclutter-xfixes: Failed to connect to the X server. Jul 04 12:26:05 volumio2 systemd[1]: unclutter.service: Main process exited, code=exited, status=1/FAILURE Jul 04 12:26:05 volumio2 systemd[1]: unclutter.service: Failed with result 'exit-code'. Jul 04 12:26:06 volumio2 volumio[1122]: info: Volumio Network Manager: Network status updated: 1 Jul 04 12:26:06 volumio2 sudo[2030]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 04 12:26:06 volumio2 sudo[2030]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:06 volumio2 sudo[2032]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 04 12:26:06 volumio2 sudo[2030]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:06 volumio2 sudo[2032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:06 volumio2 sudo[2032]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:06 volumio2 sudo[2035]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jul 04 12:26:06 volumio2 sudo[2035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:06 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jul 04 12:26:06 volumio2 systemd[1]: unclutter.service: Scheduled restart job, restart counter is at 2. Jul 04 12:26:06 volumio2 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jul 04 12:26:06 volumio2 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jul 04 12:26:06 volumio2 systemd[1]: Stopped unclutter.service - Start unclutter-xfixes to hide mouse pointer. Jul 04 12:26:06 volumio2 go-librespot[2038]: go-librespot daemon starting... Jul 04 12:26:06 volumio2 systemd[1]: Started unclutter.service - Start unclutter-xfixes to hide mouse pointer. Jul 04 12:26:06 volumio2 unclutter-xfixes[2040]: Authorization required, but no authorization protocol specified Jul 04 12:26:06 volumio2 unclutter-xfixes[2040]: [src/util.c:5] ERROR: Received error: Failed to connect to the X server. Jul 04 12:26:06 volumio2 unclutter-xfixes[2040]: unclutter-xfixes: Failed to connect to the X server. Jul 04 12:26:06 volumio2 go-librespot[2039]: time="2025-07-04T12:26:06+02:00" level=info msg="running go-librespot 0.2.0" Jul 04 12:26:06 volumio2 go-librespot[2039]: time="2025-07-04T12:26:06+02:00" level=debug msg="app state loaded" Jul 04 12:26:06 volumio2 go-librespot[2039]: time="2025-07-04T12:26:06+02:00" level=debug msg="stored credentials not found" Jul 04 12:26:06 volumio2 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jul 04 12:26:06 volumio2 systemd[1]: unclutter.service: Main process exited, code=exited, status=1/FAILURE Jul 04 12:26:06 volumio2 go-librespot[2039]: time="2025-07-04T12:26:06+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 04 12:26:06 volumio2 systemd[1]: unclutter.service: Failed with result 'exit-code'. Jul 04 12:26:06 volumio2 sudo[2035]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:06 volumio2 volumio[1122]: info: Upmpdcli Daemon Started Jul 04 12:26:06 volumio2 volumio[1122]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jul 04 12:26:06 volumio2 systemd[1]: unclutter.service: Scheduled restart job, restart counter is at 3. Jul 04 12:26:06 volumio2 systemd[1]: Stopped unclutter.service - Start unclutter-xfixes to hide mouse pointer. Jul 04 12:26:06 volumio2 systemd[1]: Started unclutter.service - Start unclutter-xfixes to hide mouse pointer. Jul 04 12:26:06 volumio2 unclutter-xfixes[2064]: Authorization required, but no authorization protocol specified Jul 04 12:26:06 volumio2 unclutter-xfixes[2064]: [src/util.c:5] ERROR: Received error: Failed to connect to the X server. Jul 04 12:26:06 volumio2 unclutter-xfixes[2064]: unclutter-xfixes: Failed to connect to the X server. Jul 04 12:26:06 volumio2 systemd[1]: unclutter.service: Main process exited, code=exited, status=1/FAILURE Jul 04 12:26:06 volumio2 systemd[1]: unclutter.service: Failed with result 'exit-code'. Jul 04 12:26:06 volumio2 systemd[1]: unclutter.service: Scheduled restart job, restart counter is at 4. Jul 04 12:26:06 volumio2 systemd[1]: Stopped unclutter.service - Start unclutter-xfixes to hide mouse pointer. Jul 04 12:26:06 volumio2 systemd[1]: Started unclutter.service - Start unclutter-xfixes to hide mouse pointer. Jul 04 12:26:06 volumio2 unclutter-xfixes[2065]: Authorization required, but no authorization protocol specified Jul 04 12:26:06 volumio2 unclutter-xfixes[2065]: [src/util.c:5] ERROR: Received error: Failed to connect to the X server. Jul 04 12:26:06 volumio2 unclutter-xfixes[2065]: unclutter-xfixes: Failed to connect to the X server. Jul 04 12:26:06 volumio2 systemd[1]: unclutter.service: Main process exited, code=exited, status=1/FAILURE Jul 04 12:26:06 volumio2 systemd[1]: unclutter.service: Failed with result 'exit-code'. Jul 04 12:26:07 volumio2 dhcpcd[826]: eth0: using IPv4LL address 169.254.110.249 Jul 04 12:26:07 volumio2 sh[822]: eth0: using IPv4LL address 169.254.110.249 Jul 04 12:26:07 volumio2 sh[822]: eth0: adding route to 169.254.0.0/16 Jul 04 12:26:07 volumio2 sh[822]: eth0: adding default route Jul 04 12:26:07 volumio2 dhcpcd[826]: eth0: adding route to 169.254.0.0/16 Jul 04 12:26:07 volumio2 dhcpcd[826]: eth0: adding default route Jul 04 12:26:07 volumio2 sh[822]: forked to background, child pid 825 Jul 04 12:26:07 volumio2 systemd[1]: unclutter.service: Scheduled restart job, restart counter is at 5. Jul 04 12:26:07 volumio2 systemd[1]: Stopped unclutter.service - Start unclutter-xfixes to hide mouse pointer. Jul 04 12:26:07 volumio2 systemd[1]: unclutter.service: Start request repeated too quickly. Jul 04 12:26:07 volumio2 systemd[1]: unclutter.service: Failed with result 'exit-code'. Jul 04 12:26:07 volumio2 systemd[1]: Failed to start unclutter.service - Start unclutter-xfixes to hide mouse pointer. Jul 04 12:26:07 volumio2 ifplugd(eth0)[1337]: client: ifup: interface eth0 already configured Jul 04 12:26:07 volumio2 sh[2100]: eth0=eth0 Jul 04 12:26:07 volumio2 ifplugd(eth0)[1337]: Program executed successfully. Jul 04 12:26:08 volumio2 volumio[1122]: info: Initializing connection to go-librespot Websocket Jul 04 12:26:08 volumio2 go-librespot[2039]: time="2025-07-04T12:26:08+02:00" level=debug msg="new websocket client" Jul 04 12:26:08 volumio2 volumio[1122]: info: Connection to go-librespot Websocket established Jul 04 12:26:09 volumio2 volumio[1122]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=4.014&uuid=25c24366becc66fc5dbb8e71214777ce" http://updates.volumio.org/downloader-v1/track-device Jul 04 12:26:09 volumio2 volumio[1122]: % Total % Received % Xferd Average Speed Time Time Time Current Jul 04 12:26:09 volumio2 volumio[1122]: Dload Upload Total Spent Left Speed Jul 04 12:26:09 volumio2 volumio[1122]: [132B blob data] Jul 04 12:26:09 volumio2 volumio[1122]: retrying in 5 seconds, trial 0 Jul 04 12:26:09 volumio2 volumio[1122]: info: Volumio Calling Home Jul 04 12:26:10 volumio2 upmpdcli[2108]: writing RSA key Jul 04 12:26:11 volumio2 volumio[1122]: info: Getting Spotify volume Jul 04 12:26:12 volumio2 ntpd[1305]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Jul 04 12:26:12 volumio2 ntpd[1305]: DNS: dns_check: DNS error: -11, System error Jul 04 12:26:12 volumio2 ntpd[1305]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12 Jul 04 12:26:12 volumio2 go-librespot[2039]: time="2025-07-04T12:26:12+02: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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 04 12:26:12 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 12:26:12 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 12:26:12 volumio2 volumio[1122]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 04 12:26:12 volumio2 volumio[1122]: Error: socket hang up Jul 04 12:26:12 volumio2 volumio[1122]: at connResetException (node:internal/errors:720:14) Jul 04 12:26:12 volumio2 volumio[1122]: at Socket.socketOnEnd (node:_http_client:519:23) Jul 04 12:26:12 volumio2 volumio[1122]: at Socket.emit (node:events:526:35) Jul 04 12:26:12 volumio2 volumio[1122]: at endReadableNT (node:internal/streams/readable:1376:12) Jul 04 12:26:12 volumio2 volumio[1122]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jul 04 12:26:12 volumio2 volumio[1122]: code: 'ECONNRESET', Jul 04 12:26:12 volumio2 volumio[1122]: response: undefined Jul 04 12:26:12 volumio2 volumio[1122]: } Jul 04 12:26:12 volumio2 volumio[1122]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 04 12:26:12 volumio2 systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jul 04 12:26:12 volumio2 setdatetime-helper.sh[2114]: Time is already synchronized. Jul 04 12:26:12 volumio2 systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jul 04 12:26:12 volumio2 systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jul 04 12:26:12 volumio2 sudo[2131]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-07-04 12:25' Jul 04 12:26:12 volumio2 sudo[2131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:12 volumio2 sudo[2131]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:12 volumio2 ntpd[1305]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Jul 04 12:26:15 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jul 04 12:26:15 volumio2 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jul 04 12:26:15 volumio2 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jul 04 12:26:15 volumio2 go-librespot[2144]: go-librespot daemon starting... Jul 04 12:26:15 volumio2 go-librespot[2145]: time="2025-07-04T12:26:15+02:00" level=info msg="running go-librespot 0.2.0" Jul 04 12:26:15 volumio2 go-librespot[2145]: time="2025-07-04T12:26:15+02:00" level=debug msg="app state loaded" Jul 04 12:26:15 volumio2 go-librespot[2145]: time="2025-07-04T12:26:15+02:00" level=debug msg="stored credentials not found" Jul 04 12:26:15 volumio2 go-librespot[2145]: time="2025-07-04T12:26:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 04 12:26:15 volumio2 dhcpcd[871]: eth0: carrier lost Jul 04 12:26:15 volumio2 dhcpcd[826]: eth0: carrier lost Jul 04 12:26:15 volumio2 kernel: r8169 0000:01:00.0 eth0: Link is Down Jul 04 12:26:15 volumio2 avahi-daemon[835]: Withdrawing address record for 169.254.110.249 on eth0. Jul 04 12:26:15 volumio2 avahi-daemon[835]: Leaving mDNS multicast group on interface eth0.IPv4 with address 169.254.110.249. Jul 04 12:26:15 volumio2 avahi-daemon[835]: Interface eth0.IPv4 no longer relevant for mDNS. Jul 04 12:26:15 volumio2 dhcpcd[826]: eth0: deleting route to 169.254.0.0/16 Jul 04 12:26:15 volumio2 dhcpcd[826]: eth0: deleting default route Jul 04 12:26:15 volumio2 dhcpcd[871]: eth0: deleting route to 169.254.0.0/16 Jul 04 12:26:15 volumio2 dhcpcd[871]: eth0: deleting default route Jul 04 12:26:15 volumio2 systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jul 04 12:26:15 volumio2 systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jul 04 12:26:15 volumio2 systemd[1]: welcome.service: Deactivated successfully. Jul 04 12:26:15 volumio2 systemd[1]: Stopped welcome.service - Show a welcome message on console. Jul 04 12:26:15 volumio2 systemd[1]: Stopping welcome.service - Show a welcome message on console... Jul 04 12:26:15 volumio2 systemd[1]: Starting welcome.service - Show a welcome message on console... Jul 04 12:26:15 volumio2 welcome[2194]: Resolved ip:[0] Jul 04 12:26:15 volumio2 systemd[1]: Finished welcome.service - Show a welcome message on console. Jul 04 12:26:15 volumio2 systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jul 04 12:26:16 volumio2 ifplugd(eth0)[1337]: Link beat lost. Jul 04 12:26:16 volumio2 ntpd[1305]: IO: Deleting interface #3 eth0, 169.254.110.249#123, interface stats: received=0, sent=0, dropped=0, active_time=11 secs Jul 04 12:26:18 volumio2 dhcpcd[826]: eth0: carrier acquired Jul 04 12:26:18 volumio2 dhcpcd[871]: eth0: carrier acquired Jul 04 12:26:18 volumio2 kernel: r8169 0000:01:00.0 eth0: Link is Up - 1Gbps/Full - flow control rx/tx Jul 04 12:26:18 volumio2 dhcpcd[826]: eth0: IAID e8:42:3c:3a Jul 04 12:26:18 volumio2 dhcpcd[871]: eth0: IAID e8:42:3c:3a Jul 04 12:26:18 volumio2 ifplugd(eth0)[1337]: Link beat detected. Jul 04 12:26:18 volumio2 dhcpcd[871]: eth0: soliciting an IPv6 router Jul 04 12:26:19 volumio2 dhcpcd[826]: eth0: soliciting an IPv6 router Jul 04 12:26:19 volumio2 dhcpcd[826]: eth0: soliciting a DHCP lease Jul 04 12:26:19 volumio2 dhcpcd[871]: eth0: soliciting a DHCP lease Jul 04 12:26:20 volumio2 ntpd[1305]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Jul 04 12:26:20 volumio2 ntpd[1305]: DNS: dns_check: DNS error: -11, System error Jul 04 12:26:20 volumio2 ntpd[1305]: DNS: dns_take_status: 2.debian.pool.ntp.org=>error, 12 Jul 04 12:26:20 volumio2 volumio-remote-updater[844]: [2025-07-04 12:26:20] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jul 04 12:26:20 volumio2 volumio-remote-updater[844]: [2025-07-04 12:26:20] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jul 04 12:26:20 volumio2 systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jul 04 12:26:20 volumio2 systemd[1]: volumio.service: Failed with result 'exit-code'. Jul 04 12:26:20 volumio2 systemd[1]: volumio.service: Consumed 9.109s CPU time. Jul 04 12:26:20 volumio2 systemd[1]: Started dynamicswap.service - dynamicswap service. Jul 04 12:26:20 volumio2 systemd[1]: dynamicswap.service: Deactivated successfully. Jul 04 12:26:20 volumio2 go-librespot[2145]: time="2025-07-04T12:26:20+02: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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 04 12:26:20 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 12:26:20 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 12:26:20 volumio2 systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. Jul 04 12:26:20 volumio2 systemd[1]: Started dynamicswap.service - dynamicswap service. Jul 04 12:26:20 volumio2 systemd[1]: Stopped volumio.service - Volumio Backend Module. Jul 04 12:26:20 volumio2 systemd[1]: volumio.service: Consumed 9.109s CPU time. Jul 04 12:26:20 volumio2 systemd[1]: Started volumio.service - Volumio Backend Module. Jul 04 12:26:20 volumio2 systemd[1]: dynamicswap.service: Deactivated successfully. Jul 04 12:26:20 volumio2 ntpd[1305]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Jul 04 12:26:20 volumio2 ntpd[1305]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Jul 04 12:26:20 volumio2 ntpd[1305]: DNS: dns_check: DNS error: -11, System error Jul 04 12:26:20 volumio2 ntpd[1305]: DNS: dns_take_status: 1.debian.pool.ntp.org=>error, 12 Jul 04 12:26:21 volumio2 volumio[2257]: info: ------------------------------------------- Jul 04 12:26:21 volumio2 volumio[2257]: info: ----- Volumio3 ---- Jul 04 12:26:21 volumio2 volumio[2257]: info: ------------------------------------------- Jul 04 12:26:21 volumio2 volumio[2257]: info: ----- System startup ---- Jul 04 12:26:21 volumio2 volumio[2257]: info: ------------------------------------------- Jul 04 12:26:21 volumio2 volumio[2257]: info: MYVOLUMIO Environment detected Jul 04 12:26:21 volumio2 volumio[2257]: info: Plugin folders cleanup Jul 04 12:26:21 volumio2 volumio[2257]: info: Scanning into folder /volumio/app/plugins/ Jul 04 12:26:21 volumio2 volumio[2257]: info: Scanning category audio_interface Jul 04 12:26:21 volumio2 volumio[2257]: info: Scanning category miscellanea Jul 04 12:26:21 volumio2 volumio[2257]: info: Scanning category music_service Jul 04 12:26:21 volumio2 volumio[2257]: info: Scanning category plugins.json Jul 04 12:26:21 volumio2 volumio[2257]: info: Scanning category system_controller Jul 04 12:26:21 volumio2 volumio[2257]: info: Scanning category user_interface Jul 04 12:26:21 volumio2 volumio[2257]: info: Scanning into folder /data/plugins/ Jul 04 12:26:21 volumio2 volumio[2257]: info: Scanning category audio_interface Jul 04 12:26:21 volumio2 volumio[2257]: info: Scanning category music_service Jul 04 12:26:21 volumio2 volumio[2257]: info: Scanning category user_interface Jul 04 12:26:21 volumio2 volumio[2257]: info: Plugin folders cleanup completed Jul 04 12:26:21 volumio2 volumio[2257]: info: ------------------------------------------- Jul 04 12:26:21 volumio2 volumio[2257]: info: ----- Core plugins startup ---- Jul 04 12:26:21 volumio2 volumio[2257]: info: ------------------------------------------- Jul 04 12:26:21 volumio2 volumio[2257]: info: Loading plugins from folder /volumio/app/plugins/ Jul 04 12:26:21 volumio2 volumio[2257]: info: Adding plugin upnp to MyMusic Plugins Jul 04 12:26:21 volumio2 volumio[2257]: info: Adding plugin airplay_emulation to MyMusic Plugins Jul 04 12:26:21 volumio2 volumio[2257]: info: Adding plugin upnp_browser to MyMusic Plugins Jul 04 12:26:21 volumio2 volumio[2257]: info: Loading plugins from folder /data/plugins/ Jul 04 12:26:21 volumio2 volumio[2257]: info: Loading plugin "system"... Jul 04 12:26:21 volumio2 systemd[1]: systemd-fsckd.service: Deactivated successfully. Jul 04 12:26:21 volumio2 volumio[2257]: info: Loading plugin "appearance"... Jul 04 12:26:21 volumio2 dhcpcd[826]: eth0: offered 192.168.1.106 from 192.168.1.1 Jul 04 12:26:21 volumio2 dhcpcd[871]: eth0: offered 192.168.1.106 from 192.168.1.1 Jul 04 12:26:21 volumio2 dhcpcd[871]: eth0: probing address 192.168.1.106/24 Jul 04 12:26:21 volumio2 dhcpcd[826]: eth0: probing address 192.168.1.106/24 Jul 04 12:26:21 volumio2 volumio[2257]: info: Loading plugin "network"... Jul 04 12:26:21 volumio2 volumio[2257]: info: Refreshing Cached IP Addresses Jul 04 12:26:21 volumio2 sudo[2289]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 04 12:26:21 volumio2 sudo[2289]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:21 volumio2 volumio[2257]: info: Loading plugin "services"... Jul 04 12:26:21 volumio2 sudo[2291]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 04 12:26:21 volumio2 sudo[2289]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:21 volumio2 sudo[2291]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:21 volumio2 sudo[2291]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:21 volumio2 volumio[2257]: info: Loading plugin "alsa_controller"... Jul 04 12:26:21 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 04 12:26:21 volumio2 volumio[2257]: info: Loading plugin "wizard"... Jul 04 12:26:21 volumio2 volumio[2257]: info: Loading plugin "networkfs"... Jul 04 12:26:21 volumio2 volumio[2257]: info: Starting Udev Watcher for removable devices Jul 04 12:26:21 volumio2 volumio[2257]: info: Ignoring mount for partition: boot Jul 04 12:26:21 volumio2 volumio[2257]: info: Ignoring mount for partition: volumio Jul 04 12:26:21 volumio2 volumio[2257]: info: Ignoring mount for partition: volumio_data Jul 04 12:26:21 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 04 12:26:21 volumio2 volumio[2257]: info: Loading plugin "volumio_command_line_client"... Jul 04 12:26:21 volumio2 volumio[2257]: info: Loading plugin "upnp"... Jul 04 12:26:21 volumio2 volumio[2257]: info: [1751624781661] Starting Upmpd Daemon Jul 04 12:26:21 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 04 12:26:21 volumio2 volumio[2257]: info: Loading plugin "my_music"... Jul 04 12:26:21 volumio2 volumio[2257]: info: Loading plugin "mpd"... Jul 04 12:26:21 volumio2 volumio[2257]: info: Loading plugin "upnp_browser"... Jul 04 12:26:21 volumio2 ntpd[1305]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Jul 04 12:26:21 volumio2 ntpd[1305]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Jul 04 12:26:21 volumio2 ntpd[1305]: DNS: dns_check: DNS error: -11, System error Jul 04 12:26:21 volumio2 ntpd[1305]: DNS: dns_take_status: 0.debian.pool.ntp.org=>error, 12 Jul 04 12:26:22 volumio2 volumio[2257]: info: Loading plugin "alarm-clock"... Jul 04 12:26:22 volumio2 volumio[2257]: info: Loading plugin "airplay_emulation"... Jul 04 12:26:22 volumio2 volumio[2257]: info: Starting Shairport Sync Jul 04 12:26:22 volumio2 volumio[2257]: info: Loading plugin "last_100"... Jul 04 12:26:22 volumio2 volumio[2257]: info: Loading plugin "webradio"... Jul 04 12:26:22 volumio2 volumio[2257]: info: Loading plugin "i2s_dacs"... Jul 04 12:26:22 volumio2 volumio[2257]: info: I2S DAC not set, start Auto-detection Jul 04 12:26:22 volumio2 volumio[2257]: info: Loading plugin "volumiodiscovery"... Jul 04 12:26:22 volumio2 volumio[2257]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 04 12:26:22 volumio2 volumio[2257]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 04 12:26:22 volumio2 volumio[2257]: *** WARNING *** For more information see Jul 04 12:26:22 volumio2 volumio[2257]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 04 12:26:22 volumio2 volumio[2257]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 04 12:26:22 volumio2 volumio[2257]: *** WARNING *** For more information see Jul 04 12:26:22 volumio2 node[2257]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 04 12:26:22 volumio2 node[2257]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 04 12:26:22 volumio2 node[2257]: *** WARNING *** For more information see Jul 04 12:26:22 volumio2 node[2257]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 04 12:26:22 volumio2 node[2257]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 04 12:26:22 volumio2 node[2257]: *** WARNING *** For more information see Jul 04 12:26:22 volumio2 volumio[2257]: info: Applying required configuration parameters for plugin volumiodiscovery Jul 04 12:26:22 volumio2 volumio[2257]: info: Discovery: Started advertising with name: Volumio2 Jul 04 12:26:22 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 04 12:26:22 volumio2 volumio[2257]: info: Loading plugin "spop"... Jul 04 12:26:22 volumio2 volumio[2257]: info: Loading plugin "now_playing"... Jul 04 12:26:22 volumio2 systemd[1]: systemd-hostnamed.service: Deactivated successfully. Jul 04 12:26:22 volumio2 volumio[2257]: info: Loading plugin "outputs"... Jul 04 12:26:22 volumio2 volumio[2257]: info: Loading plugin "albumart"... Jul 04 12:26:22 volumio2 volumio[2257]: info: Plugin example_plugin is not enabled Jul 04 12:26:22 volumio2 volumio[2257]: info: Loading plugin "inputs"... Jul 04 12:26:22 volumio2 volumio[2257]: info: Loading plugin "updater_comm"... Jul 04 12:26:23 volumio2 volumio[2257]: info: Plugin mpdemulation is not enabled Jul 04 12:26:23 volumio2 volumio[2257]: info: Loading plugin "rest_api"... Jul 04 12:26:23 volumio2 volumio[2257]: info: Loading plugin "websocket"... Jul 04 12:26:23 volumio2 volumio[2257]: info: Starting Socket.io Server version 1.7.4 Jul 04 12:26:23 volumio2 volumio[2257]: info: Loading plugin "fusiondsp"... Jul 04 12:26:23 volumio2 volumio[2322]: Forking 3 albumart workers Jul 04 12:26:23 volumio2 volumio[2257]: info: Applying required configuration parameters for plugin fusiondsp Jul 04 12:26:23 volumio2 volumio[2257]: info: Loading plugin "Systeminfo"... Jul 04 12:26:23 volumio2 volumio[2332]: Starting albumart workers Jul 04 12:26:23 volumio2 volumio[2257]: info: Loading i18n strings for locale de Jul 04 12:26:23 volumio2 volumio[2257]: Updating browse sources language Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 04 12:26:23 volumio2 volumio[2334]: Starting albumart workers Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::initPlayerControls Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 12:26:23 volumio2 volumio[2257]: Express server listening on port 3000 Jul 04 12:26:23 volumio2 volumio[2257]: [Metrics] WebUI: 2s 518.73ms Jul 04 12:26:23 volumio2 volumio[2257]: info: Setting Device type: x86 Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreStateMachine::resetVolumioState Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreStateMachine::getcurrentVolume Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::volumioRetrievevolume Jul 04 12:26:23 volumio2 volumio[2333]: Starting albumart workers Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreStateMachine::pushState Jul 04 12:26:23 volumio2 volumio[2257]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::volumioPushState Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:23 volumio2 volumio[2257]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Jul 04 12:26:23 volumio2 volumio[2257]: info: Completed loading Core Plugins Jul 04 12:26:23 volumio2 volumio[2257]: info: Preparing to generate the ALSA configuration file Jul 04 12:26:23 volumio2 volumio[2257]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jul 04 12:26:23 volumio2 volumio[2257]: info: Reading ALSA contributions from plugins. Jul 04 12:26:23 volumio2 volumio[2257]: info: Volumio Network Manager: Network status updated: 0 Jul 04 12:26:23 volumio2 volumio[2257]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Jul 04 12:26:23 volumio2 volumio[2257]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Jul 04 12:26:23 volumio2 volumio[2257]: info: Reloading queue from file Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreStateMachine::setRepeat true single undefined Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreStateMachine::pushState Jul 04 12:26:23 volumio2 volumio[2257]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::volumioPushState Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreStateMachine::setRandom null Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreStateMachine::pushState Jul 04 12:26:23 volumio2 volumio[2257]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::volumioPushState Jul 04 12:26:23 volumio2 volumio[2257]: info: Discovery: adding 6b56f2d5-cbd9-4eb4-af79-a9ffa3dae30f Jul 04 12:26:23 volumio2 volumio[2257]: info: Discovery: Found device Volumio2 Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::volumioGetState Jul 04 12:26:23 volumio2 volumio[2257]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:23 volumio2 volumio[2257]: info: Asound.conf file unchanged, so no further update is needed Jul 04 12:26:23 volumio2 volumio[2257]: info: Output device has changed, restarting MPD Jul 04 12:26:23 volumio2 volumio[2257]: info: Output device has changed, restarting Shairport Sync Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:23 volumio2 sudo[2383]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 04 12:26:23 volumio2 sudo[2383]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:23 volumio2 sudo[2383]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:23 volumio2 sudo[2385]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 04 12:26:23 volumio2 sudo[2385]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:23 volumio2 volumio[2257]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 04 12:26:23 volumio2 volumio[2257]: info: ___________ START PLUGINS ___________ Jul 04 12:26:23 volumio2 volumio[2257]: info: ControllerMpd::onStart: Initializing MPD Jul 04 12:26:23 volumio2 volumio[2257]: info: Creating MPD Configuration file Jul 04 12:26:23 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jul 04 12:26:23 volumio2 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jul 04 12:26:23 volumio2 sudo[2393]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 04 12:26:23 volumio2 sudo[2393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:23 volumio2 sudo[2393]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 04 12:26:23 volumio2 volumio[2257]: info: [1751624783697] CoreMusicLibrary::Adding element Medienserver Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 04 12:26:23 volumio2 sudo[2397]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 04 12:26:23 volumio2 sudo[2397]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:23 volumio2 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jul 04 12:26:23 volumio2 go-librespot[2395]: go-librespot daemon starting... Jul 04 12:26:23 volumio2 systemd[1]: Stopping mpd.service - Music Player Daemon... Jul 04 12:26:23 volumio2 go-librespot[2403]: time="2025-07-04T12:26:23+02:00" level=info msg="running go-librespot 0.2.0" Jul 04 12:26:23 volumio2 go-librespot[2403]: time="2025-07-04T12:26:23+02:00" level=debug msg="app state loaded" Jul 04 12:26:23 volumio2 go-librespot[2403]: time="2025-07-04T12:26:23+02:00" level=debug msg="stored credentials not found" Jul 04 12:26:23 volumio2 go-librespot[2403]: time="2025-07-04T12:26:23+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 04 12:26:23 volumio2 volumio[2257]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:23 volumio2 go-librespot[2403]: time="2025-07-04T12:26:23+02: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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 04 12:26:23 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 12:26:23 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 12:26:23 volumio2 volumio[2257]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 04 12:26:23 volumio2 volumio[2257]: info: [1751624783770] CoreMusicLibrary::Adding element Last_100 Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 04 12:26:23 volumio2 volumio[2257]: info: [1751624783772] CoreMusicLibrary::Adding element Webradio Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 04 12:26:23 volumio2 volumio[2257]: info: Initializing BBC Radios Jul 04 12:26:23 volumio2 systemd[1]: mpd.service: Deactivated successfully. Jul 04 12:26:23 volumio2 systemd[1]: Stopped mpd.service - Music Player Daemon. Jul 04 12:26:23 volumio2 systemd[1]: mpd.service: Consumed 1.149s CPU time. Jul 04 12:26:23 volumio2 systemd[1]: mpd.socket: Deactivated successfully. Jul 04 12:26:23 volumio2 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jul 04 12:26:23 volumio2 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:23 volumio2 volumio[2257]: info: Creating Spotify config file Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:23 volumio2 volumio[2257]: info: [now-playing] ConfigUpdater: config is up to date. Jul 04 12:26:23 volumio2 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jul 04 12:26:23 volumio2 volumio[2257]: info: Loading i18n strings for locale de Jul 04 12:26:23 volumio2 systemd[1]: Starting mpd.service - Music Player Daemon... Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jul 04 12:26:23 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:23 volumio2 volumio[2257]: info: FusionDsp - mixtype--------------------- None Jul 04 12:26:23 volumio2 volumio[2257]: info: Volumio Calling Home Jul 04 12:26:23 volumio2 volumio[2257]: info: Preparing to generate the ALSA configuration file Jul 04 12:26:23 volumio2 sudo[2433]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 04 12:26:23 volumio2 sudo[2433]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jul 04 12:26:23 volumio2 sudo[2433]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:23 volumio2 volumio[2257]: info: [now-playing] Fetching API key... Jul 04 12:26:24 volumio2 volumio[2257]: info: [now-playing] App is listening on port 4004. Jul 04 12:26:24 volumio2 volumio[2257]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Jul 04 12:26:24 volumio2 volumio[2257]: Unhandled rejection Error: No sockets available, cannot start. Jul 04 12:26:24 volumio2 volumio[2257]: at SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Jul 04 12:26:24 volumio2 volumio[2257]: at SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Jul 04 12:26:24 volumio2 volumio[2257]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Jul 04 12:26:24 volumio2 volumio[2257]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Jul 04 12:26:24 volumio2 volumio[2257]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Jul 04 12:26:24 volumio2 volumio[2257]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Jul 04 12:26:24 volumio2 volumio[2257]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Jul 04 12:26:24 volumio2 volumio[2257]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Jul 04 12:26:24 volumio2 volumio[2257]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Jul 04 12:26:24 volumio2 volumio[2257]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Jul 04 12:26:24 volumio2 volumio[2257]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Jul 04 12:26:24 volumio2 volumio[2257]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Jul 04 12:26:24 volumio2 volumio[2257]: at proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Jul 04 12:26:24 volumio2 volumio[2257]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Jul 04 12:26:24 volumio2 volumio[2257]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Jul 04 12:26:24 volumio2 volumio[2257]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jul 04 12:26:24 volumio2 volumio[2257]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 04 12:26:24 volumio2 volumio[2257]: info: Discovery: Getting this device information Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::volumioGetState Jul 04 12:26:24 volumio2 volumio[2257]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 04 12:26:24 volumio2 volumio[2257]: info: Listing playlists Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::volumioGetQueue Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreStateMachine::getQueue Jul 04 12:26:24 volumio2 volumio[2257]: info: CorePlayQueue::getQueue Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::volumioGetVisibleSources Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::volumioGetState Jul 04 12:26:24 volumio2 volumio[2257]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:24 volumio2 volumio[2257]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Jul 04 12:26:24 volumio2 volumio[2257]: info: Listing playlists Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::volumioGetQueue Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreStateMachine::getQueue Jul 04 12:26:24 volumio2 volumio[2257]: info: CorePlayQueue::getQueue Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::volumioGetVisibleSources Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::volumioGetState Jul 04 12:26:24 volumio2 volumio[2257]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:24 volumio2 volumio[2257]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jul 04 12:26:24 volumio2 volumio[2257]: info: Reading ALSA contributions from plugins. Jul 04 12:26:24 volumio2 volumio[2257]: error: [now-playing] Error fetching https://openweathermap.org: TypeError: fetch failed Jul 04 12:26:24 volumio2 volumio[2257]: at Object.fetch (node:internal/deps/undici/undici:11576:11) Jul 04 12:26:24 volumio2 volumio[2257]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Jul 04 12:26:24 volumio2 volumio[2257]: at async fetchPage (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:25:26) Jul 04 12:26:24 volumio2 volumio[2257]: at async doGet (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:118:22) Jul 04 12:26:24 volumio2 volumio[2257]: error: [now-playing] Caught error in callback of WeatherAPI.#getFetchPromise(): fetch failed Jul 04 12:26:24 volumio2 volumio[2257]: info: MPD Permissions set Jul 04 12:26:24 volumio2 volumio[2257]: info: MPD Permissions set Jul 04 12:26:24 volumio2 volumio[2257]: info: Spotify config file written Jul 04 12:26:24 volumio2 volumio[2257]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 sudo[2440]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jul 04 12:26:24 volumio2 sudo[2440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jul 04 12:26:24 volumio2 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jul 04 12:26:24 volumio2 go-librespot[2450]: go-librespot daemon starting... Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jul 04 12:26:24 volumio2 sudo[2440]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:24 volumio2 go-librespot[2456]: time="2025-07-04T12:26:24+02:00" level=info msg="running go-librespot 0.2.0" Jul 04 12:26:24 volumio2 go-librespot[2456]: time="2025-07-04T12:26:24+02:00" level=debug msg="app state loaded" Jul 04 12:26:24 volumio2 go-librespot[2456]: time="2025-07-04T12:26:24+02:00" level=debug msg="stored credentials not found" Jul 04 12:26:24 volumio2 go-librespot[2456]: time="2025-07-04T12:26:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 04 12:26:24 volumio2 go-librespot[2456]: time="2025-07-04T12:26:24+02: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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 12:26:24 volumio2 volumio[2257]: info: No need to fix Spotify hosts Jul 04 12:26:24 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 12:26:24 volumio2 volumio[2257]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jul 04 12:26:24 volumio2 volumio[2257]: info: Starting Shairport Sync Jul 04 12:26:24 volumio2 volumio[2257]: info: Starting Shairport Sync Jul 04 12:26:24 volumio2 volumio[2257]: info: Starting Shairport Sync Jul 04 12:26:24 volumio2 sudo[2466]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 04 12:26:24 volumio2 sudo[2466]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:24 volumio2 sudo[2470]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 04 12:26:24 volumio2 sudo[2470]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:24 volumio2 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jul 04 12:26:24 volumio2 volumio[2257]: info: Asound.conf file unchanged, so no further update is needed Jul 04 12:26:24 volumio2 volumio[2257]: info: Output device has changed, restarting MPD Jul 04 12:26:24 volumio2 systemd[1]: shairport-sync.service: Deactivated successfully. Jul 04 12:26:24 volumio2 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jul 04 12:26:24 volumio2 systemd[1]: shairport-sync.service: Consumed 1.695s CPU time. Jul 04 12:26:24 volumio2 sudo[2468]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 04 12:26:24 volumio2 volumio[2257]: info: Output device has changed, restarting Shairport Sync Jul 04 12:26:24 volumio2 sudo[2468]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:24 volumio2 sudo[2476]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 04 12:26:24 volumio2 sudo[2476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:24 volumio2 sudo[2476]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:24 volumio2 sudo[2479]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 04 12:26:24 volumio2 sudo[2479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:24 volumio2 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jul 04 12:26:24 volumio2 sudo[2466]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:24 volumio2 volumio[2257]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 04 12:26:24 volumio2 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jul 04 12:26:24 volumio2 systemd[1]: mpd.service: Deactivated successfully. Jul 04 12:26:24 volumio2 systemd[1]: Stopped mpd.service - Music Player Daemon. Jul 04 12:26:24 volumio2 systemd[1]: shairport-sync.service: Deactivated successfully. Jul 04 12:26:24 volumio2 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jul 04 12:26:24 volumio2 systemd[1]: mpd.socket: Deactivated successfully. Jul 04 12:26:24 volumio2 volumio[2257]: info: MPD Permissions set Jul 04 12:26:24 volumio2 volumio[2257]: info: Shairport-Sync Started Jul 04 12:26:24 volumio2 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jul 04 12:26:24 volumio2 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jul 04 12:26:24 volumio2 volumio[2257]: Error adding Membership: Error: addMembership EINVAL Jul 04 12:26:24 volumio2 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 systemd[1]: Starting mpd.service - Music Player Daemon... Jul 04 12:26:24 volumio2 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jul 04 12:26:24 volumio2 sudo[2470]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:24 volumio2 volumio[2257]: info: CoreCommandRouter::volumioGetState Jul 04 12:26:24 volumio2 volumio[2257]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:24 volumio2 volumio[2257]: info: Shairport-Sync Started Jul 04 12:26:24 volumio2 sudo[2468]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:24 volumio2 volumio[2257]: info: Starting Shairport Sync Jul 04 12:26:24 volumio2 volumio[2257]: info: Shairport-Sync Started Jul 04 12:26:24 volumio2 sudo[2510]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 04 12:26:24 volumio2 sudo[2510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:24 volumio2 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jul 04 12:26:24 volumio2 systemd[1]: shairport-sync.service: Deactivated successfully. Jul 04 12:26:24 volumio2 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jul 04 12:26:24 volumio2 sudo[2488]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 04 12:26:24 volumio2 sudo[2488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jul 04 12:26:24 volumio2 sudo[2488]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:24 volumio2 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jul 04 12:26:24 volumio2 sudo[2510]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:24 volumio2 volumio[2257]: info: Shairport-Sync Started Jul 04 12:26:24 volumio2 mpd[2516]: 2025-07-04T12:26:24 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 04 12:26:24 volumio2 systemd[1]: Started mpd.service - Music Player Daemon. Jul 04 12:26:24 volumio2 sudo[2397]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:24 volumio2 sudo[2479]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:24 volumio2 sudo[2385]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:24 volumio2 volumio[2257]: info: Completed starting Core Plugins Jul 04 12:26:24 volumio2 volumio[2257]: info: ------------------------------------------- Jul 04 12:26:24 volumio2 volumio[2257]: info: ----- MyVolumio plugins startup ---- Jul 04 12:26:24 volumio2 volumio[2257]: info: ------------------------------------------- Jul 04 12:26:24 volumio2 volumio[2257]: info: [MyVolumio PluginManager] Fetching plans data.... Jul 04 12:26:24 volumio2 volumio[2257]: error: MPD error: The expression evaluated to a falsy value: Jul 04 12:26:24 volumio2 volumio[2257]: assert.ok(self.idling) Jul 04 12:26:24 volumio2 volumio[2257]: error: The expression evaluated to a falsy value: Jul 04 12:26:24 volumio2 volumio[2257]: assert.ok(self.idling) Jul 04 12:26:24 volumio2 volumio[2257]: error: MPD error: The expression evaluated to a falsy value: Jul 04 12:26:24 volumio2 volumio[2257]: assert.ok(self.idling) Jul 04 12:26:24 volumio2 volumio[2257]: error: The expression evaluated to a falsy value: Jul 04 12:26:24 volumio2 volumio[2257]: assert.ok(self.idling) Jul 04 12:26:24 volumio2 volumio[2257]: info: MPD running with PID2516 Jul 04 12:26:24 volumio2 volumio[2257]: ,establishing connection Jul 04 12:26:24 volumio2 volumio[2257]: error: MPD error: The expression evaluated to a falsy value: Jul 04 12:26:24 volumio2 volumio[2257]: assert.ok(self.idling) Jul 04 12:26:24 volumio2 volumio[2257]: error: The expression evaluated to a falsy value: Jul 04 12:26:24 volumio2 volumio[2257]: assert.ok(self.idling) Jul 04 12:26:24 volumio2 volumio[2257]: error: updateQueue error: null Jul 04 12:26:25 volumio2 volumio-remote-updater[844]: [2025-07-04 12:26:25] [connect] Successful connection Jul 04 12:26:25 volumio2 volumio-remote-updater[844]: [2025-07-04 12:26:25] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1751624785 101 Jul 04 12:26:25 volumio2 volumio[2257]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 4 Jul 04 12:26:25 volumio2 volumio[2257]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Jul 04 12:26:25 volumio2 volumio[2257]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo Jul 04 12:26:25 volumio2 volumio[2257]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Jul 04 12:26:25 volumio2 volumio[2257]: info: camilladsp service started and running in background, instance 1 Jul 04 12:26:25 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:25 volumio2 volumio[2257]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 176400 192000 384000 768000 <-AAAAAAAAAAAAA Jul 04 12:26:25 volumio2 volumio[2257]: info: FusionDsp loaded Jul 04 12:26:25 volumio2 volumio[2257]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 04 12:26:25 volumio2 volumio[2257]: info: FusionDsp - Reporting Fusion DSP Enabled Jul 04 12:26:25 volumio2 volumio[2257]: info: Adding Signal Path Element [object Object] Jul 04 12:26:25 volumio2 volumio[2257]: info: Adding fusiondspeq DSP Signal Path Element Jul 04 12:26:25 volumio2 volumio[2257]: info: FusionDsp - ---- installed callbackRead Jul 04 12:26:25 volumio2 sudo[2552]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jul 04 12:26:25 volumio2 sudo[2552]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:25 volumio2 volumio[2257]: info: FusionDsp - File size found in array! Jul 04 12:26:25 volumio2 volumio[2257]: error: FusionDsp - Reload WebSocket error: [object Object] Jul 04 12:26:25 volumio2 sudo[2552]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:26 volumio2 dhcpcd[826]: eth0: leased 192.168.1.106 for 86400 seconds Jul 04 12:26:26 volumio2 avahi-daemon[835]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.106. Jul 04 12:26:26 volumio2 dhcpcd[826]: eth0: adding route to 192.168.1.0/24 Jul 04 12:26:26 volumio2 dhcpcd[826]: eth0: adding default route via 192.168.1.1 Jul 04 12:26:26 volumio2 avahi-daemon[835]: New relevant interface eth0.IPv4 for mDNS. Jul 04 12:26:26 volumio2 avahi-daemon[835]: Registering new address record for 192.168.1.106 on eth0.IPv4. Jul 04 12:26:26 volumio2 systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jul 04 12:26:26 volumio2 systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jul 04 12:26:26 volumio2 systemd[1]: welcome.service: Deactivated successfully. Jul 04 12:26:26 volumio2 systemd[1]: Stopped welcome.service - Show a welcome message on console. Jul 04 12:26:26 volumio2 systemd[1]: Stopping welcome.service - Show a welcome message on console... Jul 04 12:26:26 volumio2 systemd[1]: Starting welcome.service - Show a welcome message on console... Jul 04 12:26:26 volumio2 welcome[2571]: Resolved ip:[1] 192.168.1.106 Jul 04 12:26:26 volumio2 systemd[1]: Finished welcome.service - Show a welcome message on console. Jul 04 12:26:26 volumio2 systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jul 04 12:26:26 volumio2 dhcpcd[871]: eth0: leased 192.168.1.106 for 86400 seconds Jul 04 12:26:26 volumio2 dhcpcd[871]: eth0: adding route to 192.168.1.0/24 Jul 04 12:26:26 volumio2 dhcpcd[871]: eth0: adding default route via 192.168.1.1 Jul 04 12:26:26 volumio2 systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jul 04 12:26:26 volumio2 systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jul 04 12:26:26 volumio2 systemd[1]: welcome.service: Deactivated successfully. Jul 04 12:26:26 volumio2 systemd[1]: Stopped welcome.service - Show a welcome message on console. Jul 04 12:26:26 volumio2 systemd[1]: Stopping welcome.service - Show a welcome message on console... Jul 04 12:26:26 volumio2 systemd[1]: Starting welcome.service - Show a welcome message on console... Jul 04 12:26:26 volumio2 welcome[2599]: Resolved ip:[1] 192.168.1.106 Jul 04 12:26:26 volumio2 systemd[1]: Finished welcome.service - Show a welcome message on console. Jul 04 12:26:26 volumio2 systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jul 04 12:26:27 volumio2 volumio[2257]: info: go-librespot daemon successfully initialized Jul 04 12:26:27 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jul 04 12:26:27 volumio2 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jul 04 12:26:27 volumio2 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jul 04 12:26:27 volumio2 go-librespot[2611]: go-librespot daemon starting... Jul 04 12:26:27 volumio2 go-librespot[2612]: time="2025-07-04T12:26:27+02:00" level=info msg="running go-librespot 0.2.0" Jul 04 12:26:27 volumio2 go-librespot[2612]: time="2025-07-04T12:26:27+02:00" level=debug msg="app state loaded" Jul 04 12:26:27 volumio2 go-librespot[2612]: time="2025-07-04T12:26:27+02:00" level=debug msg="stored credentials not found" Jul 04 12:26:27 volumio2 go-librespot[2612]: time="2025-07-04T12:26:27+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 04 12:26:27 volumio2 ntpd[1305]: IO: Listen normally on 4 eth0 192.168.1.106:123 Jul 04 12:26:27 volumio2 ntpd[1305]: IO: new interface(s) found: waking up resolver Jul 04 12:26:27 volumio2 ntpd[1305]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Jul 04 12:26:29 volumio2 volumio[2257]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jul 04 12:26:30 volumio2 volumio[2257]: info: Initializing connection to go-librespot Websocket Jul 04 12:26:30 volumio2 volumio[2257]: info: Connection to go-librespot Websocket established Jul 04 12:26:30 volumio2 go-librespot[2612]: time="2025-07-04T12:26:30+02:00" level=debug msg="new websocket client" Jul 04 12:26:31 volumio2 volumio[2257]: info: Volumio Network Manager: Network status updated: 1 Jul 04 12:26:31 volumio2 sudo[2640]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 04 12:26:31 volumio2 sudo[2640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:31 volumio2 sudo[2642]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 04 12:26:31 volumio2 sudo[2642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:31 volumio2 sudo[2640]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:31 volumio2 sudo[2642]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:31 volumio2 sudo[2645]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jul 04 12:26:31 volumio2 sudo[2645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:31 volumio2 sudo[2645]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:31 volumio2 volumio[2257]: info: Upmpdcli Daemon Started Jul 04 12:26:33 volumio2 volumio[2257]: info: Getting Spotify volume Jul 04 12:26:34 volumio2 volumio[2257]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=4.014&uuid=25c24366becc66fc5dbb8e71214777ce" http://updates.volumio.org/downloader-v1/track-device Jul 04 12:26:34 volumio2 volumio[2257]: % Total % Received % Xferd Average Speed Time Time Time Current Jul 04 12:26:34 volumio2 volumio[2257]: Dload Upload Total Spent Left Speed Jul 04 12:26:34 volumio2 volumio[2257]: [132B blob data] Jul 04 12:26:34 volumio2 volumio[2257]: retrying in 5 seconds, trial 0 Jul 04 12:26:34 volumio2 volumio[2257]: info: Volumio Calling Home Jul 04 12:26:35 volumio2 dhcpcd[826]: eth0: f8:ac:65:c2:27:f2(f8:ac:65:c2:27:f2) claims 192.168.1.106 Jul 04 12:26:35 volumio2 dhcpcd[871]: eth0: f8:ac:65:c2:27:f2(f8:ac:65:c2:27:f2) claims 192.168.1.106 Jul 04 12:26:35 volumio2 dhcpcd[826]: eth0: f8:ac:65:c2:27:f2(f8:ac:65:c2:27:f2) claims 192.168.1.106 Jul 04 12:26:35 volumio2 dhcpcd[826]: eth0: 10 second defence failed for 192.168.1.106 Jul 04 12:26:35 volumio2 dhcpcd[871]: eth0: f8:ac:65:c2:27:f2(f8:ac:65:c2:27:f2) claims 192.168.1.106 Jul 04 12:26:35 volumio2 dhcpcd[871]: eth0: 10 second defence failed for 192.168.1.106 Jul 04 12:26:35 volumio2 dhcpcd[871]: eth0: deleting route to 192.168.1.0/24 Jul 04 12:26:35 volumio2 avahi-daemon[835]: Withdrawing address record for 192.168.1.106 on eth0. Jul 04 12:26:35 volumio2 dhcpcd[871]: eth0: deleting default route via 192.168.1.1 Jul 04 12:26:35 volumio2 avahi-daemon[835]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.1.106. Jul 04 12:26:35 volumio2 avahi-daemon[835]: Interface eth0.IPv4 no longer relevant for mDNS. Jul 04 12:26:35 volumio2 dhcpcd[826]: eth0: deleting route to 192.168.1.0/24 Jul 04 12:26:35 volumio2 dhcpcd[826]: eth0: deleting default route via 192.168.1.1 Jul 04 12:26:35 volumio2 volumio[2257]: info: Discovery: A device disappeared from network Jul 04 12:26:35 volumio2 volumio[2257]: info: Discovery: Device volumio2 disappeared from network Jul 04 12:26:35 volumio2 systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jul 04 12:26:35 volumio2 systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jul 04 12:26:35 volumio2 systemd[1]: welcome.service: Deactivated successfully. Jul 04 12:26:35 volumio2 systemd[1]: Stopped welcome.service - Show a welcome message on console. Jul 04 12:26:35 volumio2 systemd[1]: Stopping welcome.service - Show a welcome message on console... Jul 04 12:26:35 volumio2 dhcpcd[826]: eth0: rebinding lease of 192.168.1.106 Jul 04 12:26:35 volumio2 dhcpcd[871]: eth0: rebinding lease of 192.168.1.106 Jul 04 12:26:35 volumio2 dhcpcd[826]: eth0: probing address 192.168.1.106/24 Jul 04 12:26:35 volumio2 systemd[1]: Starting welcome.service - Show a welcome message on console... Jul 04 12:26:35 volumio2 dhcpcd[871]: eth0: probing address 192.168.1.106/24 Jul 04 12:26:35 volumio2 welcome[2678]: Resolved ip:[0] Jul 04 12:26:35 volumio2 systemd[1]: Finished welcome.service - Show a welcome message on console. Jul 04 12:26:35 volumio2 systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jul 04 12:26:35 volumio2 volumio[2257]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jul 04 12:26:35 volumio2 volumio[2257]: info: CoreCommandRouter::volumioGetState Jul 04 12:26:35 volumio2 volumio[2257]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:36 volumio2 volumio[2257]: info: Discovery: adding 6b56f2d5-cbd9-4eb4-af79-a9ffa3dae30f Jul 04 12:26:36 volumio2 volumio[2257]: info: Discovery: Found device Volumio2 Jul 04 12:26:36 volumio2 volumio[2257]: info: CoreCommandRouter::volumioGetState Jul 04 12:26:36 volumio2 volumio[2257]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:36 volumio2 go-librespot[2612]: time="2025-07-04T12:26:36+02: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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 04 12:26:36 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 12:26:36 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 12:26:36 volumio2 volumio[2257]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 04 12:26:36 volumio2 volumio[2257]: Error: socket hang up Jul 04 12:26:36 volumio2 volumio[2257]: at connResetException (node:internal/errors:720:14) Jul 04 12:26:36 volumio2 volumio[2257]: at Socket.socketOnEnd (node:_http_client:519:23) Jul 04 12:26:36 volumio2 volumio[2257]: at Socket.emit (node:events:526:35) Jul 04 12:26:36 volumio2 volumio[2257]: at endReadableNT (node:internal/streams/readable:1376:12) Jul 04 12:26:36 volumio2 volumio[2257]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jul 04 12:26:36 volumio2 volumio[2257]: code: 'ECONNRESET', Jul 04 12:26:36 volumio2 volumio[2257]: response: undefined Jul 04 12:26:36 volumio2 volumio[2257]: } Jul 04 12:26:36 volumio2 volumio[2257]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 04 12:26:36 volumio2 sudo[2699]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-07-04 12:25' Jul 04 12:26:36 volumio2 sudo[2699]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:36 volumio2 sudo[2699]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:36 volumio2 volumio-remote-updater[844]: [2025-07-04 12:26:36] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jul 04 12:26:36 volumio2 volumio-remote-updater[844]: [2025-07-04 12:26:36] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jul 04 12:26:36 volumio2 systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jul 04 12:26:36 volumio2 systemd[1]: volumio.service: Failed with result 'exit-code'. Jul 04 12:26:36 volumio2 systemd[1]: volumio.service: Consumed 7.196s CPU time. Jul 04 12:26:36 volumio2 systemd[1]: Started dynamicswap.service - dynamicswap service. Jul 04 12:26:36 volumio2 systemd[1]: dynamicswap.service: Deactivated successfully. Jul 04 12:26:36 volumio2 ntpd[1305]: IO: Deleting interface #4 eth0, 192.168.1.106#123, interface stats: received=0, sent=0, dropped=0, active_time=9 secs Jul 04 12:26:36 volumio2 ntpd[1305]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Jul 04 12:26:36 volumio2 ntpd[1305]: DNS: dns_check: DNS error: -11, System error Jul 04 12:26:36 volumio2 ntpd[1305]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12 Jul 04 12:26:37 volumio2 systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Jul 04 12:26:37 volumio2 systemd[1]: Started dynamicswap.service - dynamicswap service. Jul 04 12:26:37 volumio2 systemd[1]: Stopped volumio.service - Volumio Backend Module. Jul 04 12:26:37 volumio2 systemd[1]: volumio.service: Consumed 7.196s CPU time. Jul 04 12:26:37 volumio2 systemd[1]: Started volumio.service - Volumio Backend Module. Jul 04 12:26:37 volumio2 systemd[1]: dynamicswap.service: Deactivated successfully. Jul 04 12:26:37 volumio2 volumio[2715]: info: ------------------------------------------- Jul 04 12:26:37 volumio2 volumio[2715]: info: ----- Volumio3 ---- Jul 04 12:26:37 volumio2 volumio[2715]: info: ------------------------------------------- Jul 04 12:26:37 volumio2 volumio[2715]: info: ----- System startup ---- Jul 04 12:26:37 volumio2 volumio[2715]: info: ------------------------------------------- Jul 04 12:26:37 volumio2 volumio[2715]: info: MYVOLUMIO Environment detected Jul 04 12:26:37 volumio2 volumio[2715]: info: Plugin folders cleanup Jul 04 12:26:37 volumio2 volumio[2715]: info: Scanning into folder /volumio/app/plugins/ Jul 04 12:26:37 volumio2 volumio[2715]: info: Scanning category audio_interface Jul 04 12:26:37 volumio2 volumio[2715]: info: Scanning category miscellanea Jul 04 12:26:37 volumio2 volumio[2715]: info: Scanning category music_service Jul 04 12:26:37 volumio2 volumio[2715]: info: Scanning category plugins.json Jul 04 12:26:37 volumio2 volumio[2715]: info: Scanning category system_controller Jul 04 12:26:37 volumio2 volumio[2715]: info: Scanning category user_interface Jul 04 12:26:37 volumio2 volumio[2715]: info: Scanning into folder /data/plugins/ Jul 04 12:26:37 volumio2 volumio[2715]: info: Scanning category audio_interface Jul 04 12:26:37 volumio2 volumio[2715]: info: Scanning category music_service Jul 04 12:26:37 volumio2 volumio[2715]: info: Scanning category user_interface Jul 04 12:26:37 volumio2 volumio[2715]: info: Plugin folders cleanup completed Jul 04 12:26:37 volumio2 volumio[2715]: info: ------------------------------------------- Jul 04 12:26:37 volumio2 volumio[2715]: info: ----- Core plugins startup ---- Jul 04 12:26:37 volumio2 volumio[2715]: info: ------------------------------------------- Jul 04 12:26:37 volumio2 volumio[2715]: info: Loading plugins from folder /volumio/app/plugins/ Jul 04 12:26:37 volumio2 volumio[2715]: info: Adding plugin upnp to MyMusic Plugins Jul 04 12:26:37 volumio2 volumio[2715]: info: Adding plugin airplay_emulation to MyMusic Plugins Jul 04 12:26:37 volumio2 volumio[2715]: info: Adding plugin upnp_browser to MyMusic Plugins Jul 04 12:26:37 volumio2 volumio[2715]: info: Loading plugins from folder /data/plugins/ Jul 04 12:26:37 volumio2 volumio[2715]: info: Loading plugin "system"... Jul 04 12:26:37 volumio2 volumio[2715]: info: Loading plugin "appearance"... Jul 04 12:26:37 volumio2 ntpd[1305]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Jul 04 12:26:37 volumio2 ntpd[1305]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Jul 04 12:26:37 volumio2 ntpd[1305]: DNS: dns_check: DNS error: -11, System error Jul 04 12:26:37 volumio2 ntpd[1305]: DNS: dns_take_status: 2.debian.pool.ntp.org=>error, 12 Jul 04 12:26:37 volumio2 volumio[2715]: info: Loading plugin "network"... Jul 04 12:26:37 volumio2 volumio[2715]: info: Refreshing Cached IP Addresses Jul 04 12:26:38 volumio2 sudo[2745]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 04 12:26:38 volumio2 sudo[2745]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:38 volumio2 sudo[2747]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 04 12:26:38 volumio2 volumio[2715]: info: Loading plugin "services"... Jul 04 12:26:38 volumio2 sudo[2745]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:38 volumio2 volumio[2715]: info: Loading plugin "alsa_controller"... Jul 04 12:26:38 volumio2 sudo[2747]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:38 volumio2 sudo[2747]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:38 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 04 12:26:38 volumio2 volumio[2715]: info: Loading plugin "wizard"... Jul 04 12:26:38 volumio2 volumio[2715]: info: Loading plugin "networkfs"... Jul 04 12:26:38 volumio2 volumio[2715]: info: Starting Udev Watcher for removable devices Jul 04 12:26:38 volumio2 volumio[2715]: info: Ignoring mount for partition: boot Jul 04 12:26:38 volumio2 volumio[2715]: info: Ignoring mount for partition: volumio Jul 04 12:26:38 volumio2 volumio[2715]: info: Ignoring mount for partition: volumio_data Jul 04 12:26:38 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 04 12:26:38 volumio2 volumio[2715]: info: Loading plugin "volumio_command_line_client"... Jul 04 12:26:38 volumio2 volumio[2715]: info: Loading plugin "upnp"... Jul 04 12:26:38 volumio2 volumio[2715]: info: [1751624798062] Starting Upmpd Daemon Jul 04 12:26:38 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 04 12:26:38 volumio2 volumio[2715]: info: Loading plugin "my_music"... Jul 04 12:26:38 volumio2 volumio[2715]: info: Loading plugin "mpd"... Jul 04 12:26:38 volumio2 volumio[2715]: info: Loading plugin "upnp_browser"... Jul 04 12:26:38 volumio2 volumio[2715]: info: Loading plugin "alarm-clock"... Jul 04 12:26:38 volumio2 volumio[2715]: info: Loading plugin "airplay_emulation"... Jul 04 12:26:38 volumio2 volumio[2715]: info: Starting Shairport Sync Jul 04 12:26:38 volumio2 volumio[2715]: info: Loading plugin "last_100"... Jul 04 12:26:38 volumio2 volumio[2715]: info: Loading plugin "webradio"... Jul 04 12:26:38 volumio2 volumio[2715]: info: Loading plugin "i2s_dacs"... Jul 04 12:26:38 volumio2 volumio[2715]: info: I2S DAC not set, start Auto-detection Jul 04 12:26:38 volumio2 volumio[2715]: info: Loading plugin "volumiodiscovery"... Jul 04 12:26:38 volumio2 volumio[2715]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 04 12:26:38 volumio2 volumio[2715]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 04 12:26:38 volumio2 volumio[2715]: *** WARNING *** For more information see Jul 04 12:26:38 volumio2 volumio[2715]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 04 12:26:38 volumio2 volumio[2715]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 04 12:26:38 volumio2 node[2715]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 04 12:26:38 volumio2 volumio[2715]: *** WARNING *** For more information see Jul 04 12:26:38 volumio2 node[2715]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 04 12:26:38 volumio2 node[2715]: *** WARNING *** For more information see Jul 04 12:26:38 volumio2 node[2715]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 04 12:26:38 volumio2 node[2715]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 04 12:26:38 volumio2 node[2715]: *** WARNING *** For more information see Jul 04 12:26:38 volumio2 volumio[2715]: info: Applying required configuration parameters for plugin volumiodiscovery Jul 04 12:26:38 volumio2 volumio[2715]: info: Discovery: Started advertising with name: Volumio2 Jul 04 12:26:38 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 04 12:26:38 volumio2 volumio[2715]: info: Loading plugin "spop"... Jul 04 12:26:38 volumio2 ntpd[1305]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Jul 04 12:26:38 volumio2 ntpd[1305]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Jul 04 12:26:38 volumio2 ntpd[1305]: DNS: dns_check: DNS error: -11, System error Jul 04 12:26:38 volumio2 ntpd[1305]: DNS: dns_take_status: 1.debian.pool.ntp.org=>error, 12 Jul 04 12:26:38 volumio2 volumio[2715]: info: Loading plugin "now_playing"... Jul 04 12:26:39 volumio2 volumio[2715]: info: Loading plugin "outputs"... Jul 04 12:26:39 volumio2 volumio[2715]: info: Loading plugin "albumart"... Jul 04 12:26:39 volumio2 volumio[2715]: info: Plugin example_plugin is not enabled Jul 04 12:26:39 volumio2 volumio[2715]: info: Loading plugin "inputs"... Jul 04 12:26:39 volumio2 volumio[2715]: info: Loading plugin "updater_comm"... Jul 04 12:26:39 volumio2 volumio[2715]: info: Plugin mpdemulation is not enabled Jul 04 12:26:39 volumio2 volumio[2715]: info: Loading plugin "rest_api"... Jul 04 12:26:39 volumio2 volumio[2715]: info: Loading plugin "websocket"... Jul 04 12:26:39 volumio2 volumio[2715]: info: Starting Socket.io Server version 1.7.4 Jul 04 12:26:39 volumio2 volumio[2715]: info: Loading plugin "fusiondsp"... Jul 04 12:26:39 volumio2 volumio[2776]: Forking 3 albumart workers Jul 04 12:26:39 volumio2 volumio[2715]: info: Applying required configuration parameters for plugin fusiondsp Jul 04 12:26:39 volumio2 volumio[2715]: info: Loading plugin "Systeminfo"... Jul 04 12:26:39 volumio2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jul 04 12:26:39 volumio2 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jul 04 12:26:39 volumio2 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jul 04 12:26:39 volumio2 go-librespot[2816]: go-librespot daemon starting... Jul 04 12:26:39 volumio2 go-librespot[2817]: time="2025-07-04T12:26:39+02:00" level=info msg="running go-librespot 0.2.0" Jul 04 12:26:39 volumio2 go-librespot[2817]: time="2025-07-04T12:26:39+02:00" level=debug msg="app state loaded" Jul 04 12:26:39 volumio2 go-librespot[2817]: time="2025-07-04T12:26:39+02:00" level=debug msg="stored credentials not found" Jul 04 12:26:39 volumio2 go-librespot[2817]: time="2025-07-04T12:26:39+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 04 12:26:39 volumio2 go-librespot[2817]: time="2025-07-04T12:26:39+02: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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 04 12:26:39 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 12:26:39 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 12:26:39 volumio2 volumio[2715]: info: Loading i18n strings for locale de Jul 04 12:26:39 volumio2 volumio[2715]: Updating browse sources language Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 04 12:26:39 volumio2 volumio[2786]: Starting albumart workers Jul 04 12:26:39 volumio2 volumio[2788]: Starting albumart workers Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::initPlayerControls Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 12:26:39 volumio2 volumio[2715]: Express server listening on port 3000 Jul 04 12:26:39 volumio2 volumio[2715]: [Metrics] WebUI: 2s 260.18ms Jul 04 12:26:39 volumio2 volumio[2787]: Starting albumart workers Jul 04 12:26:39 volumio2 volumio[2715]: info: Setting Device type: x86 Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreStateMachine::resetVolumioState Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreStateMachine::getcurrentVolume Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::volumioRetrievevolume Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreStateMachine::pushState Jul 04 12:26:39 volumio2 volumio[2715]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::volumioPushState Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:39 volumio2 volumio[2715]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Jul 04 12:26:39 volumio2 volumio[2715]: info: Completed loading Core Plugins Jul 04 12:26:39 volumio2 volumio[2715]: info: Preparing to generate the ALSA configuration file Jul 04 12:26:39 volumio2 volumio[2715]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jul 04 12:26:39 volumio2 volumio[2715]: info: Reading ALSA contributions from plugins. Jul 04 12:26:39 volumio2 volumio[2715]: info: Volumio Network Manager: Network status updated: 0 Jul 04 12:26:39 volumio2 volumio[2715]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Jul 04 12:26:39 volumio2 volumio[2715]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Jul 04 12:26:39 volumio2 volumio[2715]: info: Reloading queue from file Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreStateMachine::setRepeat true single undefined Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreStateMachine::pushState Jul 04 12:26:39 volumio2 volumio[2715]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::volumioPushState Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreStateMachine::setRandom null Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreStateMachine::pushState Jul 04 12:26:39 volumio2 volumio[2715]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::volumioPushState Jul 04 12:26:39 volumio2 volumio[2715]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Jul 04 12:26:39 volumio2 volumio[2715]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'has') Jul 04 12:26:39 volumio2 volumio[2715]: info: Discovery: adding 6b56f2d5-cbd9-4eb4-af79-a9ffa3dae30f Jul 04 12:26:39 volumio2 volumio[2715]: info: Discovery: Found device Volumio2 Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::volumioGetState Jul 04 12:26:39 volumio2 volumio[2715]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:39 volumio2 volumio[2715]: info: Asound.conf file unchanged, so no further update is needed Jul 04 12:26:39 volumio2 volumio[2715]: info: Output device has changed, restarting MPD Jul 04 12:26:39 volumio2 volumio[2715]: info: Output device has changed, restarting Shairport Sync Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:39 volumio2 sudo[2848]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 04 12:26:39 volumio2 sudo[2848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:39 volumio2 sudo[2848]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:39 volumio2 ntpd[1305]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Jul 04 12:26:39 volumio2 ntpd[1305]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Jul 04 12:26:39 volumio2 ntpd[1305]: DNS: dns_check: DNS error: -11, System error Jul 04 12:26:39 volumio2 ntpd[1305]: DNS: dns_take_status: 0.debian.pool.ntp.org=>error, 12 Jul 04 12:26:39 volumio2 sudo[2850]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 04 12:26:39 volumio2 sudo[2850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:39 volumio2 volumio[2715]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 04 12:26:39 volumio2 volumio[2715]: info: ___________ START PLUGINS ___________ Jul 04 12:26:39 volumio2 volumio[2715]: info: ControllerMpd::onStart: Initializing MPD Jul 04 12:26:39 volumio2 volumio[2715]: info: Creating MPD Configuration file Jul 04 12:26:39 volumio2 systemd[1]: Stopping mpd.service - Music Player Daemon... Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 04 12:26:39 volumio2 systemd[1]: mpd.service: Deactivated successfully. Jul 04 12:26:39 volumio2 volumio[2715]: info: [1751624799932] CoreMusicLibrary::Adding element Medienserver Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 04 12:26:39 volumio2 systemd[1]: Stopped mpd.service - Music Player Daemon. Jul 04 12:26:39 volumio2 systemd[1]: mpd.socket: Deactivated successfully. Jul 04 12:26:39 volumio2 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jul 04 12:26:39 volumio2 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jul 04 12:26:39 volumio2 sudo[2859]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 04 12:26:39 volumio2 sudo[2859]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:39 volumio2 sudo[2861]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 04 12:26:39 volumio2 sudo[2859]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:39 volumio2 sudo[2861]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:39 volumio2 volumio[2715]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:39 volumio2 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jul 04 12:26:39 volumio2 systemd[1]: Starting mpd.service - Music Player Daemon... Jul 04 12:26:39 volumio2 systemd[1]: mpd.service: Deactivated successfully. Jul 04 12:26:39 volumio2 volumio[2715]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 04 12:26:39 volumio2 systemd[1]: Stopped mpd.service - Music Player Daemon. Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 04 12:26:39 volumio2 volumio[2715]: info: [1751624799990] CoreMusicLibrary::Adding element Last_100 Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 04 12:26:39 volumio2 volumio[2715]: info: [1751624799991] CoreMusicLibrary::Adding element Webradio Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 04 12:26:39 volumio2 systemd[1]: mpd.socket: Deactivated successfully. Jul 04 12:26:39 volumio2 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jul 04 12:26:39 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 04 12:26:39 volumio2 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jul 04 12:26:39 volumio2 volumio[2715]: info: Initializing BBC Radios Jul 04 12:26:40 volumio2 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jul 04 12:26:40 volumio2 systemd[1]: Starting mpd.service - Music Player Daemon... Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: Creating Spotify config file Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: [now-playing] ConfigUpdater: config is up to date. Jul 04 12:26:40 volumio2 dhcpcd[826]: eth0: leased 192.168.1.106 for 86400 seconds Jul 04 12:26:40 volumio2 avahi-daemon[835]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.106. Jul 04 12:26:40 volumio2 avahi-daemon[835]: New relevant interface eth0.IPv4 for mDNS. Jul 04 12:26:40 volumio2 avahi-daemon[835]: Registering new address record for 192.168.1.106 on eth0.IPv4. Jul 04 12:26:40 volumio2 dhcpcd[826]: eth0: adding route to 192.168.1.0/24 Jul 04 12:26:40 volumio2 dhcpcd[826]: eth0: adding default route via 192.168.1.1 Jul 04 12:26:40 volumio2 sudo[2878]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 04 12:26:40 volumio2 volumio[2715]: info: Loading i18n strings for locale de Jul 04 12:26:40 volumio2 sudo[2878]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jul 04 12:26:40 volumio2 systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jul 04 12:26:40 volumio2 sudo[2878]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:40 volumio2 systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jul 04 12:26:40 volumio2 systemd[1]: welcome.service: Deactivated successfully. Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: FusionDsp - mixtype--------------------- None Jul 04 12:26:40 volumio2 systemd[1]: Stopped welcome.service - Show a welcome message on console. Jul 04 12:26:40 volumio2 systemd[1]: Stopping welcome.service - Show a welcome message on console... Jul 04 12:26:40 volumio2 volumio[2715]: info: Volumio Calling Home Jul 04 12:26:40 volumio2 volumio[2715]: info: Preparing to generate the ALSA configuration file Jul 04 12:26:40 volumio2 systemd[1]: Starting welcome.service - Show a welcome message on console... Jul 04 12:26:40 volumio2 welcome[2906]: Resolved ip:[1] 192.168.1.106 Jul 04 12:26:40 volumio2 systemd[1]: Finished welcome.service - Show a welcome message on console. Jul 04 12:26:40 volumio2 systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jul 04 12:26:40 volumio2 volumio[2715]: info: [now-playing] Fetching API key... Jul 04 12:26:40 volumio2 volumio[2715]: info: [now-playing] App is listening on port 4004. Jul 04 12:26:40 volumio2 volumio[2715]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Jul 04 12:26:40 volumio2 volumio[2715]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jul 04 12:26:40 volumio2 volumio[2715]: info: Reading ALSA contributions from plugins. Jul 04 12:26:40 volumio2 volumio[2715]: Unhandled rejection Error: No sockets available, cannot start. Jul 04 12:26:40 volumio2 volumio[2715]: at SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Jul 04 12:26:40 volumio2 volumio[2715]: at SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Jul 04 12:26:40 volumio2 volumio[2715]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Jul 04 12:26:40 volumio2 volumio[2715]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Jul 04 12:26:40 volumio2 volumio[2715]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Jul 04 12:26:40 volumio2 volumio[2715]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Jul 04 12:26:40 volumio2 volumio[2715]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Jul 04 12:26:40 volumio2 volumio[2715]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Jul 04 12:26:40 volumio2 volumio[2715]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Jul 04 12:26:40 volumio2 volumio[2715]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Jul 04 12:26:40 volumio2 volumio[2715]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Jul 04 12:26:40 volumio2 volumio[2715]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Jul 04 12:26:40 volumio2 volumio[2715]: at proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Jul 04 12:26:40 volumio2 volumio[2715]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Jul 04 12:26:40 volumio2 volumio[2715]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Jul 04 12:26:40 volumio2 volumio[2715]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jul 04 12:26:40 volumio2 volumio[2715]: info: MPD Permissions set Jul 04 12:26:40 volumio2 volumio[2715]: info: MPD Permissions set Jul 04 12:26:40 volumio2 volumio[2715]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jul 04 12:26:40 volumio2 volumio[2715]: info: Spotify config file written Jul 04 12:26:40 volumio2 volumio[2715]: info: Listing playlists Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::volumioGetQueue Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreStateMachine::getQueue Jul 04 12:26:40 volumio2 volumio[2715]: info: CorePlayQueue::getQueue Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::volumioGetVisibleSources Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::volumioGetState Jul 04 12:26:40 volumio2 volumio[2715]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:40 volumio2 volumio[2715]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 04 12:26:40 volumio2 volumio[2715]: info: Discovery: Getting this device information Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::volumioGetState Jul 04 12:26:40 volumio2 volumio[2715]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 04 12:26:40 volumio2 volumio[2715]: info: Listing playlists Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::volumioGetQueue Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreStateMachine::getQueue Jul 04 12:26:40 volumio2 volumio[2715]: info: CorePlayQueue::getQueue Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::volumioGetVisibleSources Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::volumioGetState Jul 04 12:26:40 volumio2 volumio[2715]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:40 volumio2 sudo[2925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jul 04 12:26:40 volumio2 sudo[2925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:40 volumio2 volumio[2715]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jul 04 12:26:40 volumio2 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jul 04 12:26:40 volumio2 go-librespot[2927]: go-librespot daemon starting... Jul 04 12:26:40 volumio2 sudo[2925]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jul 04 12:26:40 volumio2 go-librespot[2941]: time="2025-07-04T12:26:40+02:00" level=info msg="running go-librespot 0.2.0" Jul 04 12:26:40 volumio2 go-librespot[2941]: time="2025-07-04T12:26:40+02:00" level=debug msg="app state loaded" Jul 04 12:26:40 volumio2 go-librespot[2941]: time="2025-07-04T12:26:40+02:00" level=debug msg="stored credentials not found" Jul 04 12:26:40 volumio2 go-librespot[2941]: time="2025-07-04T12:26:40+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: No need to fix Spotify hosts Jul 04 12:26:40 volumio2 volumio[2715]: info: Starting Shairport Sync Jul 04 12:26:40 volumio2 volumio[2715]: info: Starting Shairport Sync Jul 04 12:26:40 volumio2 volumio[2715]: info: Starting Shairport Sync Jul 04 12:26:40 volumio2 sudo[2951]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 04 12:26:40 volumio2 sudo[2951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:40 volumio2 sudo[2955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 04 12:26:40 volumio2 volumio[2715]: info: Asound.conf file unchanged, so no further update is needed Jul 04 12:26:40 volumio2 volumio[2715]: info: Output device has changed, restarting MPD Jul 04 12:26:40 volumio2 sudo[2955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:40 volumio2 sudo[2956]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 04 12:26:40 volumio2 sudo[2956]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:40 volumio2 volumio[2715]: info: Output device has changed, restarting Shairport Sync Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:40 volumio2 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jul 04 12:26:40 volumio2 sudo[2960]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 04 12:26:40 volumio2 sudo[2960]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:40 volumio2 systemd[1]: shairport-sync.service: Deactivated successfully. Jul 04 12:26:40 volumio2 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jul 04 12:26:40 volumio2 systemd[1]: shairport-sync.service: Consumed 1.674s CPU time. Jul 04 12:26:40 volumio2 sudo[2960]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:40 volumio2 sudo[2963]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 04 12:26:40 volumio2 sudo[2963]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:40 volumio2 volumio[2715]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 04 12:26:40 volumio2 volumio[2715]: info: MPD Permissions set Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jul 04 12:26:40 volumio2 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jul 04 12:26:40 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:40 volumio2 sudo[2956]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:40 volumio2 sudo[2955]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:40 volumio2 sudo[2951]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:40 volumio2 systemd[1]: mpd.service: Deactivated successfully. Jul 04 12:26:40 volumio2 systemd[1]: Stopped mpd.service - Music Player Daemon. Jul 04 12:26:40 volumio2 systemd[1]: mpd.socket: Deactivated successfully. Jul 04 12:26:40 volumio2 volumio[2715]: info: Shairport-Sync Started Jul 04 12:26:40 volumio2 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jul 04 12:26:40 volumio2 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jul 04 12:26:40 volumio2 volumio[2715]: Error adding Membership: Error: addMembership EINVAL Jul 04 12:26:40 volumio2 volumio[2715]: info: Shairport-Sync Started Jul 04 12:26:40 volumio2 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jul 04 12:26:40 volumio2 volumio[2715]: info: Shairport-Sync Started Jul 04 12:26:40 volumio2 volumio[2715]: info: Starting Shairport Sync Jul 04 12:26:40 volumio2 systemd[1]: Starting mpd.service - Music Player Daemon... Jul 04 12:26:40 volumio2 sudo[2995]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 04 12:26:40 volumio2 sudo[2995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:40 volumio2 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jul 04 12:26:40 volumio2 systemd[1]: shairport-sync.service: Deactivated successfully. Jul 04 12:26:40 volumio2 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jul 04 12:26:40 volumio2 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jul 04 12:26:40 volumio2 sudo[2995]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:40 volumio2 volumio[2715]: info: Shairport-Sync Started Jul 04 12:26:40 volumio2 sudo[2993]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 04 12:26:40 volumio2 sudo[2993]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jul 04 12:26:40 volumio2 sudo[2993]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:40 volumio2 dhcpcd[871]: eth0: leased 192.168.1.106 for 86400 seconds Jul 04 12:26:40 volumio2 dhcpcd[871]: eth0: adding route to 192.168.1.0/24 Jul 04 12:26:40 volumio2 dhcpcd[871]: eth0: adding default route via 192.168.1.1 Jul 04 12:26:40 volumio2 systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jul 04 12:26:40 volumio2 systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jul 04 12:26:40 volumio2 systemd[1]: welcome.service: Deactivated successfully. Jul 04 12:26:40 volumio2 systemd[1]: Stopped welcome.service - Show a welcome message on console. Jul 04 12:26:40 volumio2 systemd[1]: Stopping welcome.service - Show a welcome message on console... Jul 04 12:26:40 volumio2 systemd[1]: Starting welcome.service - Show a welcome message on console... Jul 04 12:26:40 volumio2 welcome[3031]: Resolved ip:[1] 192.168.1.106 Jul 04 12:26:40 volumio2 systemd[1]: Finished welcome.service - Show a welcome message on console. Jul 04 12:26:40 volumio2 systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jul 04 12:26:41 volumio2 mpd[3013]: 2025-07-04T12:26:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 04 12:26:41 volumio2 systemd[1]: Started mpd.service - Music Player Daemon. Jul 04 12:26:41 volumio2 sudo[2861]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:41 volumio2 sudo[2850]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:41 volumio2 sudo[2963]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:41 volumio2 volumio[2715]: info: Completed starting Core Plugins Jul 04 12:26:41 volumio2 volumio[2715]: info: ------------------------------------------- Jul 04 12:26:41 volumio2 volumio[2715]: info: ----- MyVolumio plugins startup ---- Jul 04 12:26:41 volumio2 volumio[2715]: info: ------------------------------------------- Jul 04 12:26:41 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Fetching plans data.... Jul 04 12:26:41 volumio2 volumio[2715]: error: MPD error: The expression evaluated to a falsy value: Jul 04 12:26:41 volumio2 volumio[2715]: assert.ok(self.idling) Jul 04 12:26:41 volumio2 volumio[2715]: error: The expression evaluated to a falsy value: Jul 04 12:26:41 volumio2 volumio[2715]: assert.ok(self.idling) Jul 04 12:26:41 volumio2 volumio[2715]: error: MPD error: The expression evaluated to a falsy value: Jul 04 12:26:41 volumio2 volumio[2715]: assert.ok(self.idling) Jul 04 12:26:41 volumio2 volumio[2715]: error: The expression evaluated to a falsy value: Jul 04 12:26:41 volumio2 volumio[2715]: assert.ok(self.idling) Jul 04 12:26:41 volumio2 volumio[2715]: error: updateQueue error: null Jul 04 12:26:41 volumio2 volumio[2715]: info: MPD running with PID3013 Jul 04 12:26:41 volumio2 volumio[2715]: ,establishing connection Jul 04 12:26:41 volumio2 volumio[2715]: error: updateQueue error: null Jul 04 12:26:41 volumio2 volumio-remote-updater[844]: [2025-07-04 12:26:41] [connect] Successful connection Jul 04 12:26:41 volumio2 volumio-remote-updater[844]: [2025-07-04 12:26:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1751624801 101 Jul 04 12:26:41 volumio2 volumio[2715]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 4 Jul 04 12:26:41 volumio2 ntpd[1305]: IO: Listen normally on 5 eth0 192.168.1.106:123 Jul 04 12:26:41 volumio2 ntpd[1305]: IO: new interface(s) found: waking up resolver Jul 04 12:26:41 volumio2 ntpd[1305]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Jul 04 12:26:42 volumio2 volumio[2715]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Jul 04 12:26:42 volumio2 volumio[2715]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo Jul 04 12:26:42 volumio2 volumio[2715]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Jul 04 12:26:42 volumio2 volumio[2715]: info: camilladsp service started and running in background, instance 1 Jul 04 12:26:42 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 04 12:26:42 volumio2 volumio[2715]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 176400 192000 384000 768000 <-AAAAAAAAAAAAA Jul 04 12:26:42 volumio2 volumio[2715]: info: FusionDsp loaded Jul 04 12:26:42 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 04 12:26:42 volumio2 volumio[2715]: error: FusionDsp - Socket connection not established Jul 04 12:26:42 volumio2 volumio[2715]: info: FusionDsp - Reporting Fusion DSP Enabled Jul 04 12:26:42 volumio2 volumio[2715]: info: Adding Signal Path Element [object Object] Jul 04 12:26:42 volumio2 volumio[2715]: info: Adding fusiondspeq DSP Signal Path Element Jul 04 12:26:42 volumio2 volumio[2715]: info: FusionDsp - ---- installed callbackRead Jul 04 12:26:42 volumio2 sudo[3060]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jul 04 12:26:42 volumio2 sudo[3060]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:42 volumio2 volumio[2715]: info: FusionDsp - File size found in array! Jul 04 12:26:42 volumio2 sudo[3060]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:42 volumio2 systemd[1]: systemd-timedated.service: Deactivated successfully. Jul 04 12:26:43 volumio2 volumio[2715]: info: go-librespot daemon successfully initialized Jul 04 12:26:46 volumio2 volumio[2715]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jul 04 12:26:46 volumio2 volumio[2715]: info: Initializing connection to go-librespot Websocket Jul 04 12:26:48 volumio2 volumio[2715]: info: Volumio Network Manager: Network status updated: 1 Jul 04 12:26:48 volumio2 sudo[3088]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 04 12:26:48 volumio2 sudo[3088]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:48 volumio2 sudo[3088]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:48 volumio2 sudo[3090]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 04 12:26:48 volumio2 sudo[3090]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:48 volumio2 sudo[3090]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:48 volumio2 sudo[3092]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jul 04 12:26:48 volumio2 sudo[3092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:48 volumio2 sudo[3092]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:48 volumio2 volumio[2715]: info: Upmpdcli Daemon Started Jul 04 12:26:49 volumio2 nmbd[1374]: [2025/07/04 12:26:49.231802, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jul 04 12:26:49 volumio2 nmbd[1374]: Packet send failed to 169.254.255.255(138) ERRNO=Network is unreachable Jul 04 12:26:50 volumio2 volumio[2715]: error: [now-playing] Error fetching https://openweathermap.org: TypeError: fetch failed Jul 04 12:26:50 volumio2 volumio[2715]: at Object.fetch (node:internal/deps/undici/undici:11576:11) Jul 04 12:26:50 volumio2 volumio[2715]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Jul 04 12:26:50 volumio2 volumio[2715]: at async fetchPage (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:25:26) Jul 04 12:26:50 volumio2 volumio[2715]: at async doGet (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:118:22) Jul 04 12:26:50 volumio2 volumio[2715]: error: [now-playing] Caught error in callback of WeatherAPI.#getFetchPromise(): fetch failed Jul 04 12:26:58 volumio2 volumio[2715]: info: Discovery: this is already registered, 6b56f2d5-cbd9-4eb4-af79-a9ffa3dae30f Jul 04 12:26:58 volumio2 volumio[2715]: info: Discovery: Found device Volumio2 Jul 04 12:26:58 volumio2 volumio[2715]: info: CoreCommandRouter::volumioGetState Jul 04 12:26:58 volumio2 volumio[2715]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:58 volumio2 volumio[2715]: error: FusionDsp - Reload WebSocket error: [object Object] Jul 04 12:26:58 volumio2 go-librespot[2941]: time="2025-07-04T12:26:58+02:00" level=debug msg="new websocket client" Jul 04 12:26:58 volumio2 volumio[2715]: info: Discovery: adding 4f26aed5-9396-49e1-a073-944229541de9 Jul 04 12:26:58 volumio2 volumio[2715]: info: Discovery: Found device volumio-az Jul 04 12:26:58 volumio2 volumio[2715]: info: Discovery: Connecting to remote: 192.168.1.11 Jul 04 12:26:58 volumio2 volumio[2715]: info: Connection to go-librespot Websocket established Jul 04 12:26:58 volumio2 volumio[2715]: info: CoreCommandRouter::volumioGetState Jul 04 12:26:58 volumio2 volumio[2715]: info: CorePlayQueue::getTrack 0 Jul 04 12:26:58 volumio2 volumio[2715]: info: Discovery: Connected to remote: 192.168.1.11 Jul 04 12:26:58 volumio2 go-librespot[2941]: time="2025-07-04T12:26:58+02: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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 04 12:26:58 volumio2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 04 12:26:58 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 04 12:26:58 volumio2 volumio[2715]: info: Connection to go-librespot Websocket closed Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jul 04 12:26:58 volumio2 volumio[2715]: info: Adding plugin bluetooth to MyMusic Plugins Jul 04 12:26:58 volumio2 volumio[2715]: info: Adding plugin multiroom to MyMusic Plugins Jul 04 12:26:58 volumio2 volumio[2715]: info: Adding plugin metavolumio to MyMusic Plugins Jul 04 12:26:58 volumio2 volumio[2715]: info: Adding plugin cd_controller to MyMusic Plugins Jul 04 12:26:58 volumio2 volumio[2715]: info: Adding plugin qobuzconnect to MyMusic Plugins Jul 04 12:26:58 volumio2 volumio[2715]: info: Adding plugin smart_inputs to MyMusic Plugins Jul 04 12:26:58 volumio2 volumio[2715]: info: Adding plugin tidalconnect to MyMusic Plugins Jul 04 12:26:58 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jul 04 12:26:59 volumio2 volumio[2715]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jul 04 12:26:59 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jul 04 12:26:59 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:59 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 04 12:26:59 volumio2 volumio[2715]: info: Starting MyVolumio Remote Streaming Endpoints Jul 04 12:26:59 volumio2 volumio[2715]: info: MyVolumio login type: Token Jul 04 12:26:59 volumio2 volumio[2715]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jul 04 12:26:59 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jul 04 12:26:59 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jul 04 12:26:59 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jul 04 12:26:59 volumio2 volumio[2715]: info: Streaming services startup Jul 04 12:26:59 volumio2 volumio[2715]: info: Starting Streaming Daemon Jul 04 12:26:59 volumio2 sudo[3126]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jul 04 12:26:59 volumio2 sudo[3126]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 04 12:26:59 volumio2 volumio[2715]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jul 04 12:26:59 volumio2 sudo[3126]: pam_unix(sudo:session): session closed for user root Jul 04 12:26:59 volumio2 volumio[2715]: error: Cannot start Volumio Streaming Daemon Jul 04 12:26:59 volumio2 volumio[2715]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jul 04 12:26:59 volumio2 volumio[2715]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jul 04 12:26:59 volumio2 volumio[2715]: error: MyVolumio Custom Token format not valid, refreshing it Jul 04 12:26:59 volumio2 ntpd[1305]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Jul 04 12:26:59 volumio2 ntpd[1305]: DNS: dns_check: DNS error: -11, System error Jul 04 12:26:59 volumio2 ntpd[1305]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12 Jul 04 12:27:00 volumio2 volumio[2715]: info: MyVolumio login type: Token Jul 04 12:27:00 volumio2 volumio[2715]: verbose: New Socket.io Connection to 192.168.1.106:3000 from 192.168.1.11 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jul 04 12:27:00 volumio2 volumio[2715]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Jul 04 12:27:00 volumio2 volumio[2715]: info: CoreCommandRouter::volumioGetState Jul 04 12:27:00 volumio2 volumio[2715]: info: CorePlayQueue::getTrack 0 Jul 04 12:27:00 volumio2 volumio[2715]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jul 04 12:27:00 volumio2 ntpd[1305]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Jul 04 12:27:00 volumio2 ntpd[1305]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Jul 04 12:27:00 volumio2 ntpd[1305]: DNS: Pool taking: 217.79.189.239 Jul 04 12:27:00 volumio2 ntpd[1305]: DNS: Pool taking: 152.53.15.80 Jul 04 12:27:00 volumio2 ntpd[1305]: DNS: Pool taking: 54.36.110.36 Jul 04 12:27:00 volumio2 ntpd[1305]: DNS: Pool taking: 49.13.14.46 Jul 04 12:27:00 volumio2 ntpd[1305]: DNS: Pool taking: 2a01:4f9:c010:157::1 Jul 04 12:27:00 volumio2 ntpd[1305]: DNS: Pool taking: 2a01:239:25e:bd00:: Jul 04 12:27:00 volumio2 ntpd[1305]: DNS: Pool taking: 2001:638:a000:1123:123::2 Jul 04 12:27:00 volumio2 ntpd[1305]: DNS: Pool taking: 2a02:c207:2127:4427::1 Jul 04 12:27:00 volumio2 ntpd[1305]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Jul 04 12:27:01 volumio2 volumio[2715]: info: Getting Spotify volume Jul 04 12:27:01 volumio2 volumio[2715]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 04 12:27:01 volumio2 volumio[2715]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 04 12:27:01 volumio2 volumio[2715]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jul 04 12:27:01 volumio2 volumio[2715]: errno: -111, Jul 04 12:27:01 volumio2 volumio[2715]: code: 'ECONNREFUSED', Jul 04 12:27:01 volumio2 volumio[2715]: syscall: 'connect', Jul 04 12:27:01 volumio2 volumio[2715]: address: '127.0.0.1', Jul 04 12:27:01 volumio2 volumio[2715]: port: 9879, Jul 04 12:27:01 volumio2 volumio[2715]: response: undefined Jul 04 12:27:01 volumio2 volumio[2715]: } Jul 04 12:27:01 volumio2 volumio[2715]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 04 12:27:01 volumio2 sudo[3149]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-07-04 12:26' Jul 04 12:27:01 volumio2 sudo[3149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="f9454895cc8e2f1971c705a815a7226e021e37d7" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1fc282af1865fae9b40239cedf2cc17c112eef0d" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Jun 28 17:17:19 UTC 2025" VOLUMIO_VERSION="4.014" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="1284cfb9a5a962d09a3251e408a89b66"