-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Fri 2025-11-28 14:09:36 CET. -- Nov 28 14:08:00 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:00 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Nov 28 14:08:00 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:00 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:00 radio go-librespot[1041]: Librespot-go daemon starting... Nov 28 14:08:00 radio go-librespot[1041]: time="2025-11-28T14:08:00+01:00" level=info msg="generated new device id: acc6be1e2bbd5208ce27628ea4d8d4d0804975fa" Nov 28 14:08:00 radio go-librespot[1041]: time="2025-11-28T14:08:00+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:00 radio go-librespot[1041]: time="2025-11-28T14:08:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:00 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:00 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:01 radio systemd[1]: systemd-fsckd.service: Succeeded. Nov 28 14:08:01 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:01 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:02 radio sh[515]: timed out Nov 28 14:08:02 radio dhcpcd[558]: timed out Nov 28 14:08:02 radio sh[515]: dhcpcd exited Nov 28 14:08:02 radio dhcpcd[558]: dhcpcd exited Nov 28 14:08:02 radio sh[515]: ifup: failed to bring up eth0 Nov 28 14:08:02 radio systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:02 radio systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Nov 28 14:08:03 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:03 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Nov 28 14:08:03 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:03 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:03 radio go-librespot[1050]: Librespot-go daemon starting... Nov 28 14:08:03 radio go-librespot[1050]: time="2025-11-28T14:08:03+01:00" level=info msg="generated new device id: 91e37cc607d32ab5b869eed7aba583844a57e5b8" Nov 28 14:08:03 radio go-librespot[1050]: time="2025-11-28T14:08:03+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:03 radio go-librespot[1050]: time="2025-11-28T14:08:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:03 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:03 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:03 radio volumio[798]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.742&uuid=4feda0d797ae7cd80ce6fbe4b9eb7636" http://updates.volumio.org/downloader-v1/track-device Nov 28 14:08:03 radio volumio[798]: % Total % Received % Xferd Average Speed Time Time Time Current Nov 28 14:08:03 radio volumio[798]: Dload Upload Total Spent Left Speed Nov 28 14:08:03 radio volumio[798]: [132B blob data] Nov 28 14:08:03 radio volumio[798]: retrying in 5 seconds, trial 1 Nov 28 14:08:03 radio volumio[798]: info: Volumio Calling Home Nov 28 14:08:04 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:04 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:05 radio volumio[798]: error: MyVolumio Plugin failed to start in a timely fashion Nov 28 14:08:05 radio volumio[798]: info: BOOT COMPLETED Nov 28 14:08:05 radio volumio[798]: [Metrics] CommandRouter: 27s 48.30ms Nov 28 14:08:05 radio volumio[798]: info: CoreCommandRouter::volumiosetStartupVolume Nov 28 14:08:05 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 14:08:05 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 14:08:05 radio volumio[798]: info: CoreCommandRouter::Close All Modals sent Nov 28 14:08:05 radio volumio[798]: info: CoreCommandRouter::Close All Modals sent Nov 28 14:08:05 radio systemd[1]: systemd-hostnamed.service: Succeeded. Nov 28 14:08:06 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Nov 28 14:08:06 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 28 14:08:06 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Nov 28 14:08:06 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:06 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Nov 28 14:08:06 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:06 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:06 radio go-librespot[1066]: Librespot-go daemon starting... Nov 28 14:08:06 radio go-librespot[1066]: time="2025-11-28T14:08:06+01:00" level=info msg="generated new device id: 438406f49c132fa58ea543b0a83879f8a6633d3b" Nov 28 14:08:06 radio go-librespot[1066]: time="2025-11-28T14:08:06+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:06 radio go-librespot[1066]: time="2025-11-28T14:08:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:06 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:06 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:07 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:07 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:09 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:09 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Nov 28 14:08:09 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:09 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:09 radio go-librespot[1073]: Librespot-go daemon starting... Nov 28 14:08:09 radio go-librespot[1073]: time="2025-11-28T14:08:09+01:00" level=info msg="generated new device id: 708f05066bb6e6bb637e773ac1c95610a66c0832" Nov 28 14:08:09 radio go-librespot[1073]: time="2025-11-28T14:08:09+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:09 radio go-librespot[1073]: time="2025-11-28T14:08:09+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:09 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:09 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:10 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:10 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:13 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:13 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Nov 28 14:08:13 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:13 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:13 radio go-librespot[1081]: Librespot-go daemon starting... Nov 28 14:08:13 radio go-librespot[1081]: time="2025-11-28T14:08:13+01:00" level=info msg="generated new device id: 47ea3b1acdf9f501e04a6f0875d04f02ffeb34da" Nov 28 14:08:13 radio go-librespot[1081]: time="2025-11-28T14:08:13+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:13 radio go-librespot[1081]: time="2025-11-28T14:08:13+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:13 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:13 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:13 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 28 14:08:13 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 14:08:13 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 28 14:08:13 radio volumio[798]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.742&uuid=4feda0d797ae7cd80ce6fbe4b9eb7636" http://updates.volumio.org/downloader-v1/track-device Nov 28 14:08:13 radio volumio[798]: % Total % Received % Xferd Average Speed Time Time Time Current Nov 28 14:08:13 radio volumio[798]: Dload Upload Total Spent Left Speed Nov 28 14:08:13 radio volumio[798]: [132B blob data] Nov 28 14:08:13 radio volumio[798]: retrying in 5 seconds, trial 2 Nov 28 14:08:13 radio volumio[798]: info: Volumio Calling Home Nov 28 14:08:13 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:13 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:16 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:16 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Nov 28 14:08:16 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:16 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:16 radio go-librespot[1094]: Librespot-go daemon starting... Nov 28 14:08:16 radio go-librespot[1094]: time="2025-11-28T14:08:16+01:00" level=info msg="generated new device id: 34a1b3659a9e771f21812d1ca6c424332f1281c7" Nov 28 14:08:16 radio go-librespot[1094]: time="2025-11-28T14:08:16+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:16 radio go-librespot[1094]: time="2025-11-28T14:08:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:16 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:16 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:16 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:16 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:19 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:19 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Nov 28 14:08:19 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:19 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:19 radio go-librespot[1101]: Librespot-go daemon starting... Nov 28 14:08:19 radio go-librespot[1101]: time="2025-11-28T14:08:19+01:00" level=info msg="generated new device id: c7943632fd43f4893eea4ab17c6c45314b5832f4" Nov 28 14:08:19 radio go-librespot[1101]: time="2025-11-28T14:08:19+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:19 radio go-librespot[1101]: time="2025-11-28T14:08:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:19 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:19 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:19 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:19 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:22 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:22 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:22 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:22 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Nov 28 14:08:22 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:22 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:22 radio go-librespot[1108]: Librespot-go daemon starting... Nov 28 14:08:22 radio go-librespot[1108]: time="2025-11-28T14:08:22+01:00" level=info msg="generated new device id: 46362fa9c0634f00a792d320279f4e81490ba0d4" Nov 28 14:08:22 radio go-librespot[1108]: time="2025-11-28T14:08:22+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:22 radio go-librespot[1108]: time="2025-11-28T14:08:22+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:22 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:22 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:25 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:25 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:26 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:26 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Nov 28 14:08:26 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:26 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:26 radio go-librespot[1115]: Librespot-go daemon starting... Nov 28 14:08:26 radio go-librespot[1115]: time="2025-11-28T14:08:26+01:00" level=info msg="generated new device id: 2949b645df6325bb76721ebc49969ee541b74548" Nov 28 14:08:26 radio go-librespot[1115]: time="2025-11-28T14:08:26+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:26 radio go-librespot[1115]: time="2025-11-28T14:08:26+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:26 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:26 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:28 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:28 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:29 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:29 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Nov 28 14:08:29 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:29 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:29 radio go-librespot[1122]: Librespot-go daemon starting... Nov 28 14:08:29 radio go-librespot[1122]: time="2025-11-28T14:08:29+01:00" level=info msg="generated new device id: aca92314b1f63d6be640f65d0ceb238f4f0a1e1e" Nov 28 14:08:29 radio go-librespot[1122]: time="2025-11-28T14:08:29+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:29 radio go-librespot[1122]: time="2025-11-28T14:08:29+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:29 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:29 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:31 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:31 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:32 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:32 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Nov 28 14:08:32 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:32 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:32 radio go-librespot[1129]: Librespot-go daemon starting... Nov 28 14:08:32 radio go-librespot[1129]: time="2025-11-28T14:08:32+01:00" level=info msg="generated new device id: 838f690aede099158c18033c5be4de7c8b00babf" Nov 28 14:08:32 radio go-librespot[1129]: time="2025-11-28T14:08:32+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:32 radio go-librespot[1129]: time="2025-11-28T14:08:32+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:32 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:32 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:34 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:34 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:35 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:35 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Nov 28 14:08:35 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:35 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:35 radio go-librespot[1159]: Librespot-go daemon starting... Nov 28 14:08:35 radio go-librespot[1159]: time="2025-11-28T14:08:35+01:00" level=info msg="generated new device id: a0840b4080a35cdd0c9f2b89c6fdd7c36c57ef08" Nov 28 14:08:35 radio go-librespot[1159]: time="2025-11-28T14:08:35+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:35 radio go-librespot[1159]: time="2025-11-28T14:08:35+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:35 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:35 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:37 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:37 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:39 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:39 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Nov 28 14:08:39 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:39 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:39 radio go-librespot[1166]: Librespot-go daemon starting... Nov 28 14:08:39 radio go-librespot[1166]: time="2025-11-28T14:08:39+01:00" level=info msg="generated new device id: d414acb03a72afae4369834e6c750aed50bcb4c0" Nov 28 14:08:39 radio go-librespot[1166]: time="2025-11-28T14:08:39+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:39 radio go-librespot[1166]: time="2025-11-28T14:08:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:39 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:39 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:40 radio ntpd[747]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Nov 28 14:08:40 radio ntpd[747]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Nov 28 14:08:40 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:40 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:42 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:42 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Nov 28 14:08:42 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:42 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:42 radio go-librespot[1173]: Librespot-go daemon starting... Nov 28 14:08:42 radio go-librespot[1173]: time="2025-11-28T14:08:42+01:00" level=info msg="generated new device id: cd6c882ac06cbfe43c81b36b6111d8f78505e638" Nov 28 14:08:42 radio go-librespot[1173]: time="2025-11-28T14:08:42+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:42 radio go-librespot[1173]: time="2025-11-28T14:08:42+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:42 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:42 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:42 radio ntpd[747]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Nov 28 14:08:43 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:43 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:44 radio ntpd[747]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Nov 28 14:08:45 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:45 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Nov 28 14:08:45 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:45 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:45 radio go-librespot[1181]: Librespot-go daemon starting... Nov 28 14:08:45 radio go-librespot[1181]: time="2025-11-28T14:08:45+01:00" level=info msg="generated new device id: 9f47a0f479a5b6b87bd5ae0e449925cd9a709f07" Nov 28 14:08:45 radio go-librespot[1181]: time="2025-11-28T14:08:45+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:45 radio go-librespot[1181]: time="2025-11-28T14:08:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:45 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:45 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:46 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:46 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:48 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:48 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Nov 28 14:08:48 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:48 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:48 radio go-librespot[1188]: Librespot-go daemon starting... Nov 28 14:08:48 radio go-librespot[1188]: time="2025-11-28T14:08:48+01:00" level=info msg="generated new device id: d0890736b1776ff3b67473dbea5c4e9f16694962" Nov 28 14:08:48 radio go-librespot[1188]: time="2025-11-28T14:08:48+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:48 radio go-librespot[1188]: time="2025-11-28T14:08:48+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:48 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:48 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:49 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:49 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:50 radio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:50 radio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Nov 28 14:08:52 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:52 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Nov 28 14:08:52 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:52 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:52 radio go-librespot[1195]: Librespot-go daemon starting... Nov 28 14:08:52 radio go-librespot[1195]: time="2025-11-28T14:08:52+01:00" level=info msg="generated new device id: b1b0133cfb9e5e847437b6e98f89d0c07c9b4bb1" Nov 28 14:08:52 radio go-librespot[1195]: time="2025-11-28T14:08:52+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:52 radio go-librespot[1195]: time="2025-11-28T14:08:52+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:52 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:52 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:52 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:52 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:55 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:55 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Nov 28 14:08:55 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:55 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:55 radio go-librespot[1202]: Librespot-go daemon starting... Nov 28 14:08:55 radio go-librespot[1202]: time="2025-11-28T14:08:55+01:00" level=info msg="generated new device id: 486bd5d378d648f5882b558092a868c5291b7182" Nov 28 14:08:55 radio go-librespot[1202]: time="2025-11-28T14:08:55+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:55 radio go-librespot[1202]: time="2025-11-28T14:08:55+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:55 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:55 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:55 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:55 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:08:58 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:08:58 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Nov 28 14:08:58 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:08:58 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:08:58 radio go-librespot[1210]: Librespot-go daemon starting... Nov 28 14:08:58 radio go-librespot[1210]: time="2025-11-28T14:08:58+01:00" level=info msg="generated new device id: 44502768efc6b03119fce23e53ca8e33ee2e8e09" Nov 28 14:08:58 radio go-librespot[1210]: time="2025-11-28T14:08:58+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:08:58 radio go-librespot[1210]: time="2025-11-28T14:08:58+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:08:58 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:08:58 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:08:58 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:08:58 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:09:01 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:09:01 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Nov 28 14:09:01 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:09:01 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:09:01 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:09:01 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:09:01 radio go-librespot[1217]: Librespot-go daemon starting... Nov 28 14:09:01 radio go-librespot[1217]: time="2025-11-28T14:09:01+01:00" level=info msg="generated new device id: 052c34d325333c94847274d5714db9312764f1ec" Nov 28 14:09:01 radio go-librespot[1217]: time="2025-11-28T14:09:01+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:09:01 radio go-librespot[1217]: time="2025-11-28T14:09:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:09:01 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:09:01 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:09:02 radio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off Nov 28 14:09:02 radio ifplugd(eth0)[766]: Link beat detected. Nov 28 14:09:02 radio ifplugd(eth0)[766]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Nov 28 14:09:02 radio dhcpcd[1244]: DUID 00:01:00:01:2e:31:51:dd:d8:3a:dd:85:6e:80 Nov 28 14:09:02 radio dhcpcd[1244]: eth0: IAID 01:33:6b:9f Nov 28 14:09:02 radio dhcpcd[1244]: eth0: adding address fe80::e65f:1ff:fe33:6b9f Nov 28 14:09:02 radio dhcpcd[1244]: ipv6_addaddr1: Permission denied Nov 28 14:09:02 radio ifplugd(eth0)[766]: client: DUID 00:01:00:01:2e:31:51:dd:d8:3a:dd:85:6e:80 Nov 28 14:09:02 radio ifplugd(eth0)[766]: client: eth0: IAID 01:33:6b:9f Nov 28 14:09:02 radio ifplugd(eth0)[766]: client: eth0: adding address fe80::e65f:1ff:fe33:6b9f Nov 28 14:09:02 radio ifplugd(eth0)[766]: client: ipv6_addaddr1: Permission denied Nov 28 14:09:03 radio dhcpcd[1244]: eth0: soliciting an IPv6 router Nov 28 14:09:03 radio ifplugd(eth0)[766]: client: eth0: soliciting an IPv6 router Nov 28 14:09:03 radio dhcpcd[1244]: eth0: soliciting a DHCP lease Nov 28 14:09:03 radio ifplugd(eth0)[766]: client: eth0: soliciting a DHCP lease Nov 28 14:09:04 radio systemd[1]: nmbd.service: Start operation timed out. Terminating. Nov 28 14:09:04 radio systemd[1]: nmbd.service: Main process exited, code=killed, status=15/TERM Nov 28 14:09:04 radio systemd[1]: nmbd.service: Failed with result 'timeout'. Nov 28 14:09:04 radio systemd[1]: Failed to start Samba NMB Daemon. Nov 28 14:09:04 radio systemd[1]: Starting Samba Winbind Daemon... Nov 28 14:09:04 radio winbindd[1247]: [2025/11/28 14:09:04.571931, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Nov 28 14:09:04 radio winbindd[1247]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Nov 28 14:09:04 radio winbindd[1247]: [2025/11/28 14:09:04.584006, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 28 14:09:04 radio winbindd[1247]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Nov 28 14:09:04 radio systemd[1]: Started Samba Winbind Daemon. Nov 28 14:09:04 radio systemd[1]: Starting Samba SMB Daemon... Nov 28 14:09:04 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:09:04 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:09:04 radio smbd[1252]: [2025/11/28 14:09:04.958178, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 28 14:09:04 radio systemd[1]: Started Samba SMB Daemon. Nov 28 14:09:04 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:09:04 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Nov 28 14:09:04 radio smbd[1252]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Nov 28 14:09:04 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:09:05 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:09:05 radio systemd[1]: Reached target Multi-User System. Nov 28 14:09:05 radio systemd[1]: Reached target Graphical Interface. Nov 28 14:09:05 radio go-librespot[1258]: Librespot-go daemon starting... Nov 28 14:09:05 radio systemd[1]: Starting Update UTMP about System Runlevel Changes... Nov 28 14:09:05 radio go-librespot[1258]: time="2025-11-28T14:09:05+01:00" level=info msg="generated new device id: 68cbcfed0b23430be7f1fd9d9b4758ec61c2947a" Nov 28 14:09:05 radio go-librespot[1258]: time="2025-11-28T14:09:05+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:09:05 radio go-librespot[1258]: time="2025-11-28T14:09:05+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:09:05 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:09:05 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:09:05 radio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Nov 28 14:09:05 radio systemd[1]: Started Update UTMP about System Runlevel Changes. Nov 28 14:09:05 radio systemd[1]: Startup finished in 15.364s (kernel) + 1min 38.955s (userspace) = 1min 54.320s. Nov 28 14:09:07 radio dhcpcd[1244]: eth0: offered 192.168.14.10 from 192.168.14.1 Nov 28 14:09:07 radio ifplugd(eth0)[766]: client: eth0: offered 192.168.14.10 from 192.168.14.1 Nov 28 14:09:07 radio dhcpcd[1244]: eth0: probing address 192.168.14.10/24 Nov 28 14:09:07 radio ifplugd(eth0)[766]: client: eth0: probing address 192.168.14.10/24 Nov 28 14:09:07 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:09:07 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:09:08 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:09:08 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Nov 28 14:09:08 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:09:08 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:09:08 radio go-librespot[1268]: Librespot-go daemon starting... Nov 28 14:09:08 radio go-librespot[1268]: time="2025-11-28T14:09:08+01:00" level=info msg="generated new device id: 2c3daa5b3b3f0f7235cf702bb39f53061b137847" Nov 28 14:09:08 radio go-librespot[1268]: time="2025-11-28T14:09:08+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:09:08 radio go-librespot[1268]: time="2025-11-28T14:09:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:09:08 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:09:08 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:09:10 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:09:10 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:09:11 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:09:11 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Nov 28 14:09:11 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:09:11 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:09:11 radio go-librespot[1275]: Librespot-go daemon starting... Nov 28 14:09:11 radio go-librespot[1275]: time="2025-11-28T14:09:11+01:00" level=info msg="generated new device id: 15fa0fecb4134f37ff4c4ee9611f3013fb83ea0c" Nov 28 14:09:11 radio go-librespot[1275]: time="2025-11-28T14:09:11+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:09:11 radio go-librespot[1275]: time="2025-11-28T14:09:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 28 14:09:11 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 28 14:09:11 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 14:09:12 radio dhcpcd[1244]: eth0: leased 192.168.14.10 for infinity Nov 28 14:09:12 radio ifplugd(eth0)[766]: client: eth0: leased 192.168.14.10 for infinity Nov 28 14:09:12 radio avahi-daemon[620]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.14.10. Nov 28 14:09:12 radio dhcpcd[1244]: eth0: adding route to 192.168.14.0/24 Nov 28 14:09:12 radio avahi-daemon[620]: New relevant interface eth0.IPv4 for mDNS. Nov 28 14:09:12 radio dhcpcd[1244]: eth0: adding default route via 192.168.14.1 Nov 28 14:09:12 radio avahi-daemon[620]: Registering new address record for 192.168.14.10 on eth0.IPv4. Nov 28 14:09:12 radio ifplugd(eth0)[766]: client: eth0: adding route to 192.168.14.0/24 Nov 28 14:09:12 radio ifplugd(eth0)[766]: client: eth0: adding default route via 192.168.14.1 Nov 28 14:09:12 radio dhcpcd[1244]: forked to background, child pid 1303 Nov 28 14:09:12 radio ifplugd(eth0)[766]: client: forked to background, child pid 1303 Nov 28 14:09:12 radio ifplugd(eth0)[766]: Program executed successfully. Nov 28 14:09:13 radio volumio[798]: info: Discovery: adding 3db0e5e4-dcd6-4753-8277-4db1a312c31e Nov 28 14:09:13 radio volumio[798]: info: Discovery: Found device radio Nov 28 14:09:13 radio volumio[798]: info: CoreCommandRouter::volumioGetState Nov 28 14:09:13 radio volumio[798]: info: CorePlayQueue::getTrack 0 Nov 28 14:09:13 radio ntpd[747]: Listen normally on 3 eth0 192.168.14.10:123 Nov 28 14:09:13 radio ntpd[747]: new interface(s) found: waking up resolver Nov 28 14:09:13 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:09:13 radio volumio[798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 28 14:09:14 radio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 14:09:14 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Nov 28 14:09:14 radio systemd[1]: Stopped go-librespot Daemon. Nov 28 14:09:14 radio systemd[1]: Started go-librespot Daemon. Nov 28 14:09:14 radio go-librespot[1329]: Librespot-go daemon starting... Nov 28 14:09:14 radio go-librespot[1329]: time="2025-11-28T14:09:14+01:00" level=info msg="generated new device id: 85e556b66c89c4ecba8f486347583501793ce495" Nov 28 14:09:14 radio go-librespot[1329]: time="2025-11-28T14:09:14+01:00" level=debug msg="stored credentials found for 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:09:14 radio go-librespot[1329]: time="2025-11-28T14:09:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 28 14:09:14 radio go-librespot[1329]: time="2025-11-28T14:09:14+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 28 14:09:14 radio go-librespot[1329]: time="2025-11-28T14:09:14+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 28 14:09:14 radio go-librespot[1329]: time="2025-11-28T14:09:14+01:00" level=debug msg="zeroconf server listening on port 35621" Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Nov 28 14:09:15 radio volumio[798]: info: Adding plugin bluetooth to MyMusic Plugins Nov 28 14:09:15 radio volumio[798]: info: Adding plugin multiroom to MyMusic Plugins Nov 28 14:09:15 radio volumio[798]: info: Adding plugin metavolumio to MyMusic Plugins Nov 28 14:09:15 radio volumio[798]: info: Adding plugin cd_controller to MyMusic Plugins Nov 28 14:09:15 radio volumio[798]: info: Adding plugin smart_inputs to MyMusic Plugins Nov 28 14:09:15 radio volumio[798]: info: Adding plugin tidalconnect to MyMusic Plugins Nov 28 14:09:15 radio volumio[798]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Nov 28 14:09:15 radio go-librespot[1329]: time="2025-11-28T14:09:15+01:00" level=debug msg="obtained new client token: AADuHbp1oMUPxIeeK56F4WjqovR/vDpI6F34602hw6a+x97QpnLUe3umLG4trhJ/M6M+Fb7aAI35zMicEnmDWya+d20j56VlpGTGPBxcW2Kd6Own3No++fPNWyZ7pX8tIIQ5AYcnA0UJb83pn3tZ1rPuuz7r/71kHLufWje55hWMsAY8GXwz9EpdFquTaKyZNY3ITeEv5qAq3buzl5ZvxMf1Wzx4e8E99X9Kf3RCTtHSriWGr7fshq+bc7w=" Nov 28 14:09:15 radio go-librespot[1329]: time="2025-11-28T14:09:15+01:00" level=debug msg="completed keyexchange" Nov 28 14:09:16 radio volumio[798]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Nov 28 14:09:16 radio volumio[798]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Nov 28 14:09:16 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 14:09:16 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 14:09:16 radio volumio[798]: info: Starting MyVolumio Remote Streaming Endpoints Nov 28 14:09:16 radio volumio[798]: info: MyVolumio login type: Token Nov 28 14:09:16 radio go-librespot[1329]: time="2025-11-28T14:09:16+01:00" level=debug msg="completed challenge" Nov 28 14:09:16 radio volumio[798]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Nov 28 14:09:16 radio volumio[798]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Nov 28 14:09:16 radio go-librespot[1329]: time="2025-11-28T14:09:16+01:00" level=debug msg="authenticated as 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:09:16 radio go-librespot[1329]: time="2025-11-28T14:09:16+01:00" level=debug msg="authenticated as 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:09:16 radio go-librespot[1329]: time="2025-11-28T14:09:16+01:00" level=debug msg="dealer connection opened" Nov 28 14:09:16 radio go-librespot[1329]: time="2025-11-28T14:09:16+01:00" level=debug msg="initializing zeroconf session, username: 4ayp0v3menlncwu6lo0jvjmje" Nov 28 14:09:16 radio go-librespot[1329]: time="2025-11-28T14:09:16+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Nov 28 14:09:16 radio go-librespot[1329]: time="2025-11-28T14:09:16+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Nov 28 14:09:16 radio go-librespot[1329]: time="2025-11-28T14:09:16+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Nov 28 14:09:16 radio go-librespot[1329]: time="2025-11-28T14:09:16+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Nov 28 14:09:16 radio go-librespot[1329]: time="2025-11-28T14:09:16+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Nov 28 14:09:16 radio go-librespot[1329]: time="2025-11-28T14:09:16+01:00" level=debug msg="autoplay enabled: false" Nov 28 14:09:16 radio go-librespot[1329]: time="2025-11-28T14:09:16+01:00" level=debug msg="received connection id: MTJjYzEwN2QtYmM1Mi00MmJlLWEwYzEtNmQ5ODUwMDNiZWQ4K2RlYWxlcit0Y3A6Ly8wYWIxNTA0Mi5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArQUE1RTMyQkFEQzI0N0NERDM2MEUzNjcxRjQ2OEYzMDQ2MUM5NzE1NjNGOEFFNkVGMTc4MDc5NDg0MEU2RUZCMg==" Nov 28 14:09:16 radio go-librespot[1329]: time="2025-11-28T14:09:16+01:00" level=debug msg="put connect state because NEW_DEVICE" Nov 28 14:09:16 radio go-librespot[1329]: time="2025-11-28T14:09:16+01:00" level=debug msg="skipping dealer message" uri="ap://product-state-update" Nov 28 14:09:16 radio go-librespot[1329]: time="2025-11-28T14:09:16+01:00" level=debug msg="autoplay enabled: false" Nov 28 14:09:17 radio volumio[798]: info: Starting Streaming Service Transparent Proxy Nov 28 14:09:17 radio volumio[798]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 28 14:09:17 radio volumio[798]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 28 14:09:17 radio volumio[798]: info: Streaming services startup Nov 28 14:09:17 radio volumio[798]: info: Starting Streaming Daemon Nov 28 14:09:17 radio sudo[1344]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 28 14:09:17 radio sudo[1344]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 14:09:17 radio volumio[798]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Nov 28 14:09:17 radio sudo[1344]: pam_unix(sudo:session): session closed for user root Nov 28 14:09:17 radio volumio[798]: info: Initializing connection to go-librespot Websocket Nov 28 14:09:17 radio volumio[798]: error: Cannot start Volumio Streaming Daemon Nov 28 14:09:17 radio volumio[798]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 28 14:09:17 radio volumio[798]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 28 14:09:17 radio go-librespot[1329]: time="2025-11-28T14:09:17+01:00" level=debug msg="new websocket client" Nov 28 14:09:17 radio volumio[798]: info: Connection to go-librespot Websocket established Nov 28 14:09:17 radio volumio[798]: error: MyVolumio Custom Token format not valid, refreshing it Nov 28 14:09:17 radio volumio[798]: STREAMING PROXY: Starting server on port 3245 Nov 28 14:09:17 radio volumio[798]: Node JS runtime: 14 Nov 28 14:09:18 radio kernel: usb 2-2: USB disconnect, device number 2 Nov 28 14:09:18 radio kernel: device offline error, dev sda, sector 0 op 0x1:(WRITE) flags 0x800 phys_seg 0 prio class 2 Nov 28 14:09:18 radio kernel: device offline error, dev sda, sector 11742218 op 0x1:(WRITE) flags 0x0 phys_seg 2 prio class 2 Nov 28 14:09:18 radio kernel: EXT4-fs warning (device sda3): ext4_end_bio:347: I/O error 17 writing to inode 2390469 starting block 5871109) Nov 28 14:09:18 radio kernel: Buffer I/O error on device sda3, logical block 3137029 Nov 28 14:09:18 radio kernel: Buffer I/O error on device sda3, logical block 3137030 Nov 28 14:09:18 radio kernel: Buffer I/O error on device sda3, logical block 3137031 Nov 28 14:09:18 radio kernel: Buffer I/O error on device sda3, logical block 3137032 Nov 28 14:09:18 radio kernel: Buffer I/O error on device sda3, logical block 3137033 Nov 28 14:09:18 radio kernel: device offline error, dev sda, sector 5486298 op 0x1:(WRITE) flags 0x0 phys_seg 3 prio class 2 Nov 28 14:09:18 radio kernel: EXT4-fs warning (device sda3): ext4_end_bio:347: I/O error 17 writing to inode 2390470 starting block 2743149) Nov 28 14:09:18 radio kernel: Buffer I/O error on device sda3, logical block 9069 Nov 28 14:09:18 radio kernel: Buffer I/O error on device sda3, logical block 9070 Nov 28 14:09:18 radio kernel: Buffer I/O error on device sda3, logical block 9071 Nov 28 14:09:18 radio kernel: Buffer I/O error on device sda3, logical block 9072 Nov 28 14:09:18 radio kernel: Buffer I/O error on device sda3, logical block 9073 Nov 28 14:09:18 radio kernel: device offline error, dev sda, sector 5488114 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 2 Nov 28 14:09:18 radio kernel: EXT4-fs warning (device sda3): ext4_end_bio:347: I/O error 17 writing to inode 2390470 starting block 2744057) Nov 28 14:09:18 radio kernel: device offline error, dev sda, sector 11742228 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 2 Nov 28 14:09:18 radio kernel: EXT4-fs warning (device sda3): ext4_end_bio:347: I/O error 17 writing to inode 2393046 starting block 5871114) Nov 28 14:09:18 radio kernel: device offline error, dev sda, sector 5468258 op 0x1:(WRITE) flags 0x3000 phys_seg 1 prio class 2 Nov 28 14:09:18 radio kernel: Buffer I/O error on dev sda3, logical block 49, lost async page write Nov 28 14:09:18 radio kernel: device offline error, dev sda, sector 5468314 op 0x1:(WRITE) flags 0x3000 phys_seg 1 prio class 2 Nov 28 14:09:18 radio kernel: Buffer I/O error on dev sda3, logical block 77, lost async page write Nov 28 14:09:18 radio kernel: device offline error, dev sda, sector 17788950 op 0x1:(WRITE) flags 0x3000 phys_seg 1 prio class 2 Nov 28 14:09:18 radio kernel: JBD2: Detected IO errors while flushing file data on sda3-8 Nov 28 14:09:18 radio kernel: Buffer I/O error on dev sda3, logical block 6160395, lost async page write Nov 28 14:09:18 radio kernel: device offline error, dev sda, sector 5599962 op 0x1:(WRITE) flags 0x800 phys_seg 13 prio class 2 Nov 28 14:09:18 radio kernel: Aborting journal on device sda3-8. Nov 28 14:09:18 radio kernel: device offline error, dev sda, sector 25128966 op 0x1:(WRITE) flags 0x3000 phys_seg 1 prio class 2 Nov 28 14:09:18 radio kernel: Buffer I/O error on dev sda3, logical block 9830403, lost async page write Nov 28 14:09:18 radio kernel: Buffer I/O error on dev sda3, logical block 9830417, lost async page write Nov 28 14:09:18 radio kernel: Buffer I/O error on dev sda3, logical block 9830418, lost async page write Nov 28 14:09:18 radio kernel: Buffer I/O error on dev sda3, logical block 65537, lost sync page write Nov 28 14:09:18 radio kernel: JBD2: I/O error when updating journal superblock for sda3-8. Nov 28 14:09:18 radio volumio[798]: info: Partition removed: {"syspath":"/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-2/2-2:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","ACTION":"remove","DEVLINKS":"/dev/disk/by-id/usb-ADATA_SU_650_925633A010051-0:0-part1 /dev/disk/by-label/boot /dev/disk/by-path/platform-fd500000.pcie-pci-0000:01:00.0-usb-0:2:1.0-scsi-0:0:0:0-part1 /dev/disk/by-partuuid/53ce6763-01 /dev/disk/by-uuid/41CA-9A8B","DEVNAME":"/dev/sda1","DEVPATH":"/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-2/2-2:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","DEVTYPE":"partition","DISKSEQ":"25","ID_BUS":"usb","ID_FS_LABEL":"boot","ID_FS_LABEL_ENC":"boot","ID_FS_TYPE":"vfat","ID_FS_USAGE":"filesystem","ID_FS_UUID":"41CA-9A8B","ID_FS_UUID_ENC":"41CA-9A8B","ID_FS_VERSION":"FAT32","ID_INSTANCE":"0:0","ID_MODEL":"650","ID_MODEL_ENC":"650\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20","ID_MODEL_ID":"7788","ID_PART_ENTRY_DISK":"8:0","ID_PART_ENTRY_FLAGS":"0x80","ID_PART_ENTRY_NUMBER":"1","ID_PART_ENTRY_OFFSET":"1","ID_PART_ENTRY_SCHEME":"dos","ID_PART_ENTRY_SIZE":"187500","ID_PART_ENTRY_TYPE":"0xc","ID_PART_ENTRY_UUID":"53ce6763-01","ID_PART_TABLE_TYPE":"dos","ID_PART_TABLE_UUID":"53ce6763","ID_PATH":"platform-fd500000.pcie-pci-0000:01:00.0-usb-0:2:1.0-scsi-0:0:0:0","ID_PATH_TAG":"platform-fd500000_pcie-pci-0000_01_00_0-usb-0_2_1_0-scsi-0_0_0_0","ID_REVISION":"0114","ID_SERIAL":"ADATA_SU_650_925633A010051-0:0","ID_SERIAL_SHORT":"925633A010051","ID_TYPE":"disk","ID_USB_DRIVER":"usb-storage","ID_USB_INTERFACES":":080650:080662:","ID_USB_INTERFACE_NUM":"00","ID_VENDOR":"ADATA_SU","ID_VENDOR_ENC":"ADATA\\x20SU","ID_VENDOR_ID":"357d","MAJOR":"8","MINOR":"1","PARTN":"1","SEQNUM":"2304","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"4281707"} Nov 28 14:09:18 radio systemd[1]: Stopped target Local File Systems. Nov 28 14:09:18 radio volumio[798]: info: Partition removed: {"syspath":"/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-2/2-2:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda2","ACTION":"remove","DEVLINKS":"/dev/disk/by-label/volumio /dev/disk/by-uuid/0c3a77ec-ae84-4f1b-8028-c61cc251ffe5 /dev/disk/by-path/platform-fd500000.pcie-pci-0000:01:00.0-usb-0:2:1.0-scsi-0:0:0:0-part2 /dev/disk/by-partuuid/53ce6763-02 /dev/disk/by-id/usb-ADATA_SU_650_925633A010051-0:0-part2","DEVNAME":"/dev/sda2","DEVPATH":"/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-2/2-2:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda2","DEVTYPE":"partition","DISKSEQ":"25","ID_BUS":"usb","ID_FS_LABEL":"volumio","ID_FS_LABEL_ENC":"volumio","ID_FS_TYPE":"ext4","ID_FS_USAGE":"filesystem","ID_FS_UUID":"0c3a77ec-ae84-4f1b-8028-c61cc251ffe5","ID_FS_UUID_ENC":"0c3a77ec-ae84-4f1b-8028-c61cc251ffe5","ID_FS_VERSION":"1.0","ID_INSTANCE":"0:0","ID_MODEL":"650","ID_MODEL_ENC":"650\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20","ID_MODEL_ID":"7788","ID_PART_ENTRY_DISK":"8:0","ID_PART_ENTRY_NUMBER":"2","ID_PART_ENTRY_OFFSET":"188416","ID_PART_ENTRY_SCHEME":"dos","ID_PART_ENTRY_SIZE":"5279744","ID_PART_ENTRY_TYPE":"0x83","ID_PART_ENTRY_UUID":"53ce6763-02","ID_PART_TABLE_TYPE":"dos","ID_PART_TABLE_UUID":"53ce6763","ID_PATH":"platform-fd500000.pcie-pci-0000:01:00.0-usb-0:2:1.0-scsi-0:0:0:0","ID_PATH_TAG":"platform-fd500000_pcie-pci-0000_01_00_0-usb-0_2_1_0-scsi-0_0_0_0","ID_REVISION":"0114","ID_SERIAL":"ADATA_SU_650_925633A010051-0:0","ID_SERIAL_SHORT":"925633A010051","ID_TYPE":"disk","ID_USB_DRIVER":"usb-storage","ID_USB_INTERFACES":":080650:080662:","ID_USB_INTERFACE_NUM":"00","ID_VENDOR":"ADATA_SU","ID_VENDOR_ENC":"ADATA\\x20SU","ID_VENDOR_ID":"357d","MAJOR":"8","MINOR":"2","PARTN":"2","SEQNUM":"2305","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"4277873"} Nov 28 14:09:18 radio kernel: Buffer I/O error on dev sda3, logical block 9830437, lost async page write Nov 28 14:09:18 radio kernel: Buffer I/O error on dev sda3, logical block 9830438, lost async page write Nov 28 14:09:18 radio kernel: Buffer I/O error on dev sda3, logical block 9830439, lost async page write Nov 28 14:09:18 radio volumio[798]: info: Partition removed: {"syspath":"/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-2/2-2:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda3","ACTION":"remove","DEVLINKS":"/dev/disk/by-id/usb-ADATA_SU_650_925633A010051-0:0-part3 /dev/disk/by-uuid/0324d53a-d066-482b-b659-eb98af2b49e7 /dev/disk/by-label/volumio_data /dev/disk/by-path/platform-fd500000.pcie-pci-0000:01:00.0-usb-0:2:1.0-scsi-0:0:0:0-part3 /dev/disk/by-partuuid/53ce6763-03","DEVNAME":"/dev/sda3","DEVPATH":"/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-2/2-2:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda3","DEVTYPE":"partition","DISKSEQ":"25","ID_BUS":"usb","ID_FS_LABEL":"volumio_data","ID_FS_LABEL_ENC":"volumio_data","ID_FS_TYPE":"ext4","ID_FS_USAGE":"filesystem","ID_FS_UUID":"0324d53a-d066-482b-b659-eb98af2b49e7","ID_FS_UUID_ENC":"0324d53a-d066-482b-b659-eb98af2b49e7","ID_FS_VERSION":"1.0","ID_INSTANCE":"0:0","ID_MODEL":"650","ID_MODEL_ENC":"650\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20","ID_MODEL_ID":"7788","ID_PART_ENTRY_DISK":"8:0","ID_PART_ENTRY_NUMBER":"3","ID_PART_ENTRY_OFFSET":"5468160","ID_PART_ENTRY_SCHEME":"dos","ID_PART_ENTRY_SIZE":"228973247","ID_PART_ENTRY_TYPE":"0x83","ID_PART_ENTRY_UUID":"53ce6763-03","ID_PART_TABLE_TYPE":"dos","ID_PART_TABLE_UUID":"53ce6763","ID_PATH":"platform-fd500000.pcie-pci-0000:01:00.0-usb-0:2:1.0-scsi-0:0:0:0","ID_PATH_TAG":"platform-fd500000_pcie-pci-0000_01_00_0-usb-0_2_1_0-scsi-0_0_0_0","ID_REVISION":"0114","ID_SERIAL":"ADATA_SU_650_925633A010051-0:0","ID_SERIAL_SHORT":"925633A010051","ID_TYPE":"disk","ID_USB_DRIVER":"usb-storage","ID_USB_INTERFACES":":080650:080662:","ID_USB_INTERFACE_NUM":"00","ID_VENDOR":"ADATA_SU","ID_VENDOR_ENC":"ADATA\\x20SU","ID_VENDOR_ID":"357d","MAJOR":"8","MINOR":"3","PARTN":"3","SEQNUM":"2306","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"4278125"} Nov 28 14:09:18 radio volumio[798]: info: MyVolumio login type: Token Nov 28 14:09:18 radio systemd[1]: Unmounting /boot... Nov 28 14:09:18 radio systemd[1354]: boot.mount: Failed to execute command: Input/output error Nov 28 14:09:18 radio systemd[1354]: boot.mount: Failed at step EXEC spawning /bin/umount: Input/output error Nov 28 14:09:18 radio systemd[1]: boot.mount: Mount process exited, code=exited, status=203/EXEC Nov 28 14:09:18 radio systemd[1]: Failed unmounting /boot. Nov 28 14:09:18 radio systemd[1]: boot.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-41CA\x2d9A8B.device. Stopping, too. Nov 28 14:09:18 radio systemd[1]: Unmounting /boot... Nov 28 14:09:18 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2393027: comm (umount): reading directory lblock 0 Nov 28 14:09:18 radio systemd[1355]: boot.mount: Failed to execute command: Input/output error Nov 28 14:09:18 radio systemd[1355]: boot.mount: Failed at step EXEC spawning /bin/umount: Input/output error Nov 28 14:09:18 radio systemd[1]: boot.mount: Mount process exited, code=exited, status=203/EXEC Nov 28 14:09:18 radio systemd[1]: Failed unmounting /boot. Nov 28 14:09:18 radio systemd[1]: boot.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-41CA\x2d9A8B.device. Stopping, too. Nov 28 14:09:18 radio systemd[1]: Unmounting /boot... Nov 28 14:09:18 radio systemd[1356]: boot.mount: Failed to execute command: Input/output error Nov 28 14:09:18 radio systemd[1356]: boot.mount: Failed at step EXEC spawning /bin/umount: Input/output error Nov 28 14:09:18 radio systemd[1]: boot.mount: Mount process exited, code=exited, status=203/EXEC Nov 28 14:09:18 radio systemd[1]: Failed unmounting /boot. Nov 28 14:09:18 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2393027: comm (umount): reading directory lblock 0 Nov 28 14:09:18 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2393027: comm (umount): reading directory lblock 0 Nov 28 14:09:18 radio systemd[1]: boot.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-41CA\x2d9A8B.device. Stopping, too. Nov 28 14:09:18 radio systemd[1]: Unmounting /boot... Nov 28 14:09:18 radio systemd[1357]: boot.mount: Failed to execute command: Input/output error Nov 28 14:09:18 radio systemd[1357]: boot.mount: Failed at step EXEC spawning /bin/umount: Input/output error Nov 28 14:09:18 radio systemd[1]: boot.mount: Mount process exited, code=exited, status=203/EXEC Nov 28 14:09:18 radio systemd[1]: Failed unmounting /boot. Nov 28 14:09:18 radio systemd[1]: boot.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-41CA\x2d9A8B.device. Stopping, too. Nov 28 14:09:18 radio systemd[1]: Unmounting /boot... Nov 28 14:09:18 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2393027: comm (umount): reading directory lblock 0 Nov 28 14:09:18 radio systemd[1358]: boot.mount: Failed to execute command: Input/output error Nov 28 14:09:18 radio systemd[1358]: boot.mount: Failed at step EXEC spawning /bin/umount: Input/output error Nov 28 14:09:18 radio systemd[1]: boot.mount: Mount process exited, code=exited, status=203/EXEC Nov 28 14:09:18 radio systemd[1]: Failed unmounting /boot. Nov 28 14:09:18 radio systemd[1]: boot.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-41CA\x2d9A8B.device. Stopping, too. Nov 28 14:09:18 radio systemd[1]: Unmounting /boot... Nov 28 14:09:18 radio systemd[1359]: boot.mount: Failed to execute command: Input/output error Nov 28 14:09:18 radio systemd[1359]: boot.mount: Failed at step EXEC spawning /bin/umount: Input/output error Nov 28 14:09:18 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2393027: comm (umount): reading directory lblock 0 Nov 28 14:09:18 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2393027: comm (umount): reading directory lblock 0 Nov 28 14:09:18 radio systemd[1]: boot.mount: Mount process exited, code=exited, status=203/EXEC Nov 28 14:09:18 radio systemd[1]: Failed unmounting /boot. Nov 28 14:09:18 radio systemd[1]: boot.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-41CA\x2d9A8B.device. Stopping, too. Nov 28 14:09:18 radio systemd[1]: Unmounting /boot... Nov 28 14:09:18 radio systemd[1360]: boot.mount: Failed to execute command: Input/output error Nov 28 14:09:18 radio systemd[1360]: boot.mount: Failed at step EXEC spawning /bin/umount: Input/output error Nov 28 14:09:18 radio systemd[1]: boot.mount: Mount process exited, code=exited, status=203/EXEC Nov 28 14:09:18 radio systemd[1]: Failed unmounting /boot. Nov 28 14:09:18 radio systemd[1]: boot.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-41CA\x2d9A8B.device. Stopping, too. Nov 28 14:09:18 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2393027: comm (umount): reading directory lblock 0 Nov 28 14:09:18 radio systemd[1]: Unmounting /boot... Nov 28 14:09:18 radio systemd[1361]: boot.mount: Failed to execute command: Input/output error Nov 28 14:09:18 radio systemd[1361]: boot.mount: Failed at step EXEC spawning /bin/umount: Input/output error Nov 28 14:09:18 radio systemd[1]: boot.mount: Mount process exited, code=exited, status=203/EXEC Nov 28 14:09:18 radio systemd[1]: Failed unmounting /boot. Nov 28 14:09:18 radio systemd[1]: boot.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-41CA\x2d9A8B.device. Stopping, too. Nov 28 14:09:18 radio systemd[1]: Unmounting /boot... Nov 28 14:09:18 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2393027: comm (umount): reading directory lblock 0 Nov 28 14:09:18 radio systemd[1362]: boot.mount: Failed to execute command: Input/output error Nov 28 14:09:18 radio systemd[1362]: boot.mount: Failed at step EXEC spawning /bin/umount: Input/output error Nov 28 14:09:18 radio systemd[1]: boot.mount: Mount process exited, code=exited, status=203/EXEC Nov 28 14:09:18 radio systemd[1]: Failed unmounting /boot. Nov 28 14:09:18 radio systemd[1]: boot.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-41CA\x2d9A8B.device. Stopping, too. Nov 28 14:09:18 radio systemd[1]: Unmounting /boot... Nov 28 14:09:18 radio systemd[1363]: boot.mount: Failed to execute command: Input/output error Nov 28 14:09:18 radio systemd[1363]: boot.mount: Failed at step EXEC spawning /bin/umount: Input/output error Nov 28 14:09:18 radio systemd[1]: boot.mount: Mount process exited, code=exited, status=203/EXEC Nov 28 14:09:18 radio systemd[1]: Failed unmounting /boot. Nov 28 14:09:18 radio systemd[1]: boot.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-41CA\x2d9A8B.device. Stopping, too. Nov 28 14:09:18 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2393027: comm (umount): reading directory lblock 0 Nov 28 14:09:18 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2393027: comm (umount): reading directory lblock 0 Nov 28 14:09:18 radio systemd[1]: Unmounting /boot... Nov 28 14:09:18 radio systemd[1364]: boot.mount: Failed to execute command: Input/output error Nov 28 14:09:18 radio systemd[1364]: boot.mount: Failed at step EXEC spawning /bin/umount: Input/output error Nov 28 14:09:18 radio systemd[1]: boot.mount: Mount process exited, code=exited, status=203/EXEC Nov 28 14:09:18 radio systemd[1]: Failed unmounting /boot. Nov 28 14:09:18 radio systemd[1]: boot.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-41CA\x2d9A8B.device. Stopping, too. Nov 28 14:09:18 radio systemd[1]: Unmounting /boot... Nov 28 14:09:18 radio systemd[1365]: boot.mount: Failed to execute command: Input/output error Nov 28 14:09:18 radio systemd[1365]: boot.mount: Failed at step EXEC spawning /bin/umount: Input/output error Nov 28 14:09:18 radio systemd[1]: boot.mount: Mount process exited, code=exited, status=203/EXEC Nov 28 14:09:18 radio systemd[1]: Failed unmounting /boot. Nov 28 14:09:18 radio systemd[1]: boot.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-41CA\x2d9A8B.device. Stopping, too. Nov 28 14:09:18 radio systemd[1]: Unmounting /boot... Nov 28 14:09:18 radio systemd[1366]: boot.mount: Failed to execute command: Input/output error Nov 28 14:09:18 radio systemd[1366]: boot.mount: Failed at step EXEC spawning /bin/umount: Input/output error Nov 28 14:09:18 radio kernel: sd 0:0:0:0: [sda] Synchronizing SCSI cache Nov 28 14:09:18 radio kernel: sd 0:0:0:0: [sda] Synchronize Cache(10) failed: Result: hostbyte=0x01 driverbyte=DRIVER_OK Nov 28 14:09:18 radio systemd[1]: boot.mount: Mount process exited, code=exited, status=203/EXEC Nov 28 14:09:18 radio systemd[1]: Failed unmounting /boot. Nov 28 14:09:18 radio systemd[1]: boot.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-41CA\x2d9A8B.device. Stopping, too. Nov 28 14:09:18 radio systemd[1]: Unmounting /boot... Nov 28 14:09:18 radio systemd[1367]: boot.mount: Failed to execute command: Input/output error Nov 28 14:09:18 radio systemd[1367]: boot.mount: Failed at step EXEC spawning /bin/umount: Input/output error Nov 28 14:09:18 radio systemd[1]: boot.mount: Mount process exited, code=exited, status=203/EXEC Nov 28 14:09:18 radio systemd[1]: Failed unmounting /boot. Nov 28 14:09:18 radio systemd[1]: boot.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-41CA\x2d9A8B.device. Stopping, too. Nov 28 14:09:18 radio systemd[1]: Unmounting /boot... Nov 28 14:09:18 radio systemd[1368]: boot.mount: Failed to execute command: Input/output error Nov 28 14:09:18 radio systemd[1368]: boot.mount: Failed at step EXEC spawning /bin/umount: Input/output error Nov 28 14:09:18 radio systemd[1]: boot.mount: Mount process exited, code=exited, status=203/EXEC Nov 28 14:09:18 radio systemd[1]: Failed unmounting /boot. Nov 28 14:09:18 radio systemd[1]: boot.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-41CA\x2d9A8B.device. Stopping, too. Nov 28 14:09:18 radio systemd[1]: Unmounting /boot... Nov 28 14:09:18 radio systemd[1369]: boot.mount: Failed to execute command: Input/output error Nov 28 14:09:18 radio systemd[1369]: boot.mount: Failed at step EXEC spawning /bin/umount: Input/output error Nov 28 14:09:18 radio systemd[1]: boot.mount: Mount process exited, code=exited, status=203/EXEC Nov 28 14:09:18 radio systemd[1]: Failed unmounting /boot. Nov 28 14:09:18 radio systemd[1]: boot.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-41CA\x2d9A8B.device. Stopping, too. Nov 28 14:09:18 radio systemd[1]: Unmounting /boot... Nov 28 14:09:18 radio systemd[1370]: boot.mount: Failed to execute command: Input/output error Nov 28 14:09:18 radio systemd[1370]: boot.mount: Failed at step EXEC spawning /bin/umount: Input/output error Nov 28 14:09:18 radio systemd[1]: boot.mount: Mount process exited, code=exited, status=203/EXEC Nov 28 14:09:18 radio systemd[1]: Failed unmounting /boot. Nov 28 14:09:18 radio systemd[1]: boot.mount: Unit is bound to inactive unit dev-disk-by\x2duuid-41CA\x2d9A8B.device, but not stopping since we tried this too often recently. Nov 28 14:09:18 radio systemd[1]: systemd-fsck@dev-disk-by\x2duuid-41CA\x2d9A8B.service: Succeeded. Nov 28 14:09:18 radio systemd[1]: Stopped File System Check on /dev/disk/by-uuid/41CA-9A8B. Nov 28 14:09:18 radio volumio[798]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Nov 28 14:09:19 radio volumio[798]: info: MyVolumio token set successfully Nov 28 14:09:19 radio volumio[798]: info: MYVOLUMIO: Adding device Nov 28 14:09:19 radio volumio[798]: info: MYVOLUMIO: Evaluating Server Nov 28 14:09:19 radio volumio[798]: Configuration write error: Error: EROFS: read-only file system, open '/data/configuration/system_controller/my_volumio/config.json' Nov 28 14:09:19 radio kernel: EXT4-fs (sda3): Remounting filesystem read-only Nov 28 14:09:19 radio volumio[798]: error: Could not find ideal Myvolumio endpoint, defaulting to eu1 Nov 28 14:09:19 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 14:09:19 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 14:09:19 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 14:09:19 radio volumio[798]: info: MyVolumio status changed Nov 28 14:09:19 radio volumio[798]: info: Streaming services startup Nov 28 14:09:19 radio volumio[798]: info: Starting Streaming Daemon Nov 28 14:09:19 radio volumio[798]: info: Removing browser output: myVolumio user plan is not superstar Nov 28 14:09:19 radio volumio[798]: info: Removing audio output: Nov 28 14:09:19 radio volumio[798]: info: Stoppping Tunnel 1 Nov 28 14:09:19 radio sudo[1375]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 28 14:09:19 radio sudo[1375]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 14:09:19 radio sudo[1378]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Nov 28 14:09:19 radio sudo[1378]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 14:09:19 radio sudo[1375]: pam_unix(sudo:session): session closed for user root Nov 28 14:09:19 radio volumio[798]: error: Cannot start Volumio Streaming Daemon Nov 28 14:09:19 radio volumio[798]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 28 14:09:19 radio volumio[798]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 28 14:09:19 radio sudo[1378]: pam_unix(sudo:session): session closed for user root Nov 28 14:09:19 radio volumio[798]: error: Cannot stop Remote SSH: Error: Command failed: /usr/bin/sudo /bin/systemctl stop sshtunnel.service Nov 28 14:09:19 radio volumio[798]: Failed to stop sshtunnel.service: Unit sshtunnel.service not loaded. Nov 28 14:09:20 radio volumio[798]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 28 14:09:20 radio volumio[798]: info: Getting Spotify volume Nov 28 14:09:20 radio volumio[798]: info: Spotify volume: 100 Nov 28 14:09:20 radio volumio[798]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Nov 28 14:09:20 radio volumio[798]: info: CoreCommandRouter::volumioGetState Nov 28 14:09:20 radio volumio[798]: info: CorePlayQueue::getTrack 0 Nov 28 14:09:20 radio volumio[798]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 28 14:09:20 radio volumio[798]: info: Updating MyVolumio device info Nov 28 14:09:20 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 14:09:20 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 14:09:20 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 14:09:21 radio volumio[798]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 28 14:09:21 radio go-librespot[1329]: time="2025-11-28T14:09:21+01:00" level=debug msg="autoplay enabled: false" Nov 28 14:09:24 radio volumio[798]: info: MYVOLUMIO: Adding device Nov 28 14:09:24 radio volumio[798]: info: MYVOLUMIO: Evaluating Server Nov 28 14:09:24 radio kernel: EXT4-fs error: 11 callbacks suppressed Nov 28 14:09:24 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2393027: comm node: reading directory lblock 0 Nov 28 14:09:24 radio volumio[798]: error: Could not find ideal Myvolumio endpoint, defaulting to eu1 Nov 28 14:09:24 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 14:09:24 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 14:09:24 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 14:09:24 radio volumio[798]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 28 14:09:25 radio volumio[798]: info: Updating MyVolumio device info Nov 28 14:09:25 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 14:09:25 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 14:09:25 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 14:09:25 radio volumio[798]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 28 14:09:30 radio kernel: usb 2-2: new SuperSpeed USB device number 3 using xhci_hcd Nov 28 14:09:30 radio kernel: usb 2-2: New USB device found, idVendor=357d, idProduct=7788, bcdDevice= 1.14 Nov 28 14:09:30 radio kernel: usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Nov 28 14:09:30 radio kernel: usb 2-2: Product: USB to ATA/ATAPI Bridge Nov 28 14:09:30 radio kernel: usb 2-2: Manufacturer: JMicron Nov 28 14:09:30 radio kernel: usb 2-2: SerialNumber: 925633A010051 Nov 28 14:09:30 radio kernel: usb 2-2: UAS is ignored for this device, using usb-storage instead Nov 28 14:09:30 radio kernel: usb 2-2: UAS is ignored for this device, using usb-storage instead Nov 28 14:09:30 radio kernel: usb-storage 2-2:1.0: USB Mass Storage device detected Nov 28 14:09:30 radio kernel: usb-storage 2-2:1.0: Quirks match for vid 357d pid 7788: 1800000 Nov 28 14:09:30 radio kernel: scsi host1: usb-storage 2-2:1.0 Nov 28 14:09:31 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 28 14:09:31 radio volumio[798]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Nov 28 14:09:31 radio volumio[798]: info: CoreCommandRouter::volumioGetState Nov 28 14:09:31 radio volumio[798]: info: CorePlayQueue::getTrack 0 Nov 28 14:09:31 radio kernel: scsi 1:0:0:0: Direct-Access ADATA SU 650 0114 PQ: 0 ANSI: 6 Nov 28 14:09:31 radio kernel: sd 1:0:0:0: Attached scsi generic sg0 type 0 Nov 28 14:09:31 radio kernel: sd 1:0:0:0: [sdb] Spinning up disk... Nov 28 14:09:32 radio kernel: .ready Nov 28 14:09:32 radio kernel: sd 1:0:0:0: [sdb] 234441648 512-byte logical blocks: (120 GB/112 GiB) Nov 28 14:09:32 radio kernel: sd 1:0:0:0: [sdb] Write Protect is off Nov 28 14:09:32 radio kernel: sd 1:0:0:0: [sdb] Mode Sense: 47 00 10 08 Nov 28 14:09:32 radio kernel: sd 1:0:0:0: [sdb] Disabling FUA Nov 28 14:09:32 radio kernel: sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA Nov 28 14:09:32 radio kernel: sdb: sdb1 sdb2 sdb3 Nov 28 14:09:32 radio kernel: sd 1:0:0:0: [sdb] Attached SCSI disk Nov 28 14:09:33 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2390598: comm systemd: reading directory lblock 0 Nov 28 14:09:33 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2390598: comm systemd: reading directory lblock 0 Nov 28 14:09:33 radio volumio[798]: info: Ignoring mount for partition: volumio_data Nov 28 14:09:33 radio volumio[798]: info: Ignoring mount for partition: volumio Nov 28 14:09:33 radio volumio[798]: info: Ignoring mount for partition: boot Nov 28 14:09:33 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2390598: comm systemd: reading directory lblock 0 Nov 28 14:09:33 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2390598: comm systemd: reading directory lblock 0 Nov 28 14:09:33 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2390598: comm systemd: reading directory lblock 0 Nov 28 14:09:33 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2390598: comm systemd: reading directory lblock 0 Nov 28 14:09:33 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2390598: comm systemd: reading directory lblock 0 Nov 28 14:09:33 radio kernel: EXT4-fs error (device sda3): __ext4_find_entry:1684: inode #2390598: comm systemd: reading directory lblock 0 Nov 28 14:09:36 radio kernel: EXT4-fs warning (device sda3): htree_dirblock_to_tree:1082: inode #2390499: lblock 0: comm node: error -5 reading directory block Nov 28 14:09:36 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 14:09:36 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Nov 28 14:09:36 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 28 14:09:36 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Nov 28 14:09:36 radio volumio[798]: info: CoreCommandRouter::volumioGetBrowseSources Nov 28 14:09:36 radio volumio[798]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 28 14:09:36 radio volumio[798]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 28 14:09:36 radio volumio[798]: Error: EIO: i/o error, scandir '/data/plugins/' Nov 28 14:09:36 radio volumio[798]: at Object.readdirSync (fs.js:1021:3) Nov 28 14:09:36 radio volumio[798]: at PluginManager.getInstalledPlugins (/volumio/app/pluginmanager.js:1627:30) Nov 28 14:09:36 radio volumio[798]: at CoreCommandRouter.getInstalledPlugins (/volumio/app/index.js:1521:29) Nov 28 14:09:36 radio volumio[798]: at myVolumio.identifyUserProperties (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:42317) Nov 28 14:09:36 radio volumio[798]: at Timeout._onTimeout (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:2508) Nov 28 14:09:36 radio volumio[798]: at listOnTimeout (internal/timers.js:554:17) Nov 28 14:09:36 radio volumio[798]: at processTimers (internal/timers.js:497:7) { Nov 28 14:09:36 radio volumio[798]: errno: -5, Nov 28 14:09:36 radio volumio[798]: syscall: 'scandir', Nov 28 14:09:36 radio volumio[798]: code: 'EIO', Nov 28 14:09:36 radio volumio[798]: path: '/data/plugins/' Nov 28 14:09:36 radio volumio[798]: } Nov 28 14:09:36 radio volumio[798]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 28 14:09:36 radio sudo[1436]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-11-28 14:08 Nov 28 14:09:36 radio sudo[1436]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"