Aug 29 18:42:00 volumionuc ntpd[1161]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 29 18:42:00 volumionuc nmbd[1233]: [2026/08/29 18:42:00.238182, 0] ../../source3/nmbd/nmbd.c:901(main) Aug 29 18:42:00 volumionuc nmbd[1233]: nmbd version 4.17.12-Debian started. Aug 29 18:42:00 volumionuc nmbd[1233]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Aug 29 18:42:00 volumionuc ntpd[1161]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Aug 29 18:42:00 volumionuc ntpd[1161]: DNS: dns_check: DNS error: -11, System error Aug 29 18:42:00 volumionuc ntpd[1161]: DNS: dns_take_status: 0.debian.pool.ntp.org=>error, 12 Aug 29 18:42:00 volumionuc nmbd[1233]: [2026/08/29 18:42:00.249872, 0] ../../source3/nmbd/asyncdns.c:158(start_async_dns) Aug 29 18:42:00 volumionuc nmbd[1233]: started asyncdns process 1237 Aug 29 18:42:00 volumionuc nmbd[1233]: [2026/08/29 18:42:00.253018, 0] ../../lib/util/become_daemon.c:150(daemon_status) Aug 29 18:42:00 volumionuc nmbd[1233]: daemon_status: daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Aug 29 18:42:00 volumionuc nmbd[1233]: [2026/08/29 18:42:00.253115, 0] ../../source3/nmbd/nmbd_subnetdb.c:252(create_subnets) Aug 29 18:42:00 volumionuc nmbd[1233]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Aug 29 18:42:00 volumionuc wireless.js[984]: WIRELESS.JS - INFO: Single Network Mode enabled (default) - only one network device can be active at a time between ethernet and wireless Aug 29 18:42:00 volumionuc wireless.js[984]: WIRELESS.JS - INFO: Wireless.js initializing wireless flow Aug 29 18:42:00 volumionuc avahi-daemon[974]: Service "Volumio_nuc" (/services/volumio.service) successfully established. Aug 29 18:42:00 volumionuc sudo[1256]: root : unable to resolve host volumionuc: System error Aug 29 18:42:00 volumionuc sudo[1256]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 29 18:42:00 volumionuc sudo[1256]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 18:42:00 volumionuc sudo[1256]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:00 volumionuc sudo[1258]: root : unable to resolve host volumionuc: System error Aug 29 18:42:00 volumionuc sudo[1258]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 29 18:42:00 volumionuc sudo[1258]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 18:42:00 volumionuc sudo[1258]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:00 volumionuc wireless.js[984]: WIRELESS.JS - INFO: Cleaning previous... Aug 29 18:42:00 volumionuc sudo[1261]: root : unable to resolve host volumionuc: System error Aug 29 18:42:00 volumionuc sudo[1261]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 29 18:42:00 volumionuc sudo[1261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 18:42:00 volumionuc kernel: iwlwifi 0000:00:0c.0: Conflict between TLV & NVM regarding enabling LAR (TLV = enabled NVM =disabled) Aug 29 18:42:00 volumionuc sudo[1261]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:00 volumionuc wireless.js[984]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Aug 29 18:42:00 volumionuc wireless.js[984]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 2ms Aug 29 18:42:00 volumionuc wireless.js[984]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: 68:ec:c5:9c:2a:0c) Aug 29 18:42:00 volumionuc sudo[1268]: volumio : unable to resolve host volumionuc: System error Aug 29 18:42:00 volumionuc sudo[1268]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Aug 29 18:42:00 volumionuc sudo[1268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:00 volumionuc sudo[1268]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:00 volumionuc wireless.js[984]: sudo: unable to resolve host volumionuc: System error Aug 29 18:42:00 volumionuc sudo[1276]: volumio : unable to resolve host volumionuc: System error Aug 29 18:42:00 volumionuc sudo[1276]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Aug 29 18:42:00 volumionuc sudo[1276]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:01 volumionuc ntpd[1161]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 29 18:42:01 volumionuc ntpd[1161]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Aug 29 18:42:01 volumionuc ntpd[1161]: DNS: dns_check: DNS error: -11, System error Aug 29 18:42:01 volumionuc ntpd[1161]: DNS: dns_take_status: 1.debian.pool.ntp.org=>error, 12 Aug 29 18:42:02 volumionuc ntpd[1161]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 29 18:42:02 volumionuc ntpd[1161]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Aug 29 18:42:02 volumionuc ntpd[1161]: DNS: dns_check: DNS error: -11, System error Aug 29 18:42:02 volumionuc ntpd[1161]: DNS: dns_take_status: 2.debian.pool.ntp.org=>error, 12 Aug 29 18:42:03 volumionuc systemd[1]: systemd-rfkill.service: Deactivated successfully. Aug 29 18:42:03 volumionuc ntpd[1161]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 29 18:42:03 volumionuc ntpd[1161]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Aug 29 18:42:03 volumionuc ntpd[1161]: DNS: dns_check: DNS error: -11, System error Aug 29 18:42:03 volumionuc ntpd[1161]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12 Aug 29 18:42:03 volumionuc volumio-remote-updater[983]: [2026-08-29 18:42:03] [info] asio async_connect error: asio.system:111 (Connection refused) Aug 29 18:42:03 volumionuc volumio-remote-updater[983]: [2026-08-29 18:42:03] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Aug 29 18:42:03 volumionuc volumio-remote-updater[983]: [2026-08-29 18:42:03] [error] handle_connect error: Connection refused Aug 29 18:42:04 volumionuc sudo[1276]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:04 volumionuc wireless.js[984]: sudo: unable to resolve host volumionuc: System error Aug 29 18:42:04 volumionuc wireless.js[984]: WIRELESS.JS - INFO: SETTING APPROPRIATE REG DOMAIN: DE Aug 29 18:42:04 volumionuc sudo[1303]: volumio : unable to resolve host volumionuc: System error Aug 29 18:42:04 volumionuc sudo[1303]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set DE Aug 29 18:42:04 volumionuc sudo[1303]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:04 volumionuc sudo[1303]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:04 volumionuc wireless.js[984]: sudo: unable to resolve host volumionuc: System error Aug 29 18:42:04 volumionuc wireless.js[984]: WIRELESS.JS - INFO: SUCCESSFULLY SET NEW REGDOMAIN: DE Aug 29 18:42:04 volumionuc wireless.js[984]: WIRELESS.JS - INFO: Start wireless flow Aug 29 18:42:04 volumionuc wireless.js[984]: WIRELESS.JS - INFO: Stopped hotspot (if there).. Aug 29 18:42:04 volumionuc sudo[1311]: root : unable to resolve host volumionuc: System error Aug 29 18:42:04 volumionuc sudo[1311]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 29 18:42:04 volumionuc sudo[1311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 18:42:04 volumionuc sudo[1311]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:04 volumionuc sudo[1313]: root : unable to resolve host volumionuc: System error Aug 29 18:42:04 volumionuc sudo[1313]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 29 18:42:04 volumionuc sudo[1313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 18:42:04 volumionuc sudo[1313]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:04 volumionuc wireless.js[984]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Aug 29 18:42:04 volumionuc wireless.js[984]: WIRELESS.JS - INFO: STAGE 1: wlan0 validated and ready (MAC: 68:ec:c5:9c:2a:0c, USB: false) Aug 29 18:42:04 volumionuc wpa_supplicant[1324]: Successfully initialized wpa_supplicant Aug 29 18:42:04 volumionuc kernel: iwlwifi 0000:00:0c.0: Conflict between TLV & NVM regarding enabling LAR (TLV = enabled NVM =disabled) Aug 29 18:42:04 volumionuc sudo[1331]: root : unable to resolve host volumionuc: System error Aug 29 18:42:04 volumionuc sudo[1331]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 29 18:42:04 volumionuc sudo[1331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 18:42:04 volumionuc sudo[1331]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:04 volumionuc wireless.js[984]: sudo: unable to resolve host volumionuc: System error Aug 29 18:42:05 volumionuc bash[1138]: setdatetime-helper: all HTTPS Date fallbacks failed Aug 29 18:42:05 volumionuc systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 29 18:42:05 volumionuc systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 29 18:42:05 volumionuc wireless.js[984]: WIRELESS.JS - INFO: DHCP IP fallback Aug 29 18:42:05 volumionuc wireless.js[984]: WIRELESS.JS - INFO: STAGE 2: Starting event-driven WPA state monitor Aug 29 18:42:05 volumionuc wireless.js[984]: WIRELESS.JS - INFO: WpaStateMachine: Starting state monitor for wlan0 Aug 29 18:42:06 volumionuc wireless.js[984]: WIRELESS.JS - INFO: WpaStateMachine: State transition: NULL -> SCANNING (duration: 0ms) Aug 29 18:42:08 volumionuc wpa_supplicant[1328]: wlan0: SME: Trying to authenticate with a2:05:d6:f3:6d:50 (SSID='Family_Wlan' freq=5240 MHz) Aug 29 18:42:08 volumionuc kernel: wlan0: authenticate with a2:05:d6:f3:6d:50 (local address=68:ec:c5:9c:2a:0c) Aug 29 18:42:08 volumionuc kernel: wlan0: send auth to a2:05:d6:f3:6d:50 (try 1/3) Aug 29 18:42:08 volumionuc wpa_supplicant[1328]: wlan0: Trying to associate with a2:05:d6:f3:6d:50 (SSID='Family_Wlan' freq=5240 MHz) Aug 29 18:42:08 volumionuc kernel: wlan0: authenticated Aug 29 18:42:08 volumionuc kernel: wlan0: associate with a2:05:d6:f3:6d:50 (try 1/3) Aug 29 18:42:08 volumionuc kernel: wlan0: RX AssocResp from a2:05:d6:f3:6d:50 (capab=0x1111 status=0 aid=5) Aug 29 18:42:08 volumionuc wpa_supplicant[1328]: wlan0: Associated with a2:05:d6:f3:6d:50 Aug 29 18:42:08 volumionuc wpa_supplicant[1328]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Aug 29 18:42:08 volumionuc wpa_supplicant[1328]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE Aug 29 18:42:08 volumionuc kernel: wlan0: associated Aug 29 18:42:08 volumionuc kernel: wlan0: Limiting TX power to 23 (23 - 0) dBm as advertised by a2:05:d6:f3:6d:50 Aug 29 18:42:08 volumionuc wpa_supplicant[1328]: wlan0: WPA: Key negotiation completed with a2:05:d6:f3:6d:50 [PTK=CCMP GTK=CCMP] Aug 29 18:42:08 volumionuc wpa_supplicant[1328]: wlan0: CTRL-EVENT-CONNECTED - Connection to a2:05:d6:f3:6d:50 completed [id=0 id_str=] Aug 29 18:42:08 volumionuc dhcpcd[1013]: wlan0: carrier acquired Aug 29 18:42:08 volumionuc dhcpcd[1013]: wlan0: connected to Access Point: Family_Wlan Aug 29 18:42:08 volumionuc wpa_supplicant[1328]: wlan0: RRM: Unexpected neighbor report Aug 29 18:42:08 volumionuc dhcpcd[1013]: wlan0: IAID c5:9c:2a:0c Aug 29 18:42:08 volumionuc wireless.js[984]: WIRELESS.JS - INFO: WpaStateMachine: State transition: SCANNING -> COMPLETED (duration: 2028ms) Aug 29 18:42:08 volumionuc wireless.js[984]: WIRELESS.JS - INFO: WpaStateMachine: COMPLETED - connection successful Aug 29 18:42:08 volumionuc wireless.js[984]: WIRELESS.JS - INFO: STAGE 2: Connection successful - Connected to a2:05:d6:f3:6d:50 Aug 29 18:42:08 volumionuc wireless.js[984]: WIRELESS.JS - INFO: Onboard WiFi adapter detected, using standard dhcpcd flow Aug 29 18:42:08 volumionuc dhcpcd[1013]: wlan0: soliciting an IPv6 router Aug 29 18:42:09 volumionuc sudo[1374]: root : unable to resolve host volumionuc: System error Aug 29 18:42:09 volumionuc sudo[1374]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd wlan0 Aug 29 18:42:09 volumionuc sudo[1374]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 18:42:09 volumionuc dhcpcd[1013]: control command: /sbin/dhcpcd wlan0 Aug 29 18:42:09 volumionuc dhcpcd[1013]: control_free: No such file or directory Aug 29 18:42:09 volumionuc sudo[1374]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:09 volumionuc dhcpcd[1013]: wlan0: soliciting a DHCP lease Aug 29 18:42:09 volumionuc dhcpcd[1013]: wlan0: offered 192.168.1.86 from 192.168.1.1 Aug 29 18:42:09 volumionuc dhcpcd[1013]: wlan0: probing address 192.168.1.86/24 Aug 29 18:42:11 volumionuc volumio-remote-updater[983]: [2026-08-29 18:42:11] [info] asio async_connect error: asio.system:111 (Connection refused) Aug 29 18:42:11 volumionuc volumio-remote-updater[983]: [2026-08-29 18:42:11] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Aug 29 18:42:11 volumionuc volumio-remote-updater[983]: [2026-08-29 18:42:11] [error] handle_connect error: Connection refused Aug 29 18:42:11 volumionuc wireless.js[984]: WIRELESS.JS - INFO: Start ap Aug 29 18:42:11 volumionuc wireless.js[984]: WIRELESS.JS - INFO: Notified systemd about wireless ready Aug 29 18:42:11 volumionuc systemd[1]: Started wireless.service - Wireless Services. Aug 29 18:42:11 volumionuc systemd[1]: Started volumio.service - Volumio Backend Module. Aug 29 18:42:11 volumionuc systemd[1]: Started screenshot.service - Process screenshots triggered by PrtSc-button. Aug 29 18:42:11 volumionuc systemd[1]: Started soundcard-init.service - Intel SST and HDA soundcard init service. Aug 29 18:42:11 volumionuc systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker. Aug 29 18:42:11 volumionuc volumio-cpu-tweak[1388]: Setting RT Priority for mpd Aug 29 18:42:11 volumionuc volumio-cpu-tweak[1415]: pid 35's current scheduling policy: SCHED_OTHER Aug 29 18:42:11 volumionuc volumio-cpu-tweak[1415]: pid 35's current scheduling priority: 0 Aug 29 18:42:11 volumionuc volumio-cpu-tweak[1388]: Setting MPD Affinity Aug 29 18:42:11 volumionuc volumio-cpu-tweak[1416]: pid 3's current affinity mask: f Aug 29 18:42:11 volumionuc volumio-cpu-tweak[1388]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Aug 29 18:42:11 volumionuc systemd[1]: volumio_cpu_tweak.service: Deactivated successfully. Aug 29 18:42:11 volumionuc soundcard-init.sh[1439]: Card 0 Chip Realtek Generic Name HDA Intel PCH Aug 29 18:42:11 volumionuc soundcard-init.sh[1451]: Simple mixer control 'Master',0 Aug 29 18:42:11 volumionuc soundcard-init.sh[1451]: Capabilities: pvolume pvolume-joined pswitch pswitch-joined Aug 29 18:42:11 volumionuc soundcard-init.sh[1451]: Playback channels: Mono Aug 29 18:42:11 volumionuc soundcard-init.sh[1451]: Limits: Playback 0 - 87 Aug 29 18:42:11 volumionuc soundcard-init.sh[1451]: Mono: Playback 65 [75%] [-16.50dB] [on] Aug 29 18:42:11 volumionuc soundcard-init.sh[1439]: Card 5 Chip USB Mixer Name Jabra Link 380 Aug 29 18:42:11 volumionuc systemd[1]: soundcard-init.service: Deactivated successfully. Aug 29 18:42:12 volumionuc wireless.js[984]: WIRELESS.JS - INFO: trying... Aug 29 18:42:12 volumionuc sudo[1472]: volumio : unable to resolve host volumionuc: System error Aug 29 18:42:12 volumionuc sudo[1472]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 29 18:42:12 volumionuc sudo[1472]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:12 volumionuc sudo[1472]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:12 volumionuc wireless.js[984]: sudo: unable to resolve host volumionuc: System error Aug 29 18:42:12 volumionuc sudo[1482]: root : unable to resolve host volumionuc: System error Aug 29 18:42:12 volumionuc sudo[1482]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 18:42:12 volumionuc sudo[1482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 18:42:12 volumionuc sudo[1482]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:12 volumionuc wireless.js[984]: WIRELESS.JS - INFO: ... wlan0 IPv4 is undefined, ipV6 is undefined Aug 29 18:42:12 volumionuc volumio[1384]: info: ------------------------------------------- Aug 29 18:42:12 volumionuc volumio[1384]: info: ----- Volumio3 ---- Aug 29 18:42:12 volumionuc volumio[1384]: info: ------------------------------------------- Aug 29 18:42:12 volumionuc volumio[1384]: info: ----- System startup ---- Aug 29 18:42:12 volumionuc volumio[1384]: info: ------------------------------------------- Aug 29 18:42:12 volumionuc volumio[1384]: info: MYVOLUMIO Environment detected Aug 29 18:42:13 volumionuc volumio[1384]: info: Plugin folders cleanup Aug 29 18:42:13 volumionuc volumio[1384]: info: Scanning into folder /volumio/app/plugins/ Aug 29 18:42:13 volumionuc volumio[1384]: info: Scanning category audio_interface Aug 29 18:42:13 volumionuc volumio[1384]: info: Scanning category miscellanea Aug 29 18:42:13 volumionuc volumio[1384]: info: Scanning category music_service Aug 29 18:42:13 volumionuc volumio[1384]: info: Scanning category plugins.json Aug 29 18:42:13 volumionuc volumio[1384]: info: Scanning category system_controller Aug 29 18:42:13 volumionuc volumio[1384]: info: Scanning category user_interface Aug 29 18:42:13 volumionuc volumio[1384]: info: Scanning into folder /data/plugins/ Aug 29 18:42:13 volumionuc volumio[1384]: info: Scanning category music_service Aug 29 18:42:13 volumionuc volumio[1384]: info: Scanning category system_controller Aug 29 18:42:13 volumionuc volumio[1384]: info: Scanning category system_hardware Aug 29 18:42:13 volumionuc volumio[1384]: info: Scanning category user_interface Aug 29 18:42:13 volumionuc volumio[1384]: info: Plugin folders cleanup completed Aug 29 18:42:13 volumionuc volumio[1384]: info: ------------------------------------------- Aug 29 18:42:13 volumionuc volumio[1384]: info: ----- Core plugins startup ---- Aug 29 18:42:13 volumionuc volumio[1384]: info: ------------------------------------------- Aug 29 18:42:13 volumionuc volumio[1384]: info: Loading plugins from folder /volumio/app/plugins/ Aug 29 18:42:13 volumionuc volumio[1384]: info: Adding plugin upnp to MyMusic Plugins Aug 29 18:42:13 volumionuc volumio[1384]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 29 18:42:13 volumionuc volumio[1384]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 29 18:42:13 volumionuc volumio[1384]: info: Loading plugins from folder /data/plugins/ Aug 29 18:42:13 volumionuc volumio[1384]: info: Loading plugin "system"... Aug 29 18:42:13 volumionuc volumio[1384]: info: Loading plugin "appearance"... Aug 29 18:42:13 volumionuc wireless.js[984]: WIRELESS.JS - INFO: trying... Aug 29 18:42:13 volumionuc sudo[1499]: volumio : unable to resolve host volumionuc: System error Aug 29 18:42:13 volumionuc sudo[1499]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 29 18:42:13 volumionuc sudo[1499]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:13 volumionuc sudo[1499]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:13 volumionuc wireless.js[984]: sudo: unable to resolve host volumionuc: System error Aug 29 18:42:13 volumionuc sudo[1503]: root : unable to resolve host volumionuc: System error Aug 29 18:42:13 volumionuc sudo[1503]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 18:42:13 volumionuc sudo[1503]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 18:42:13 volumionuc sudo[1503]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:13 volumionuc wireless.js[984]: WIRELESS.JS - INFO: ... wlan0 IPv4 is undefined, ipV6 is undefined Aug 29 18:42:13 volumionuc systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Aug 29 18:42:13 volumionuc systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 18:42:13 volumionuc systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 18:42:13 volumionuc upmpdcli[1505]: Could not open config: /tmp/upmpdcli.conf Aug 29 18:42:13 volumionuc systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:42:13 volumionuc systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 18:42:13 volumionuc volumio[1384]: info: Loading plugin "network"... Aug 29 18:42:13 volumionuc volumio[1384]: info: Refreshing Cached IP Addresses Aug 29 18:42:13 volumionuc sudo[1507]: volumio : unable to resolve host volumionuc: System error Aug 29 18:42:13 volumionuc sudo[1509]: volumio : unable to resolve host volumionuc: System error Aug 29 18:42:13 volumionuc sudo[1507]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 18:42:13 volumionuc volumio[1384]: info: Loading plugin "services"... Aug 29 18:42:13 volumionuc sudo[1509]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 18:42:13 volumionuc sudo[1507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:13 volumionuc volumio[1384]: info: Loading plugin "volumio5onboarding"... Aug 29 18:42:13 volumionuc sudo[1509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:13 volumionuc sudo[1507]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:13 volumionuc sudo[1520]: volumio : unable to resolve host volumionuc: System error Aug 29 18:42:13 volumionuc sudo[1509]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:13 volumionuc volumio[1384]: info: Loading plugin "alsa_controller"... Aug 29 18:42:13 volumionuc sudo[1520]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 29 18:42:13 volumionuc sudo[1520]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:13 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 18:42:13 volumionuc volumio[1384]: info: Loading plugin "wizard"... Aug 29 18:42:13 volumionuc volumio[1384]: info: Loading plugin "networkfs"... Aug 29 18:42:13 volumionuc volumio[1384]: info: Starting Udev Watcher for removable devices Aug 29 18:42:13 volumionuc sudo[1541]: volumio : unable to resolve host volumionuc: System error Aug 29 18:42:13 volumionuc sudo[1541]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=wald,password=!AdmNas!1120,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.69/Daten/mp3 /mnt/NAS/Srv-Nas Aug 29 18:42:13 volumionuc sudo[1541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:13 volumionuc volumio[1384]: info: Ignoring mount for partition: boot Aug 29 18:42:13 volumionuc volumio[1384]: info: Ignoring mount for partition: volumio Aug 29 18:42:13 volumionuc volumio[1384]: info: Ignoring mount for partition: volumio_data Aug 29 18:42:13 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 29 18:42:13 volumionuc volumio[1384]: info: Loading plugin "volumio_command_line_client"... Aug 29 18:42:13 volumionuc volumio[1384]: info: Loading plugin "upnp"... Aug 29 18:42:13 volumionuc volumio[1384]: info: [1788021733996] Starting Upmpd Daemon Aug 29 18:42:13 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 29 18:42:13 volumionuc volumio[1384]: info: Loading plugin "my_music"... Aug 29 18:42:14 volumionuc volumio[1384]: info: Loading plugin "mpd"... Aug 29 18:42:14 volumionuc dhcpcd[1013]: wlan0: leased 192.168.1.86 for 86400 seconds Aug 29 18:42:14 volumionuc dhcpcd[1013]: wlan0: adding route to 192.168.1.0/24 Aug 29 18:42:14 volumionuc avahi-daemon[974]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.86. Aug 29 18:42:14 volumionuc avahi-daemon[974]: New relevant interface wlan0.IPv4 for mDNS. Aug 29 18:42:14 volumionuc avahi-daemon[974]: Registering new address record for 192.168.1.86 on wlan0.IPv4. Aug 29 18:42:14 volumionuc kernel: netfs: FS-Cache loaded Aug 29 18:42:14 volumionuc systemd[1]: welcome.service: Deactivated successfully. Aug 29 18:42:14 volumionuc kernel: Key type dns_resolver registered Aug 29 18:42:14 volumionuc systemd[1]: Stopped welcome.service - Show a welcome message on console. Aug 29 18:42:14 volumionuc systemd[1]: Stopping welcome.service - Show a welcome message on console... Aug 29 18:42:14 volumionuc dhcpcd[1013]: wlan0: adding default route via 192.168.1.1 Aug 29 18:42:14 volumionuc systemd[1]: Starting welcome.service - Show a welcome message on console... Aug 29 18:42:14 volumionuc welcome[1564]: Resolved ip:[1] 192.168.1.86 Aug 29 18:42:14 volumionuc systemd[1]: Finished welcome.service - Show a welcome message on console. Aug 29 18:42:14 volumionuc systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Aug 29 18:42:14 volumionuc systemd[1]: Started nmbd.service - Samba NMB Daemon. Aug 29 18:42:14 volumionuc kernel: Key type cifs.spnego registered Aug 29 18:42:14 volumionuc kernel: Key type cifs.idmap registered Aug 29 18:42:14 volumionuc kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Aug 29 18:42:14 volumionuc kernel: CIFS: Attempting to mount //192.168.1.69/Daten/mp3 Aug 29 18:42:14 volumionuc systemd[1]: Starting winbind.service - Samba Winbind Daemon... Aug 29 18:42:14 volumionuc volumio[1384]: info: Loading plugin "upnp_browser"... Aug 29 18:42:14 volumionuc wireless.js[984]: WIRELESS.JS - INFO: trying... Aug 29 18:42:14 volumionuc sudo[1613]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 29 18:42:14 volumionuc sudo[1613]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:14 volumionuc sudo[1613]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:14 volumionuc sudo[1617]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 18:42:14 volumionuc sudo[1617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 18:42:14 volumionuc sudo[1617]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:14 volumionuc wireless.js[984]: WIRELESS.JS - INFO: ... wlan0 IPv4 is 192.168.1.86, ipV6 is undefined Aug 29 18:42:14 volumionuc wireless.js[984]: WIRELESS.JS - INFO: Connected to SSID: Family_Wlan Aug 29 18:42:14 volumionuc wireless.js[984]: WIRELESS.JS - INFO: It's done! AP Aug 29 18:42:14 volumionuc wireless.js[984]: WIRELESS.JS - INFO: Restarting avahi-daemon... Aug 29 18:42:14 volumionuc winbindd[1606]: [2026/08/29 18:42:14.579985, 0] ../../source3/winbindd/winbindd.c:1440(main) Aug 29 18:42:14 volumionuc winbindd[1606]: winbindd version 4.17.12-Debian started. Aug 29 18:42:14 volumionuc winbindd[1606]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Aug 29 18:42:14 volumionuc sudo[1622]: root : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart avahi-daemon Aug 29 18:42:14 volumionuc winbindd[1606]: [2026/08/29 18:42:14.588213, 0] ../../source3/winbindd/winbindd_cache.c:3117(initialize_winbindd_cache) Aug 29 18:42:14 volumionuc winbindd[1606]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Aug 29 18:42:14 volumionuc sudo[1622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 18:42:14 volumionuc sudo[1541]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:14 volumionuc systemd[1]: Started winbind.service - Samba Winbind Daemon. Aug 29 18:42:14 volumionuc systemd[1]: Starting smbd.service - Samba SMB Daemon... Aug 29 18:42:14 volumionuc systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 18:42:14 volumionuc systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 18:42:14 volumionuc systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 18:42:14 volumionuc systemd[1]: shairport-sync.service: Consumed 1.863s CPU time. Aug 29 18:42:14 volumionuc systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Aug 29 18:42:14 volumionuc avahi-daemon[974]: Got SIGTERM, quitting. Aug 29 18:42:14 volumionuc avahi-daemon[974]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.86. Aug 29 18:42:14 volumionuc avahi-daemon[974]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Aug 29 18:42:14 volumionuc avahi-daemon[974]: avahi-daemon 0.8 exiting. Aug 29 18:42:14 volumionuc systemd[1]: avahi-daemon.service: Deactivated successfully. Aug 29 18:42:14 volumionuc systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Aug 29 18:42:14 volumionuc systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Aug 29 18:42:14 volumionuc avahi-daemon[1630]: Process 974 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) Aug 29 18:42:14 volumionuc avahi-daemon[1630]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Aug 29 18:42:14 volumionuc avahi-daemon[1630]: Successfully dropped root privileges. Aug 29 18:42:14 volumionuc avahi-daemon[1630]: avahi-daemon 0.8 starting up. Aug 29 18:42:14 volumionuc systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Aug 29 18:42:14 volumionuc avahi-daemon[1630]: Successfully called chroot(). Aug 29 18:42:14 volumionuc avahi-daemon[1630]: Successfully dropped remaining capabilities. Aug 29 18:42:14 volumionuc avahi-daemon[1630]: Loading service file /services/volumio.service. Aug 29 18:42:14 volumionuc sudo[1622]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:14 volumionuc avahi-daemon[1630]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.86. Aug 29 18:42:14 volumionuc avahi-daemon[1630]: New relevant interface wlan0.IPv4 for mDNS. Aug 29 18:42:14 volumionuc avahi-daemon[1630]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Aug 29 18:42:14 volumionuc avahi-daemon[1630]: New relevant interface lo.IPv4 for mDNS. Aug 29 18:42:14 volumionuc avahi-daemon[1630]: Network interface enumeration completed. Aug 29 18:42:14 volumionuc avahi-daemon[1630]: Registering new address record for 192.168.1.86 on wlan0.IPv4. Aug 29 18:42:14 volumionuc avahi-daemon[1630]: Registering new address record for 127.0.0.1 on lo.IPv4. Aug 29 18:42:14 volumionuc systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 18:42:14 volumionuc wireless.js[984]: WIRELESS.JS - INFO: Notified systemd about wireless ready Aug 29 18:42:14 volumionuc smbd[1649]: [2026/08/29 18:42:14.916625, 0] ../../source3/smbd/server.c:1741(main) Aug 29 18:42:14 volumionuc smbd[1649]: smbd version 4.17.12-Debian started. Aug 29 18:42:14 volumionuc smbd[1649]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Aug 29 18:42:15 volumionuc ntpd[1161]: IO: Listen normally on 3 wlan0 192.168.1.86:123 Aug 29 18:42:15 volumionuc ntpd[1161]: IO: new interface(s) found: waking up resolver Aug 29 18:42:15 volumionuc ntpd[1161]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 29 18:42:15 volumionuc volumio[1384]: info: Starting UPNP Browser Aug 29 18:42:15 volumionuc volumio[1384]: info: Loading plugin "alarm-clock"... Aug 29 18:42:15 volumionuc ntpd[1161]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Aug 29 18:42:15 volumionuc ntpd[1161]: DNS: Pool taking: 157.90.24.29 Aug 29 18:42:15 volumionuc ntpd[1161]: DNS: Pool taking: 141.84.43.73 Aug 29 18:42:15 volumionuc ntpd[1161]: DNS: Pool taking: 77.37.65.181 Aug 29 18:42:15 volumionuc ntpd[1161]: DNS: Pool taking: 5.189.151.39 Aug 29 18:42:15 volumionuc ntpd[1161]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Aug 29 18:42:15 volumionuc volumio[1384]: info: Loading plugin "airplay_emulation"... Aug 29 18:42:15 volumionuc volumio[1384]: info: Starting Shairport Sync Aug 29 18:42:15 volumionuc volumio[1384]: info: Loading plugin "last_100"... Aug 29 18:42:15 volumionuc volumio[1384]: info: Loading plugin "webradio"... Aug 29 18:42:15 volumionuc avahi-daemon[1630]: Server startup complete. Host name is volumionuc.local. Local service cookie is 2442245824. Aug 29 18:42:15 volumionuc volumio[1384]: info: Loading plugin "i2s_dacs"... Aug 29 18:42:15 volumionuc volumio[1384]: info: I2S DAC not set, start Auto-detection Aug 29 18:42:15 volumionuc systemd[1]: Started smbd.service - Samba SMB Daemon. Aug 29 18:42:15 volumionuc systemd[1]: Reached target multi-user.target - Multi-User System. Aug 29 18:42:15 volumionuc volumio[1384]: info: Loading plugin "volumiodiscovery"... Aug 29 18:42:15 volumionuc systemd[1]: Reached target graphical.target - Graphical Interface. Aug 29 18:42:15 volumionuc systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Aug 29 18:42:15 volumionuc systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Aug 29 18:42:15 volumionuc systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Aug 29 18:42:15 volumionuc volumio[1384]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 29 18:42:15 volumionuc volumio[1384]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 18:42:15 volumionuc volumio[1384]: *** WARNING *** For more information see Aug 29 18:42:15 volumionuc volumio[1384]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 29 18:42:15 volumionuc node[1384]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 29 18:42:15 volumionuc volumio[1384]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 18:42:15 volumionuc volumio[1384]: *** WARNING *** For more information see Aug 29 18:42:15 volumionuc node[1384]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 18:42:15 volumionuc node[1384]: *** WARNING *** For more information see Aug 29 18:42:15 volumionuc node[1384]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 29 18:42:15 volumionuc node[1384]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 18:42:15 volumionuc node[1384]: *** WARNING *** For more information see Aug 29 18:42:15 volumionuc systemd[1]: Startup finished in 5.665s (firmware) + 2.390s (loader) + 20.228s (kernel) + 20.281s (userspace) = 48.565s. Aug 29 18:42:15 volumionuc volumio[1384]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 29 18:42:15 volumionuc volumio[1384]: info: Discovery: Started advertising with name: Volumio_nuc Aug 29 18:42:15 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 29 18:42:15 volumionuc volumio[1384]: info: Loading plugin "spop"... Aug 29 18:42:16 volumionuc volumio[1384]: info: Loading plugin "SleepWakePlugin"... Aug 29 18:42:16 volumionuc ntpd[1161]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 29 18:42:16 volumionuc ntpd[1161]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Aug 29 18:42:16 volumionuc ntpd[1161]: DNS: Pool taking: 77.42.16.222 Aug 29 18:42:16 volumionuc ntpd[1161]: DNS: Pool taking: 141.144.241.16 Aug 29 18:42:16 volumionuc ntpd[1161]: DNS: Pool taking: 5.45.97.204 Aug 29 18:42:16 volumionuc ntpd[1161]: DNS: Pool taking: 85.202.163.55 Aug 29 18:42:16 volumionuc ntpd[1161]: DNS: Pool taking: 2a01:4f8:160:43aa::2 Aug 29 18:42:16 volumionuc ntpd[1161]: DNS: Pool taking: 2a0e:b107:27d0:1::5 Aug 29 18:42:16 volumionuc ntpd[1161]: DNS: Pool taking: 2a03:4000:21:209::1 Aug 29 18:42:16 volumionuc ntpd[1161]: DNS: Pool taking: 2a01:239:25e:bd00::2 Aug 29 18:42:16 volumionuc ntpd[1161]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Aug 29 18:42:16 volumionuc volumio[1384]: info: Applying required configuration parameters for plugin SleepWakePlugin Aug 29 18:42:16 volumionuc volumio[1384]: info: SleepWakePlugin - onVolumioStart Aug 29 18:42:16 volumionuc volumio[1384]: info: Loading plugin "stylish_player"... Aug 29 18:42:16 volumionuc avahi-daemon[1630]: Service "Volumio_nuc" (/services/volumio.service) successfully established. Aug 29 18:42:16 volumionuc volumio[1384]: info: Loading plugin "outputs"... Aug 29 18:42:16 volumionuc volumio[1384]: info: Loading plugin "albumart"... Aug 29 18:42:16 volumionuc volumio[1384]: info: Plugin example_plugin is not enabled Aug 29 18:42:16 volumionuc volumio[1384]: info: Loading plugin "inputs"... Aug 29 18:42:16 volumionuc volumio[1384]: info: Loading plugin "updater_comm"... Aug 29 18:42:16 volumionuc volumio[1384]: info: Plugin mpdemulation is not enabled Aug 29 18:42:16 volumionuc volumio[1384]: info: Loading plugin "rest_api"... Aug 29 18:42:16 volumionuc volumio[1677]: Forking 3 albumart workers Aug 29 18:42:16 volumionuc volumio[1384]: info: Loading plugin "websocket"... Aug 29 18:42:16 volumionuc volumio[1384]: info: Starting Socket.io Server version 1.7.4 Aug 29 18:42:16 volumionuc volumio[1384]: info: Loading plugin "volusonic"... Aug 29 18:42:16 volumionuc systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems... Aug 29 18:42:16 volumionuc systemd[1]: e2scrub_all.service: Deactivated successfully. Aug 29 18:42:16 volumionuc systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems. Aug 29 18:42:16 volumionuc volumio[1688]: Starting albumart workers Aug 29 18:42:16 volumionuc volumio[1689]: Starting albumart workers Aug 29 18:42:16 volumionuc volumio[1687]: Starting albumart workers Aug 29 18:42:17 volumionuc ntpd[1161]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 29 18:42:17 volumionuc volumio[1384]: info: Applying required configuration parameters for plugin volusonic Aug 29 18:42:17 volumionuc volumio[1384]: info: Loading plugin "Bluetoothremote"... Aug 29 18:42:17 volumionuc ntpd[1161]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Aug 29 18:42:17 volumionuc ntpd[1161]: DNS: Pool taking: 94.16.122.152 Aug 29 18:42:17 volumionuc ntpd[1161]: DNS: Pool taking: 185.16.60.96 Aug 29 18:42:17 volumionuc ntpd[1161]: DNS: Pool taking: 78.46.204.247 Aug 29 18:42:17 volumionuc ntpd[1161]: DNS: Pool taking: 62.108.36.235 Aug 29 18:42:17 volumionuc ntpd[1161]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Aug 29 18:42:17 volumionuc volumio[1384]: info: Applying required configuration parameters for plugin Bluetoothremote Aug 29 18:42:17 volumionuc volumio[1384]: info: Loading plugin "Systeminfo"... Aug 29 18:42:17 volumionuc volumio[1384]: info: Loading i18n strings for locale de Aug 29 18:42:17 volumionuc volumio[1384]: Updating browse sources language Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::initPlayerControls Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 18:42:17 volumionuc volumio[1384]: Express server listening on port 3000 Aug 29 18:42:17 volumionuc volumio[1384]: [Metrics] WebUI: 5s 522.90ms Aug 29 18:42:17 volumionuc sudo[1520]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:17 volumionuc volumio[1384]: info: Setting Device type: x86 Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreStateMachine::resetVolumioState Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreStateMachine::getcurrentVolume Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::volumioRetrievevolume Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:42:17 volumionuc volumio[1384]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Aug 29 18:42:17 volumionuc volumio[1384]: info: Completed loading Core Plugins Aug 29 18:42:17 volumionuc volumio[1384]: info: Preparing to generate the ALSA configuration file Aug 29 18:42:17 volumionuc volumio[1384]: info: The plugin stylish_player has an ALSA contribution file sp_in.sp_out.7.conf Aug 29 18:42:17 volumionuc volumio[1384]: info: Reading ALSA contributions from plugins. Aug 29 18:42:17 volumionuc volumio[1384]: info: Volumio Network Manager: Network status updated: 0 Aug 29 18:42:17 volumionuc volumio[1384]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Aug 29 18:42:17 volumionuc volumio[1384]: info: Reloading queue from file Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreStateMachine::setRepeat true single undefined Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreStateMachine::pushState Aug 29 18:42:17 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::volumioPushState Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreStateMachine::setRandom null Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreStateMachine::pushState Aug 29 18:42:17 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::volumioPushState Aug 29 18:42:17 volumionuc volumio[1384]: info: VolumeController:: Volume=100 Mute =false Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreStateMachine::pushState Aug 29 18:42:17 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::volumioPushState Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreStateMachine::updateTrackBlock Aug 29 18:42:17 volumionuc volumio[1384]: info: CorePlayQueue::getTrackBlock Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::volumioRetrievevolume Aug 29 18:42:17 volumionuc volumio[1384]: info: Asound.conf file written Aug 29 18:42:17 volumionuc sudo[1756]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Aug 29 18:42:17 volumionuc sudo[1756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:17 volumionuc sudo[1756]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:17 volumionuc volumio[1384]: info: Output device has changed, restarting MPD Aug 29 18:42:17 volumionuc volumio[1384]: info: Output device has changed, restarting Shairport Sync Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:42:17 volumionuc sudo[1762]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 18:42:17 volumionuc sudo[1762]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:17 volumionuc sudo[1762]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:17 volumionuc volumio[1384]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 18:42:17 volumionuc volumio[1384]: info: ___________ START PLUGINS ___________ Aug 29 18:42:17 volumionuc sudo[1764]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 18:42:17 volumionuc sudo[1764]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:17 volumionuc volumio[1384]: info: ControllerMpd::onStart: Initializing MPD Aug 29 18:42:17 volumionuc volumio[1384]: info: Creating MPD Configuration file Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 18:42:17 volumionuc volumio[1384]: info: [1788021737898] CoreMusicLibrary::Adding element Medienserver Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 18:42:17 volumionuc sudo[1772]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 29 18:42:17 volumionuc sudo[1772]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:17 volumionuc sudo[1774]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 18:42:17 volumionuc volumio[1384]: info: UPNP Browser: Client initialized successfully Aug 29 18:42:17 volumionuc sudo[1774]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:17 volumionuc sudo[1774]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:42:17 volumionuc sudo[1776]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 18:42:17 volumionuc sudo[1776]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:17 volumionuc systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 29 18:42:17 volumionuc volumio[1384]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:42:17 volumionuc systemd[1]: Starting mpd.service - Music Player Daemon... Aug 29 18:42:17 volumionuc volumio[1384]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 18:42:17 volumionuc volumio[1384]: info: [1788021737949] CoreMusicLibrary::Adding element Last_100 Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 18:42:17 volumionuc volumio[1384]: info: [1788021737951] CoreMusicLibrary::Adding element Webradio Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 18:42:17 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 18:42:17 volumionuc volumio[1384]: info: Initializing BBC Radios Aug 29 18:42:17 volumionuc systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 18:42:17 volumionuc sudo[1772]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:17 volumionuc systemd[1]: mpd.service: Deactivated successfully. Aug 29 18:42:17 volumionuc systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 29 18:42:17 volumionuc systemd[1]: mpd.socket: Deactivated successfully. Aug 29 18:42:17 volumionuc systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 29 18:42:17 volumionuc systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 29 18:42:17 volumionuc systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 29 18:42:17 volumionuc systemd[1]: Starting mpd.service - Music Player Daemon... Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: Creating Spotify config file Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc sudo[1805]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 29 18:42:18 volumionuc sudo[1805]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 18:42:18 volumionuc sudo[1811]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 29 18:42:18 volumionuc sudo[1805]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:18 volumionuc volumio[1384]: info: SleepWakePlugin - onStart Aug 29 18:42:18 volumionuc volumio[1384]: info: SleepWakePlugin - Sleep scheduled in 22661869 milliseconds Aug 29 18:42:18 volumionuc volumio[1384]: info: SleepWakePlugin - Wake scheduled in 44261868 milliseconds Aug 29 18:42:18 volumionuc volumio[1384]: info: Stylish Player: Peppy data path ready at /data/INTERNAL/stylish_player Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Aug 29 18:42:18 volumionuc volumio[1384]: info: Stylish Player: Found process ID Aug 29 18:42:18 volumionuc volumio[1384]: info: Stylish Player: Starting audio server on port 9993 Aug 29 18:42:18 volumionuc volumio[1384]: info: Loading i18n strings for locale de Aug 29 18:42:18 volumionuc volumio[1384]: Updating browse sources language Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 18:42:18 volumionuc volumio[1384]: info: [1788021738191] CoreMusicLibrary::Adding element Volusonic Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 18:42:18 volumionuc volumio[1384]: Cannot find translation for source Volusonic Aug 29 18:42:18 volumionuc volumio[1384]: info: Loading i18n strings for locale de Aug 29 18:42:18 volumionuc volumio[1384]: info: Volumio Calling Home Aug 29 18:42:18 volumionuc ntpd[1161]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 29 18:42:18 volumionuc ntpd[1161]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Aug 29 18:42:18 volumionuc ntpd[1161]: DNS: Pool taking: 85.220.190.246 Aug 29 18:42:18 volumionuc ntpd[1161]: DNS: Pool taking: 185.248.189.10 Aug 29 18:42:18 volumionuc ntpd[1161]: DNS: Pool taking: 88.99.86.9 Aug 29 18:42:18 volumionuc ntpd[1161]: DNS: Pool taking: 134.60.1.27 Aug 29 18:42:18 volumionuc ntpd[1161]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Aug 29 18:42:18 volumionuc volumio[1384]: info: Preparing to generate the ALSA configuration file Aug 29 18:42:18 volumionuc volumio[1384]: info: Stylish Player: Resilient Audio Streamer on port 9993 Aug 29 18:42:18 volumionuc volumio[1384]: info: Stylish Player: FIFO sentinel opened Aug 29 18:42:18 volumionuc volumio[1384]: info: Stylish Player: No stream clients — draining FIFO to keep ALSA unblocked Aug 29 18:42:18 volumionuc volumio[1384]: info: Stylish Player: Server listening on port 3339 Aug 29 18:42:18 volumionuc volumio5-onboarding[1794]: time=2026-08-29T18:42:18.252+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 29 18:42:18 volumionuc volumio[1384]: info: Discovery: adding 8a861d29-dc2d-4b1b-95cd-dae5e101b2fa Aug 29 18:42:18 volumionuc volumio[1384]: info: Discovery: Found device Volumio_nuc Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:42:18 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:42:18 volumionuc volumio[1384]: info: Discovery: this is already registered, 8a861d29-dc2d-4b1b-95cd-dae5e101b2fa Aug 29 18:42:18 volumionuc volumio[1384]: info: Discovery: Found device Volumio_nuc Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:42:18 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:42:18 volumionuc volumio[1384]: info: The plugin stylish_player has an ALSA contribution file sp_in.sp_out.7.conf Aug 29 18:42:18 volumionuc volumio[1384]: info: Reading ALSA contributions from plugins. Aug 29 18:42:18 volumionuc volumio[1384]: info: MPD Permissions set Aug 29 18:42:18 volumionuc volumio[1384]: info: MPD Permissions set Aug 29 18:42:18 volumionuc volumio[1384]: info: VolumeController:: Volume=100 Mute =false Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreStateMachine::pushState Aug 29 18:42:18 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::volumioPushState Aug 29 18:42:18 volumionuc volumio[1384]: info: Stylish Player: pushState → fmt=s16le rate=44100 isDSD=false Aug 29 18:42:18 volumionuc volumio[1384]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 29 18:42:18 volumionuc volumio[1384]: info: Volumio called home Aug 29 18:42:18 volumionuc volumio[1384]: info: Spotify config file written Aug 29 18:42:18 volumionuc volumio[1384]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 29 18:42:18 volumionuc volumio[1384]: info: Received Get System Info Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:42:18 volumionuc volumio[1384]: info: Discovery: Getting this device information Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:42:18 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:42:18 volumionuc volumio5-onboarding[1794]: time=2026-08-29T18:42:18.400+02:00 level=INFO msg="system info for 86cdbd53c8b76585e288344f8b9a065d" deviceName=Volumio_nuc deviceVariant=volumio deviceModel= softwareVersion=4.119 Aug 29 18:42:18 volumionuc sudo[1832]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 18:42:18 volumionuc sudo[1832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:18 volumionuc volumio[1384]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Aug 29 18:42:18 volumionuc systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 18:42:18 volumionuc systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio5-onboarding[1794]: time=2026-08-29T18:42:18.424+02:00 level=INFO msg="bootstrapping state" hasInternet=true Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 29 18:42:18 volumionuc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:42:18 volumionuc go-librespot[1839]: go-librespot daemon starting... Aug 29 18:42:18 volumionuc sudo[1832]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: No need to fix Spotify hosts Aug 29 18:42:18 volumionuc go-librespot[1844]: time="2026-08-29T18:42:18+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 18:42:18 volumionuc go-librespot[1844]: time="2026-08-29T18:42:18+02:00" level=debug msg="app state loaded" Aug 29 18:42:18 volumionuc go-librespot[1844]: time="2026-08-29T18:42:18+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 18:42:18 volumionuc volumio[1384]: info: Received Get System Info Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:42:18 volumionuc volumio[1384]: info: Discovery: Getting this device information Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:42:18 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:42:18 volumionuc volumio[1384]: info: Starting Shairport Sync Aug 29 18:42:18 volumionuc volumio[1384]: info: Starting Shairport Sync Aug 29 18:42:18 volumionuc volumio[1384]: info: Starting Shairport Sync Aug 29 18:42:18 volumionuc sudo[1862]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 18:42:18 volumionuc sudo[1862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:18 volumionuc sudo[1864]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 18:42:18 volumionuc sudo[1864]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:18 volumionuc volumio[1384]: info: Asound.conf file unchanged, so no further update is needed Aug 29 18:42:18 volumionuc volumio[1384]: info: Output device has changed, restarting MPD Aug 29 18:42:18 volumionuc systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 18:42:18 volumionuc systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 18:42:18 volumionuc systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 18:42:18 volumionuc systemd[1]: shairport-sync.service: Consumed 1.425s CPU time. Aug 29 18:42:18 volumionuc sudo[1866]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 18:42:18 volumionuc sudo[1866]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:18 volumionuc volumio[1384]: info: Output device has changed, restarting Shairport Sync Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:42:18 volumionuc systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 18:42:18 volumionuc sudo[1862]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:18 volumionuc volumio[1384]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 18:42:18 volumionuc sudo[1872]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 18:42:18 volumionuc sudo[1872]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:18 volumionuc systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 18:42:18 volumionuc sudo[1875]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 18:42:18 volumionuc sudo[1875]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:18 volumionuc sudo[1872]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:18 volumionuc systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 18:42:18 volumionuc systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 18:42:18 volumionuc systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 18:42:18 volumionuc sudo[1866]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:18 volumionuc sudo[1864]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:18 volumionuc systemd[1]: mpd.service: Deactivated successfully. Aug 29 18:42:18 volumionuc systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 29 18:42:18 volumionuc systemd[1]: mpd.socket: Deactivated successfully. Aug 29 18:42:18 volumionuc systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 29 18:42:18 volumionuc systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 29 18:42:18 volumionuc systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 29 18:42:18 volumionuc systemd[1]: Starting mpd.service - Music Player Daemon... Aug 29 18:42:18 volumionuc volumio[1384]: info: Shairport-Sync Started Aug 29 18:42:18 volumionuc volumio[1384]: Error adding Membership: Error: addMembership EINVAL Aug 29 18:42:18 volumionuc volumio[1384]: info: New Spotify access tokenBQCu8Lj7My... Aug 29 18:42:18 volumionuc volumio[1384]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 29 18:42:18 volumionuc volumio[1384]: info: Shairport-Sync Started Aug 29 18:42:18 volumionuc volumio[1384]: info: Shairport-Sync Started Aug 29 18:42:18 volumionuc volumio[1384]: info: MPD Permissions set Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:42:18 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc go-librespot[1844]: time="2026-08-29T18:42:18+02: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 18:42:18 volumionuc go-librespot[1844]: time="2026-08-29T18:42:18+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 18:42:18 volumionuc go-librespot[1844]: time="2026-08-29T18:42:18+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 18:42:18 volumionuc go-librespot[1844]: time="2026-08-29T18:42:18+02:00" level=info msg="zeroconf server listening on port 40079" Aug 29 18:42:18 volumionuc go-librespot[1844]: time="2026-08-29T18:42:18+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:42:18 volumionuc volumio[1384]: info: Starting Shairport Sync Aug 29 18:42:18 volumionuc sudo[1896]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 29 18:42:18 volumionuc sudo[1896]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 18:42:18 volumionuc sudo[1908]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 29 18:42:18 volumionuc sudo[1896]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:18 volumionuc go-librespot[1844]: time="2026-08-29T18:42:18+02:00" level=debug msg="obtained new client token: AAEI4inrWF0IeBiYANKSEcRwPxvSigN0LcMbreel7kYU4g79lvygg7pYnUKo7EOUYBuAX7i9owx+XRNarpMeVFNIbAJWnfr6SZWBV4B7yfJuvS5nBMG4onthIPeeT4pRopBnXUH31Wq/21JwWjzRi7Q4AQ7hx+XRkTtZFVTZz2/T40GdH+zMIhoeZGX8alxe6JQxnwSXWBu81rUL2C3eLrt/Mssf1JmT72XbtqPNxP5NWdSFY0QKLhs=" Aug 29 18:42:18 volumionuc sudo[1907]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 18:42:18 volumionuc sudo[1907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:18 volumionuc go-librespot[1844]: time="2026-08-29T18:42:18+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Aug 29 18:42:18 volumionuc systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 18:42:18 volumionuc systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 18:42:18 volumionuc systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 18:42:18 volumionuc systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 18:42:18 volumionuc sudo[1907]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:18 volumionuc volumio[1384]: info: Shairport-Sync Started Aug 29 18:42:18 volumionuc go-librespot[1844]: time="2026-08-29T18:42:18+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 29 18:42:18 volumionuc go-librespot[1844]: time="2026-08-29T18:42:18+02:00" level=debug msg="completed keyexchange" Aug 29 18:42:18 volumionuc go-librespot[1844]: time="2026-08-29T18:42:18+02:00" level=debug msg="completed challenge" Aug 29 18:42:18 volumionuc volumio[1384]: SPOTIFY: User informations: {"account_id":"91nISDntKJ","country":"IN","display_name":"Waldemar Dyck","email":"dyck@wald.pro","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31dnvnj3ing6mgu6mcevacskp3gu"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/31dnvnj3ing6mgu6mcevacskp3gu","id":"31dnvnj3ing6mgu6mcevacskp3gu","images":[],"product":"premium","type":"user","uri":"spotify:user:31dnvnj3ing6mgu6mcevacskp3gu"} Aug 29 18:42:18 volumionuc volumio[1384]: info: Spotify Successfully logged in Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 18:42:18 volumionuc volumio[1384]: info: [1788021738979] CoreMusicLibrary::Adding element Spotify Aug 29 18:42:18 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 18:42:18 volumionuc volumio[1384]: Cannot find translation for source Volusonic Aug 29 18:42:18 volumionuc volumio[1384]: Cannot find translation for source Spotify Aug 29 18:42:18 volumionuc go-librespot[1844]: time="2026-08-29T18:42:18+02:00" level=info msg="authenticated AP" username="31************************gu" Aug 29 18:42:19 volumionuc go-librespot[1844]: time="2026-08-29T18:42:19+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 18:42:19 volumionuc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:42:19 volumionuc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 18:42:20 volumionuc mpd[1909]: 2026-08-29T18:42:20 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 29 18:42:20 volumionuc systemd[1]: Started mpd.service - Music Player Daemon. Aug 29 18:42:20 volumionuc sudo[1764]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:20 volumionuc sudo[1875]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:20 volumionuc sudo[1776]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:20 volumionuc volumio[1384]: info: Completed starting Core Plugins Aug 29 18:42:20 volumionuc volumio[1384]: info: ------------------------------------------- Aug 29 18:42:20 volumionuc volumio[1384]: info: ----- MyVolumio plugins startup ---- Aug 29 18:42:20 volumionuc volumio[1384]: info: ------------------------------------------- Aug 29 18:42:20 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 29 18:42:20 volumionuc volumio[1384]: error: MPD error: The expression evaluated to a falsy value: Aug 29 18:42:20 volumionuc volumio[1384]: assert.ok(self.idling) Aug 29 18:42:20 volumionuc volumio[1384]: error: The expression evaluated to a falsy value: Aug 29 18:42:20 volumionuc volumio[1384]: assert.ok(self.idling) Aug 29 18:42:20 volumionuc volumio[1384]: error: MPD error: The expression evaluated to a falsy value: Aug 29 18:42:20 volumionuc volumio[1384]: assert.ok(self.idling) Aug 29 18:42:20 volumionuc volumio[1384]: error: The expression evaluated to a falsy value: Aug 29 18:42:20 volumionuc volumio[1384]: assert.ok(self.idling) Aug 29 18:42:20 volumionuc volumio[1384]: info: MPD running with PID1909 Aug 29 18:42:20 volumionuc volumio[1384]: ,establishing connection Aug 29 18:42:20 volumionuc volumio[1384]: error: updateQueue error: null Aug 29 18:42:20 volumionuc volumio[1384]: error: updateQueue error: null Aug 29 18:42:21 volumionuc volumio-remote-updater[983]: [2026-08-29 18:42:21] [connect] Successful connection Aug 29 18:42:21 volumionuc volumio-remote-updater[983]: [2026-08-29 18:42:21] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788021741 101 Aug 29 18:42:21 volumionuc volumio[1384]: 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: 3 Aug 29 18:42:45 volumionuc ntpd[1161]: CLOCK: time stepped by 23.783236 Aug 29 18:42:45 volumionuc ntpd[1161]: INIT: MRU 10922 entries, 13 hash bits, 65536 bytes Aug 29 18:42:45 volumionuc systemd[1]: Starting apt-daily-upgrade.service - Daily apt upgrade and clean activities... Aug 29 18:42:45 volumionuc volumio[1384]: info: go-librespot daemon successfully initialized Aug 29 18:42:46 volumionuc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 29 18:42:46 volumionuc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:42:46 volumionuc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:42:46 volumionuc go-librespot[1954]: go-librespot daemon starting... Aug 29 18:42:46 volumionuc go-librespot[1955]: time="2026-08-29T18:42:46+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 18:42:46 volumionuc go-librespot[1955]: time="2026-08-29T18:42:46+02:00" level=debug msg="app state loaded" Aug 29 18:42:46 volumionuc go-librespot[1955]: time="2026-08-29T18:42:46+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 18:42:46 volumionuc go-librespot[1955]: time="2026-08-29T18:42:46+02: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 18:42:46 volumionuc go-librespot[1955]: time="2026-08-29T18:42:46+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 18:42:46 volumionuc go-librespot[1955]: time="2026-08-29T18:42:46+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 18:42:46 volumionuc go-librespot[1955]: time="2026-08-29T18:42:46+02:00" level=info msg="zeroconf server listening on port 45767" Aug 29 18:42:46 volumionuc go-librespot[1955]: time="2026-08-29T18:42:46+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 18:42:46 volumionuc go-librespot[1955]: time="2026-08-29T18:42:46+02:00" level=debug msg="obtained new client token: AAElaPalYtn9s/hH3rTt718sINsOv7Mvke1g5ad6f+RfZwu4w3F0eHgqiN/iOIX+l/uq52wnt6eKFy3N6HI0l1j2rgmfPKGSVvxyGoKjlXfgM4PIUfiHnlMyEtlm1H7RNzY97FFHAqlFwe0CRkKS0GSWGRP7TE2YFuJtxGopz/HWQ+NNy8+mAyuDzk48GV+uZ36yOEdjYZwJQzqo8oI/htgAGzLUox22o7GSHGYC1VcaDFU7DM0xJPE=" Aug 29 18:42:46 volumionuc go-librespot[1955]: time="2026-08-29T18:42:46+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 18:42:46 volumionuc go-librespot[1955]: time="2026-08-29T18:42:46+02:00" level=debug msg="completed keyexchange" Aug 29 18:42:46 volumionuc go-librespot[1955]: time="2026-08-29T18:42:46+02:00" level=debug msg="completed challenge" Aug 29 18:42:46 volumionuc go-librespot[1955]: time="2026-08-29T18:42:46+02:00" level=info msg="authenticated AP" username="31************************gu" Aug 29 18:42:46 volumionuc go-librespot[1955]: time="2026-08-29T18:42:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 18:42:46 volumionuc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:42:46 volumionuc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 18:42:46 volumionuc systemd[1]: apt-daily-upgrade.service: Deactivated successfully. Aug 29 18:42:46 volumionuc systemd[1]: Finished apt-daily-upgrade.service - Daily apt upgrade and clean activities. Aug 29 18:42:46 volumionuc systemd[1]: apt-daily-upgrade.service: Consumed 1.434s CPU time. Aug 29 18:42:47 volumionuc volumio[1384]: info: Volumio Network Manager: Network status updated: 2 Aug 29 18:42:47 volumionuc sudo[2010]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 18:42:47 volumionuc sudo[2010]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:47 volumionuc sudo[2012]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 18:42:47 volumionuc sudo[2012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:47 volumionuc sudo[2010]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:47 volumionuc sudo[2012]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:47 volumionuc sudo[2014]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 29 18:42:47 volumionuc sudo[2014]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:48 volumionuc volumio[1384]: info: Initializing connection to go-librespot Websocket Aug 29 18:42:48 volumionuc volumio[1384]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 18:42:49 volumionuc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 29 18:42:49 volumionuc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:42:49 volumionuc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:42:49 volumionuc go-librespot[2020]: go-librespot daemon starting... Aug 29 18:42:49 volumionuc go-librespot[2021]: time="2026-08-29T18:42:49+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 18:42:49 volumionuc go-librespot[2021]: time="2026-08-29T18:42:49+02:00" level=debug msg="app state loaded" Aug 29 18:42:49 volumionuc go-librespot[2021]: time="2026-08-29T18:42:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 18:42:49 volumionuc go-librespot[2021]: time="2026-08-29T18:42:49+02: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]" Aug 29 18:42:49 volumionuc go-librespot[2021]: time="2026-08-29T18:42:49+02: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]" Aug 29 18:42:49 volumionuc go-librespot[2021]: time="2026-08-29T18:42:49+02: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]" Aug 29 18:42:49 volumionuc go-librespot[2021]: time="2026-08-29T18:42:49+02:00" level=info msg="zeroconf server listening on port 39423" Aug 29 18:42:49 volumionuc go-librespot[2021]: time="2026-08-29T18:42:49+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 18:42:49 volumionuc go-librespot[2021]: time="2026-08-29T18:42:49+02:00" level=debug msg="obtained new client token: AAHwsm7geoDrU8/EttFgfmdnh1WT0AlS+lyguWANh7M88bO3kZGXPiEfVhM5wSk87Bwis5C0LcS/accYkAiS0s2CMiwIvGEH/HPmnf5Xb35dGa/eGAiQBqqsPP6d/L4RPATUz/vqK8b8yiZb/WtniONJOQFS19OsQcBHM/LdF9TJzJEREK4tfB1BN2O5FgFBzv3Yp+3xKBsXN1e2QmLSLffhISdnobkRH89+WV/mQtoIQdR9ZIQh1jY=" Aug 29 18:42:49 volumionuc go-librespot[2021]: time="2026-08-29T18:42:49+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 18:42:49 volumionuc go-librespot[2021]: time="2026-08-29T18:42:49+02:00" level=debug msg="completed keyexchange" Aug 29 18:42:49 volumionuc go-librespot[2021]: time="2026-08-29T18:42:49+02:00" level=debug msg="completed challenge" Aug 29 18:42:49 volumionuc go-librespot[2021]: time="2026-08-29T18:42:49+02:00" level=info msg="authenticated AP" username="31************************gu" Aug 29 18:42:49 volumionuc go-librespot[2021]: time="2026-08-29T18:42:49+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 18:42:49 volumionuc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:42:49 volumionuc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 18:42:50 volumionuc volumio[1384]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 29 18:42:50 volumionuc systemd[1]: systemd-fsckd.service: Deactivated successfully. Aug 29 18:42:51 volumionuc volumio[1384]: info: Initializing connection to go-librespot Websocket Aug 29 18:42:51 volumionuc dhcpcd[860]: timed out Aug 29 18:42:51 volumionuc sh[852]: timed out Aug 29 18:42:51 volumionuc dhcpcd[860]: dhcpcd exited Aug 29 18:42:51 volumionuc sh[797]: ifup: failed to bring up eth0 Aug 29 18:42:51 volumionuc systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:42:51 volumionuc systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Aug 29 18:42:52 volumionuc volumio[1384]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 18:42:52 volumionuc systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Aug 29 18:42:52 volumionuc systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 18:42:52 volumionuc systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 18:42:52 volumionuc sudo[2014]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:52 volumionuc systemd[1]: systemd-hostnamed.service: Deactivated successfully. Aug 29 18:42:53 volumionuc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 29 18:42:53 volumionuc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:42:53 volumionuc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:42:53 volumionuc go-librespot[2049]: go-librespot daemon starting... Aug 29 18:42:53 volumionuc go-librespot[2050]: time="2026-08-29T18:42:53+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 18:42:53 volumionuc go-librespot[2050]: time="2026-08-29T18:42:53+02:00" level=debug msg="app state loaded" Aug 29 18:42:53 volumionuc go-librespot[2050]: time="2026-08-29T18:42:53+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 18:42:53 volumionuc go-librespot[2050]: time="2026-08-29T18:42:53+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 18:42:53 volumionuc go-librespot[2050]: time="2026-08-29T18:42:53+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 18:42:53 volumionuc go-librespot[2050]: time="2026-08-29T18:42:53+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 18:42:53 volumionuc go-librespot[2050]: time="2026-08-29T18:42:53+02:00" level=info msg="zeroconf server listening on port 33293" Aug 29 18:42:53 volumionuc go-librespot[2050]: time="2026-08-29T18:42:53+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 18:42:53 volumionuc go-librespot[2050]: time="2026-08-29T18:42:53+02:00" level=debug msg="obtained new client token: AAGAXoMgrt0bFCX8/dL6K1Dl0D6uL2Jnf/SVQnqvkxj+AlEp+UvCrKTO8BlO9DQVLAdET3rcb9xyynEhZLEWwPhhrdifLKgfmJ49lEMvKrytom4UvwLJge4QfWr2K6dBApO3AWQYW0nbi0N2FguPfxB1zmugxudmz3HcC15BUxW0Ce1n5i4Mx1+QwCsZtZruz/dU8Xv+IIn1rcNAmfjR8eSffOhKba28W6oTBOtxfxpg7afKfSzfCw0=" Aug 29 18:42:53 volumionuc go-librespot[2050]: time="2026-08-29T18:42:53+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 18:42:53 volumionuc go-librespot[2050]: time="2026-08-29T18:42:53+02:00" level=debug msg="completed keyexchange" Aug 29 18:42:53 volumionuc go-librespot[2050]: time="2026-08-29T18:42:53+02:00" level=debug msg="completed challenge" Aug 29 18:42:53 volumionuc go-librespot[2050]: time="2026-08-29T18:42:53+02:00" level=info msg="authenticated AP" username="31************************gu" Aug 29 18:42:53 volumionuc go-librespot[2050]: time="2026-08-29T18:42:53+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 18:42:53 volumionuc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:42:53 volumionuc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 18:42:53 volumionuc volumio[1384]: info: Upmpdcli Daemon Started Aug 29 18:42:55 volumionuc volumio[1384]: info: Initializing connection to go-librespot Websocket Aug 29 18:42:56 volumionuc volumio[1384]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 18:42:56 volumionuc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 29 18:42:56 volumionuc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:42:56 volumionuc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:42:56 volumionuc go-librespot[2065]: go-librespot daemon starting... Aug 29 18:42:56 volumionuc go-librespot[2066]: time="2026-08-29T18:42:56+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 18:42:56 volumionuc go-librespot[2066]: time="2026-08-29T18:42:56+02:00" level=debug msg="app state loaded" Aug 29 18:42:56 volumionuc go-librespot[2066]: time="2026-08-29T18:42:56+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 18:42:56 volumionuc go-librespot[2066]: time="2026-08-29T18:42:56+02: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 18:42:56 volumionuc go-librespot[2066]: time="2026-08-29T18:42:56+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 18:42:56 volumionuc go-librespot[2066]: time="2026-08-29T18:42:56+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 18:42:56 volumionuc go-librespot[2066]: time="2026-08-29T18:42:56+02:00" level=info msg="zeroconf server listening on port 34385" Aug 29 18:42:56 volumionuc go-librespot[2066]: time="2026-08-29T18:42:56+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 18:42:56 volumionuc go-librespot[2066]: time="2026-08-29T18:42:56+02:00" level=debug msg="obtained new client token: AAGp8D9HGrbogY/ByVObXcW5peRaq2jVok8NvNcO9PZ0f3826Y98naavO/mLxOhEsUZFImSzlbX1f60VZ2ewxRMlcbQROH15tiWobhOuZNG5mWhgr5QPUHnptWGYCWFjIIzZ++9rbVCW0wdo1o7JYrJnzubir1Rp56j0KwcDi8f+irtCpzYb282ZozyexGM9bwGZcFqHczknoDfCSNMrOb7N+724aSQGenLRSAthS40Ki3T+b5wqW64=" Aug 29 18:42:56 volumionuc go-librespot[2066]: time="2026-08-29T18:42:56+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 18:42:56 volumionuc go-librespot[2066]: time="2026-08-29T18:42:56+02:00" level=debug msg="completed keyexchange" Aug 29 18:42:56 volumionuc go-librespot[2066]: time="2026-08-29T18:42:56+02:00" level=debug msg="completed challenge" Aug 29 18:42:56 volumionuc go-librespot[2066]: time="2026-08-29T18:42:56+02:00" level=info msg="authenticated AP" username="31************************gu" Aug 29 18:42:56 volumionuc go-librespot[2066]: time="2026-08-29T18:42:56+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 18:42:56 volumionuc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:42:56 volumionuc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 29 18:42:57 volumionuc volumio[1384]: info: Adding plugin bluetooth to MyMusic Plugins Aug 29 18:42:57 volumionuc volumio[1384]: info: Adding plugin multiroom to MyMusic Plugins Aug 29 18:42:57 volumionuc volumio[1384]: info: Adding plugin metavolumio to MyMusic Plugins Aug 29 18:42:57 volumionuc volumio[1384]: info: Adding plugin cd_controller to MyMusic Plugins Aug 29 18:42:57 volumionuc volumio[1384]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 29 18:42:57 volumionuc volumio[1384]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 29 18:42:57 volumionuc volumio[1384]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 29 18:42:57 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 29 18:42:57 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:42:57 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:42:57 volumionuc volumio[1384]: info: Starting MyVolumio Remote Streaming Endpoints Aug 29 18:42:57 volumionuc volumio[1384]: info: MyVolumio login type: Token Aug 29 18:42:58 volumionuc volumio[1384]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 29 18:42:58 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 29 18:42:58 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 29 18:42:58 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 29 18:42:58 volumionuc volumio[1384]: info: Streaming services startup Aug 29 18:42:58 volumionuc volumio[1384]: info: Starting Streaming Daemon Aug 29 18:42:58 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 29 18:42:58 volumionuc sudo[2096]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 29 18:42:58 volumionuc sudo[2096]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:42:58 volumionuc sudo[2096]: pam_unix(sudo:session): session closed for user root Aug 29 18:42:59 volumionuc volumio[1384]: error: Cannot start Volumio Streaming Daemon Aug 29 18:42:59 volumionuc volumio[1384]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 29 18:42:59 volumionuc volumio[1384]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 29 18:42:59 volumionuc volumio[1384]: info: Initializing connection to go-librespot Websocket Aug 29 18:43:00 volumionuc volumio[1384]: Upnp client error: Error: This socket has been ended by the other party Aug 29 18:43:00 volumionuc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 29 18:43:00 volumionuc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:00 volumionuc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:00 volumionuc go-librespot[2103]: go-librespot daemon starting... Aug 29 18:43:00 volumionuc systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Aug 29 18:43:00 volumionuc go-librespot[2104]: time="2026-08-29T18:43:00+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 18:43:00 volumionuc go-librespot[2104]: time="2026-08-29T18:43:00+02:00" level=debug msg="app state loaded" Aug 29 18:43:00 volumionuc go-librespot[2104]: time="2026-08-29T18:43:00+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 18:43:00 volumionuc upmpdcli[2127]: writing RSA key Aug 29 18:43:00 volumionuc go-librespot[2104]: time="2026-08-29T18:43:00+02: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 18:43:00 volumionuc go-librespot[2104]: time="2026-08-29T18:43:00+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 18:43:00 volumionuc go-librespot[2104]: time="2026-08-29T18:43:00+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 18:43:00 volumionuc go-librespot[2104]: time="2026-08-29T18:43:00+02:00" level=info msg="zeroconf server listening on port 35611" Aug 29 18:43:00 volumionuc go-librespot[2104]: time="2026-08-29T18:43:00+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 18:43:00 volumionuc go-librespot[2104]: time="2026-08-29T18:43:00+02:00" level=debug msg="obtained new client token: AAFhKde22yl4NDiANDFsT5bljrYm6Sbs+AumdmkudzOZzu4VuRPm9Y5SxTGpduIMjpUwGGgwR7sFe0BL6Ts1ni9sPtSnC48gfos3QEm4cJwX0jFiw5EcV/kdclLO6yVdmgrnZMYsTeJ/jAbL3nbLRd0tz0+Wfmd5yrDzyDqoEc9VYiUM/SMQHxi/bkm7gGg2LnHQmOrb2aU6B9FnpxxzW/aCxmc4lmaZkBeLQXKavw4E/k/PpWuRfd8=" Aug 29 18:43:00 volumionuc go-librespot[2104]: time="2026-08-29T18:43:00+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 18:43:00 volumionuc go-librespot[2104]: time="2026-08-29T18:43:00+02:00" level=debug msg="completed keyexchange" Aug 29 18:43:00 volumionuc go-librespot[2104]: time="2026-08-29T18:43:00+02:00" level=debug msg="completed challenge" Aug 29 18:43:00 volumionuc go-librespot[2104]: time="2026-08-29T18:43:00+02:00" level=info msg="authenticated AP" username="31************************gu" Aug 29 18:43:00 volumionuc go-librespot[2104]: time="2026-08-29T18:43:00+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 18:43:00 volumionuc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:43:00 volumionuc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 18:43:00 volumionuc systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 29 18:43:00 volumionuc systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 29 18:43:01 volumionuc volumio[1384]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 18:43:03 volumionuc volumio[1384]: error: MyVolumio Custom Token format not valid, refreshing it Aug 29 18:43:03 volumionuc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 29 18:43:03 volumionuc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:03 volumionuc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:03 volumionuc go-librespot[2157]: go-librespot daemon starting... Aug 29 18:43:03 volumionuc go-librespot[2158]: time="2026-08-29T18:43:03+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 18:43:03 volumionuc go-librespot[2158]: time="2026-08-29T18:43:03+02:00" level=debug msg="app state loaded" Aug 29 18:43:03 volumionuc go-librespot[2158]: time="2026-08-29T18:43:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 18:43:03 volumionuc go-librespot[2158]: time="2026-08-29T18:43:03+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 18:43:03 volumionuc go-librespot[2158]: time="2026-08-29T18:43:03+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 18:43:03 volumionuc go-librespot[2158]: time="2026-08-29T18:43:03+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 18:43:03 volumionuc go-librespot[2158]: time="2026-08-29T18:43:03+02:00" level=info msg="zeroconf server listening on port 39575" Aug 29 18:43:03 volumionuc go-librespot[2158]: time="2026-08-29T18:43:03+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 18:43:03 volumionuc go-librespot[2158]: time="2026-08-29T18:43:03+02:00" level=debug msg="obtained new client token: AAFbB0tAXpflBYJmr0i4RzZNb2IgLg/bySh+16EwfXIo1+KR2cD6+8ROCE8k5kt50hb7UDmzQeILVybFDyk39e7iySQQvbAtI1Hw0LaRYdYZ14sv7CyI24w2zJcdQvPpCburKNLumfMGqGRavAZeT/hC0RyribS/k4vMEcNuOm/OIALQUM8hWXctb0DMwe4srIlXG1teo92nctpiXbeOYYk+8utUE7mRV6We+m0KWoGA48hna9E6zWA=" Aug 29 18:43:03 volumionuc go-librespot[2158]: time="2026-08-29T18:43:03+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 18:43:03 volumionuc go-librespot[2158]: time="2026-08-29T18:43:03+02:00" level=debug msg="completed keyexchange" Aug 29 18:43:03 volumionuc go-librespot[2158]: time="2026-08-29T18:43:03+02:00" level=debug msg="completed challenge" Aug 29 18:43:03 volumionuc go-librespot[2158]: time="2026-08-29T18:43:03+02:00" level=info msg="authenticated AP" username="31************************gu" Aug 29 18:43:03 volumionuc go-librespot[2158]: time="2026-08-29T18:43:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 18:43:03 volumionuc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:43:03 volumionuc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 18:43:04 volumionuc volumio[1384]: info: Initializing connection to go-librespot Websocket Aug 29 18:43:06 volumionuc volumio[1384]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 18:43:07 volumionuc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 29 18:43:07 volumionuc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:07 volumionuc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:07 volumionuc go-librespot[2171]: go-librespot daemon starting... Aug 29 18:43:07 volumionuc go-librespot[2172]: time="2026-08-29T18:43:07+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 18:43:07 volumionuc go-librespot[2172]: time="2026-08-29T18:43:07+02:00" level=debug msg="app state loaded" Aug 29 18:43:07 volumionuc go-librespot[2172]: time="2026-08-29T18:43:07+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 18:43:07 volumionuc go-librespot[2172]: time="2026-08-29T18:43:07+02: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 18:43:07 volumionuc go-librespot[2172]: time="2026-08-29T18:43:07+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 18:43:07 volumionuc go-librespot[2172]: time="2026-08-29T18:43:07+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 18:43:07 volumionuc go-librespot[2172]: time="2026-08-29T18:43:07+02:00" level=info msg="zeroconf server listening on port 45295" Aug 29 18:43:07 volumionuc go-librespot[2172]: time="2026-08-29T18:43:07+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 18:43:07 volumionuc go-librespot[2172]: time="2026-08-29T18:43:07+02:00" level=debug msg="obtained new client token: AAEWco2p0RtpWdC4D3KK1hrnplb2xU+V+BDp87lk9hwAZKAeU36+HZUvTGnBw3+db3JaiGerzYjLViIAp9v+Kmj5qTz2lUMqmGl5AXM8PyTMiFMDpJ5iKpgYxyRa1YyeN1rYiPh7lmKjUT/QQXm5Pq5YLH2ehdukwYRBo575SMDQjcRILVVD/oU5u0VbskJIlp1VpbK95hq6H0vGb3KzBXi6IZg/rguTFmPy4T6rQKWZ9q4ahb13KS4=" Aug 29 18:43:07 volumionuc go-librespot[2172]: time="2026-08-29T18:43:07+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 18:43:07 volumionuc go-librespot[2172]: time="2026-08-29T18:43:07+02:00" level=debug msg="completed keyexchange" Aug 29 18:43:07 volumionuc go-librespot[2172]: time="2026-08-29T18:43:07+02:00" level=debug msg="completed challenge" Aug 29 18:43:07 volumionuc go-librespot[2172]: time="2026-08-29T18:43:07+02:00" level=info msg="authenticated AP" username="31************************gu" Aug 29 18:43:07 volumionuc go-librespot[2172]: time="2026-08-29T18:43:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 18:43:07 volumionuc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:43:07 volumionuc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 18:43:09 volumionuc volumio[1384]: info: Bluetoothremote--- Checking for trusted devices to reconnect... Aug 29 18:43:09 volumionuc volumio[1384]: info: Bluetoothremote--- Device list cleared and placeholder written. Aug 29 18:43:09 volumionuc bluetoothd[975]: Path / reserved for Adv Monitor app :1.31 Aug 29 18:43:09 volumionuc bluetoothd[975]: Adv Monitor app :1.31 disconnected from D-Bus Aug 29 18:43:09 volumionuc bluetoothd[975]: Path / reserved for Adv Monitor app :1.32 Aug 29 18:43:09 volumionuc bluetoothd[975]: Adv Monitor app :1.32 disconnected from D-Bus Aug 29 18:43:09 volumionuc bluetoothd[975]: Adv Monitor app :1.33 disconnected from D-Bus Aug 29 18:43:09 volumionuc volumio[1384]: info: Initializing connection to go-librespot Websocket Aug 29 18:43:09 volumionuc volumio[1384]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 18:43:09 volumionuc volumio[1384]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 29 18:43:09 volumionuc volumio[1384]: info: Bluetoothremote--- Device found: Press scan to detect BT device - xx Aug 29 18:43:09 volumionuc bluetoothd[975]: Path / reserved for Adv Monitor app :1.34 Aug 29 18:43:09 volumionuc bluetoothd[975]: Adv Monitor app :1.34 disconnected from D-Bus Aug 29 18:43:10 volumionuc volumio[1384]: info: MyVolumio login type: Token Aug 29 18:43:10 volumionuc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 29 18:43:10 volumionuc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:10 volumionuc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:10 volumionuc go-librespot[2209]: go-librespot daemon starting... Aug 29 18:43:10 volumionuc volumio[1384]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 29 18:43:10 volumionuc go-librespot[2210]: time="2026-08-29T18:43:10+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 18:43:10 volumionuc go-librespot[2210]: time="2026-08-29T18:43:10+02:00" level=debug msg="app state loaded" Aug 29 18:43:10 volumionuc go-librespot[2210]: time="2026-08-29T18:43:10+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 18:43:10 volumionuc go-librespot[2210]: time="2026-08-29T18:43:10+02: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]" Aug 29 18:43:10 volumionuc go-librespot[2210]: time="2026-08-29T18:43:10+02: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]" Aug 29 18:43:10 volumionuc go-librespot[2210]: time="2026-08-29T18:43:10+02: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]" Aug 29 18:43:10 volumionuc go-librespot[2210]: time="2026-08-29T18:43:10+02:00" level=info msg="zeroconf server listening on port 35203" Aug 29 18:43:10 volumionuc go-librespot[2210]: time="2026-08-29T18:43:10+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 18:43:10 volumionuc go-librespot[2210]: time="2026-08-29T18:43:10+02:00" level=debug msg="obtained new client token: AAGL2dLDpc9QfJJ1SUD9xUIk4lxwWSRFzT6XQxPkC8CnLUk8IVT9CLM6mHq+7jYqCfaiYu0RnkQvtBqv11SrmcRUNNHMoI0YsDdkDOXgJ5mo7rbJ37dRVGZDQCVEMbimyd3ugGMmZ2yAvPKcXugwqEFPog6+ET4bfFgXjOQBsSAqb/TWsu4e9aHJWxPauZ93To6K80t/1piKVjhL0TMyMaAlaahEPUX9kZbbtpfR4HSnjn8LRkHwfbE=" Aug 29 18:43:10 volumionuc go-librespot[2210]: time="2026-08-29T18:43:10+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 18:43:10 volumionuc go-librespot[2210]: time="2026-08-29T18:43:10+02:00" level=debug msg="completed keyexchange" Aug 29 18:43:10 volumionuc go-librespot[2210]: time="2026-08-29T18:43:10+02:00" level=debug msg="completed challenge" Aug 29 18:43:10 volumionuc go-librespot[2210]: time="2026-08-29T18:43:10+02:00" level=info msg="authenticated AP" username="31************************gu" Aug 29 18:43:10 volumionuc go-librespot[2210]: time="2026-08-29T18:43:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 18:43:10 volumionuc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:43:10 volumionuc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 18:43:11 volumionuc volumio[1384]: info: MyVolumio token set successfully Aug 29 18:43:11 volumionuc volumio[1384]: info: MYVOLUMIO: Adding device Aug 29 18:43:11 volumionuc volumio[1384]: info: MYVOLUMIO: Evaluating Server Aug 29 18:43:11 volumionuc volumio[1384]: info: MyVolumio Plan changed: premium Aug 29 18:43:11 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Aug 29 18:43:11 volumionuc volumio[1384]: info: Removing browser output: myVolumio user plan is not superstar Aug 29 18:43:11 volumionuc volumio[1384]: info: Removing audio output: Aug 29 18:43:11 volumionuc volumio[1384]: info: MYVOLUMIO: Adding device Aug 29 18:43:11 volumionuc volumio[1384]: info: MYVOLUMIO: Evaluating Server Aug 29 18:43:11 volumionuc volumio[1384]: info: Remote config written successfully Aug 29 18:43:11 volumionuc volumio[1384]: info: Starting Tunnel 1 Aug 29 18:43:11 volumionuc volumio[1384]: info: Starting Tunnel Connection Checker Aug 29 18:43:11 volumionuc volumio[1384]: info: Completed starting MyVolumio Plugin Aug 29 18:43:11 volumionuc volumio[1384]: info: MYVolumio Device enabled Aug 29 18:43:11 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Aug 29 18:43:11 volumionuc volumio[1384]: info: MyVolumio status changed Aug 29 18:43:11 volumionuc volumio[1384]: info: Streaming services startup Aug 29 18:43:11 volumionuc volumio[1384]: info: Starting Streaming Daemon Aug 29 18:43:11 volumionuc sudo[2260]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 29 18:43:11 volumionuc sudo[2260]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:11 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Aug 29 18:43:11 volumionuc volumio[1384]: error: [MyVolumio PluginManager] Cache data is invalid! Aug 29 18:43:11 volumionuc sudo[2260]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:11 volumionuc volumio[1384]: error: Cannot start Volumio Streaming Daemon Aug 29 18:43:11 volumionuc volumio[1384]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 29 18:43:11 volumionuc volumio[1384]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 29 18:43:11 volumionuc volumio[1384]: info: Setting Geolocation for MyVolumio to eu6 Aug 29 18:43:11 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:43:11 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:43:11 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:43:11 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 18:43:11 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:43:11 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 29 18:43:12 volumionuc volumio[1384]: info: Setting Geolocation for MyVolumio to eu6 Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 29 18:43:12 volumionuc volumio-remote-updater[983]: Test mode disabled Aug 29 18:43:12 volumionuc volumio-remote-updater[983]: Alpha mode disabled Aug 29 18:43:12 volumionuc volumio-remote-updater[983]: Alpha legacy test mode disabled Aug 29 18:43:12 volumionuc volumio5-onboarding[1794]: failed to bootstrap state: failed to check for software update: could not check for updates: context deadline exceeded Aug 29 18:43:12 volumionuc systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:43:12 volumionuc systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Aug 29 18:43:12 volumionuc volumio[1384]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 29 18:43:12 volumionuc systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1. Aug 29 18:43:12 volumionuc systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 18:43:12 volumionuc systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 18:43:12 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:12.334+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 29 18:43:12 volumionuc volumio[1384]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Aug 29 18:43:12 volumionuc volumio[1384]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Aug 29 18:43:12 volumionuc volumio[1384]: info: Received Get System Info Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:43:12 volumionuc volumio[1384]: info: Discovery: Getting this device information Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:43:12 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:43:12 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:12.364+02:00 level=INFO msg="system info for 86cdbd53c8b76585e288344f8b9a065d" deviceName=Volumio_nuc deviceVariant=volumio deviceModel= softwareVersion=4.119 Aug 29 18:43:12 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:12.374+02:00 level=INFO msg="bootstrapping state" hasInternet=true Aug 29 18:43:12 volumionuc volumio[1384]: info: Received Get System Info Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:43:12 volumionuc volumio[1384]: info: Discovery: Getting this device information Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:43:12 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:43:12 volumionuc volumio-remote-updater[983]: Test mode disabled Aug 29 18:43:12 volumionuc volumio-remote-updater[983]: Alpha mode disabled Aug 29 18:43:12 volumionuc volumio-remote-updater[983]: Alpha legacy test mode disabled Aug 29 18:43:12 volumionuc volumio[1384]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 29 18:43:12 volumionuc volumio[1384]: info: Successfully Added MyVolumio device Aug 29 18:43:12 volumionuc volumio[1384]: info: Successfully Added MyVolumio device Aug 29 18:43:12 volumionuc volumio[1384]: info: Initializing connection to go-librespot Websocket Aug 29 18:43:12 volumionuc volumio[1384]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 18:43:12 volumionuc volumio[1384]: info: Updating MyVolumio device info Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:43:12 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:43:12 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Aug 29 18:43:13 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin bluetooth Aug 29 18:43:13 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin bluetooth Aug 29 18:43:13 volumionuc volumio[1384]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Aug 29 18:43:13 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Aug 29 18:43:13 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Aug 29 18:43:13 volumionuc sudo[2281]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Aug 29 18:43:13 volumionuc sudo[2281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:13 volumionuc sudo[2281]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:13 volumionuc volumio[1384]: info: MRS: MultiRoom plugin initialized Aug 29 18:43:13 volumionuc volumio[1384]: info: MRS: STOPPING SNAPCLIENT Aug 29 18:43:13 volumionuc volumio[1384]: info: MRS: Snap server stop Aug 29 18:43:13 volumionuc volumio[1384]: info: MRS: STOPPING volumioStreaming Aug 29 18:43:13 volumionuc sudo[2298]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Aug 29 18:43:13 volumionuc sudo[2298]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:13 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Aug 29 18:43:13 volumionuc sudo[2300]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Aug 29 18:43:13 volumionuc sudo[2300]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:13 volumionuc sudo[2302]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Aug 29 18:43:13 volumionuc sudo[2302]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:13 volumionuc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Aug 29 18:43:13 volumionuc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:13 volumionuc sudo[2305]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Aug 29 18:43:13 volumionuc sudo[2305]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:13 volumionuc sudo[2305]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:13 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Aug 29 18:43:13 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Aug 29 18:43:13 volumionuc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:13 volumionuc go-librespot[2308]: go-librespot daemon starting... Aug 29 18:43:13 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Aug 29 18:43:13 volumionuc go-librespot[2310]: time="2026-08-29T18:43:13+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 18:43:13 volumionuc go-librespot[2310]: time="2026-08-29T18:43:13+02:00" level=debug msg="app state loaded" Aug 29 18:43:13 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Aug 29 18:43:13 volumionuc go-librespot[2310]: time="2026-08-29T18:43:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 18:43:13 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Aug 29 18:43:14 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Aug 29 18:43:14 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Aug 29 18:43:14 volumionuc sudo[2298]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:14 volumionuc sudo[2302]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:14 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Aug 29 18:43:14 volumionuc sudo[2300]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:14 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Aug 29 18:43:14 volumionuc volumio[1384]: info: Preparing to generate the ALSA configuration file Aug 29 18:43:14 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 29 18:43:14 volumionuc volumio[1384]: info: Updating MyVolumio device info Aug 29 18:43:14 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:43:14 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:43:14 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:43:14 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Aug 29 18:43:14 volumionuc volumio[1384]: info: Successfully Updated MyVolumio device Aug 29 18:43:14 volumionuc volumio[1384]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Aug 29 18:43:14 volumionuc volumio[1384]: info: The plugin stylish_player has an ALSA contribution file sp_in.sp_out.7.conf Aug 29 18:43:14 volumionuc volumio[1384]: info: Reading ALSA contributions from plugins. Aug 29 18:43:14 volumionuc volumio[1384]: info: MRS: Removed streaming files Aug 29 18:43:14 volumionuc volumio[1384]: info: MRS: volumioStreaming STOPPED Aug 29 18:43:14 volumionuc volumio[1384]: info: MRS: SNAPSERVER STOPPED Aug 29 18:43:14 volumionuc volumio[1384]: info: MRS: SNAPCLIENT STOPPED Aug 29 18:43:14 volumionuc go-librespot[2310]: time="2026-08-29T18:43:14+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 18:43:14 volumionuc go-librespot[2310]: time="2026-08-29T18:43:14+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 18:43:14 volumionuc go-librespot[2310]: time="2026-08-29T18:43:14+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 18:43:14 volumionuc go-librespot[2310]: time="2026-08-29T18:43:14+02:00" level=info msg="zeroconf server listening on port 32811" Aug 29 18:43:14 volumionuc go-librespot[2310]: time="2026-08-29T18:43:14+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 18:43:14 volumionuc volumio[1384]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Aug 29 18:43:14 volumionuc volumio[1384]: info: Asound.conf file written Aug 29 18:43:14 volumionuc go-librespot[2310]: time="2026-08-29T18:43:14+02:00" level=debug msg="obtained new client token: AAENCA7aFnzam692EYpT6ZbJ4cd6xzF/icq84MEsPhm5Q3vLMD8f7SzMxqftxUT9qP8KSYh2dFqUzj2zzVHECfjFhalhGJxHEnWk/++vRdli7LoFU5OS6+FqOoVfU7QEYU+vElwOlneAkQzF0PV0wqjUQFNlQsQzPUAyuLDJHRYqoQJ4ViNQFqronLEPJUTm9aaJqesXNZe9KCnHfRjgUpqluDbluVRvs8I+SeNw3ioCcjHwL6MG" Aug 29 18:43:14 volumionuc sudo[2321]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Aug 29 18:43:14 volumionuc sudo[2321]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:14 volumionuc sudo[2321]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:14 volumionuc go-librespot[2310]: time="2026-08-29T18:43:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 18:43:14 volumionuc volumio[1384]: info: Output device has changed, restarting MPD Aug 29 18:43:14 volumionuc go-librespot[2310]: time="2026-08-29T18:43:14+02:00" level=debug msg="completed keyexchange" Aug 29 18:43:14 volumionuc go-librespot[2310]: time="2026-08-29T18:43:14+02:00" level=debug msg="completed challenge" Aug 29 18:43:14 volumionuc volumio[1384]: info: Output device has changed, restarting Shairport Sync Aug 29 18:43:14 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:43:14 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:43:14 volumionuc sudo[2327]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 18:43:14 volumionuc sudo[2327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:14 volumionuc sudo[2327]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:14 volumionuc sudo[2329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 18:43:14 volumionuc sudo[2329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:14 volumionuc volumio[1384]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 18:43:14 volumionuc volumio[1384]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Aug 29 18:43:14 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:43:14 volumionuc go-librespot[2310]: time="2026-08-29T18:43:14+02:00" level=info msg="authenticated AP" username="31************************gu" Aug 29 18:43:14 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Aug 29 18:43:14 volumionuc volumio[1384]: ------------------------------------ BT MESSAGE: [FUNC] onStart Aug 29 18:43:14 volumionuc volumio[1384]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Aug 29 18:43:14 volumionuc systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 29 18:43:14 volumionuc volumio[1384]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Aug 29 18:43:14 volumionuc volumio[1384]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/ Aug 29 18:43:14 volumionuc volumio[1384]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Aug 29 18:43:14 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Aug 29 18:43:14 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Aug 29 18:43:14 volumionuc volumio[1384]: info: MRS: Pushing multiroomSync output for this device Aug 29 18:43:14 volumionuc volumio[1384]: info: MRS: Pushing multiroomSync output Aug 29 18:43:14 volumionuc volumio[1384]: info: Adding audio output: Aug 29 18:43:14 volumionuc volumio[1384]: info: Adding audio output: Aug 29 18:43:14 volumionuc volumio[1384]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Aug 29 18:43:14 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:43:14 volumionuc bluetoothd[975]: Path / reserved for Adv Monitor app :1.40 Aug 29 18:43:14 volumionuc bluetoothd[975]: Adv Monitor app :1.40 disconnected from D-Bus Aug 29 18:43:14 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Aug 29 18:43:14 volumionuc volumio[1384]: info: Adding METAVOLUMIO REST API Endpoints Aug 29 18:43:14 volumionuc volumio[1384]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Aug 29 18:43:14 volumionuc volumio[1384]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Aug 29 18:43:14 volumionuc volumio[1384]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Aug 29 18:43:14 volumionuc volumio[1384]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Aug 29 18:43:14 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Aug 29 18:43:14 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Aug 29 18:43:14 volumionuc volumio[1384]: info: Preparing CD Folders Aug 29 18:43:14 volumionuc volumio[1384]: info: Adding CD REST API Endpoints Aug 29 18:43:14 volumionuc volumio[1384]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Aug 29 18:43:14 volumionuc volumio[1384]: info: Starting UDEV Watcher for CD Aug 29 18:43:14 volumionuc volumio[1384]: info: Detecting CD presence with UDEV Aug 29 18:43:14 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Aug 29 18:43:14 volumionuc go-librespot[2310]: time="2026-08-29T18:43:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 18:43:14 volumionuc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:43:14 volumionuc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 18:43:14 volumionuc systemd[1]: mpd.service: Deactivated successfully. Aug 29 18:43:14 volumionuc systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 29 18:43:14 volumionuc systemd[1]: mpd.service: Consumed 2.713s CPU time. Aug 29 18:43:14 volumionuc systemd[1]: mpd.socket: Deactivated successfully. Aug 29 18:43:14 volumionuc systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 29 18:43:14 volumionuc systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 29 18:43:14 volumionuc systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 29 18:43:14 volumionuc systemd[1]: Starting mpd.service - Music Player Daemon... Aug 29 18:43:14 volumionuc sudo[2348]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 29 18:43:14 volumionuc sudo[2348]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 18:43:14 volumionuc sudo[2348]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:15 volumionuc mpd[2350]: 2026-08-29T18:43:15 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 29 18:43:15 volumionuc systemd[1]: Started mpd.service - Music Player Daemon. Aug 29 18:43:15 volumionuc sudo[2329]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:17 volumionuc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Aug 29 18:43:17 volumionuc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:17 volumionuc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:17 volumionuc go-librespot[2363]: go-librespot daemon starting... Aug 29 18:43:17 volumionuc go-librespot[2364]: time="2026-08-29T18:43:17+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 18:43:17 volumionuc go-librespot[2364]: time="2026-08-29T18:43:17+02:00" level=debug msg="app state loaded" Aug 29 18:43:17 volumionuc go-librespot[2364]: time="2026-08-29T18:43:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 18:43:17 volumionuc go-librespot[2364]: time="2026-08-29T18:43:17+02: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]" Aug 29 18:43:17 volumionuc go-librespot[2364]: time="2026-08-29T18:43:17+02: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]" Aug 29 18:43:17 volumionuc go-librespot[2364]: time="2026-08-29T18:43:17+02: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]" Aug 29 18:43:17 volumionuc go-librespot[2364]: time="2026-08-29T18:43:17+02:00" level=info msg="zeroconf server listening on port 37591" Aug 29 18:43:17 volumionuc go-librespot[2364]: time="2026-08-29T18:43:17+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 18:43:17 volumionuc go-librespot[2364]: time="2026-08-29T18:43:17+02:00" level=debug msg="obtained new client token: AAHPWbpmr2I2zA4Vkp3nGoomnEO113KXtolsIGCvMEZDW8tycLrQUdUQV8PBJgakicutus4bVOPc47oXyLEuh2/f+b/EJXpJIGI8FXcQYIh0pit8s/9Sa0O+3HnPWeqUnb3siCL6f2eQiLrlpzxEWay4v2wnb5Y7MosNYnwf4D26c3inSoBldP68OXKAI4dgwYELf2JFPdQHvESiD68Q+idlKL8q0urWiOcRsfhOhOpXVwO1avzbCvw=" Aug 29 18:43:17 volumionuc go-librespot[2364]: time="2026-08-29T18:43:17+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 18:43:17 volumionuc go-librespot[2364]: time="2026-08-29T18:43:17+02:00" level=debug msg="completed keyexchange" Aug 29 18:43:17 volumionuc go-librespot[2364]: time="2026-08-29T18:43:17+02:00" level=debug msg="completed challenge" Aug 29 18:43:17 volumionuc go-librespot[2364]: time="2026-08-29T18:43:17+02:00" level=info msg="authenticated AP" username="31************************gu" Aug 29 18:43:17 volumionuc go-librespot[2364]: time="2026-08-29T18:43:17+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 18:43:17 volumionuc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:43:17 volumionuc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 18:43:19 volumionuc volumio[1384]: warn: [cd-plugin] cdspeedctl: device or media not ready Aug 29 18:43:19 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Aug 29 18:43:19 volumionuc volumio[1384]: info: Adding inputs REST Endpoints Aug 29 18:43:19 volumionuc volumio[1384]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Aug 29 18:43:19 volumionuc volumio[1384]: info: Scanning Audio Inputs Aug 29 18:43:19 volumionuc volumio[1384]: info: Checking against Known Cards name Aug 29 18:43:19 volumionuc volumio[1384]: info: Checking against Known Cards name Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 18:43:19 volumionuc volumio[1384]: info: [1788021799377] CoreMusicLibrary::Adding element Jabra Link 380 Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 18:43:19 volumionuc volumio[1384]: Cannot find translation for source Volusonic Aug 29 18:43:19 volumionuc volumio[1384]: Cannot find translation for source Spotify Aug 29 18:43:19 volumionuc volumio[1384]: Cannot find translation for source Jabra Link 380 Aug 29 18:43:19 volumionuc volumio[1384]: info: Checking against Known Cards name Aug 29 18:43:19 volumionuc volumio[1384]: info: Adding Server instance for streaming Aug 29 18:43:19 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Aug 29 18:43:19 volumionuc volumio[1384]: error: Hi Res Audio Failed Login: Missing Login Data Aug 29 18:43:19 volumionuc volumio[1384]: info: Adding HIGHRESAUDIO REST API Endpoints Aug 29 18:43:19 volumionuc volumio[1384]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Aug 29 18:43:19 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Aug 29 18:43:19 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Aug 29 18:43:19 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Aug 29 18:43:19 volumionuc volumio[1384]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Aug 29 18:43:19 volumionuc volumio[1384]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:43:19 volumionuc volumio[1384]: info: QobuzConnect: Starting Qobuz Connect socket and service Aug 29 18:43:19 volumionuc sudo[2394]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Aug 29 18:43:19 volumionuc sudo[2394]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:19 volumionuc volumio[1384]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Aug 29 18:43:19 volumionuc volumio[1384]: info: Adding TIDAL REST API Endpoints Aug 29 18:43:19 volumionuc volumio[1384]: info: Stopping AccessToken refresher cron for QOBUZ Aug 29 18:43:19 volumionuc sudo[2401]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Aug 29 18:43:19 volumionuc sudo[2401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:19 volumionuc sudo[2394]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:19 volumionuc volumio[1384]: info: AccessToken refresher cron started for QOBUZ Aug 29 18:43:19 volumionuc volumio[1384]: info: Adding QOBUZ REST API Endpoints Aug 29 18:43:19 volumionuc sudo[2401]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:43:19 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:19 volumionuc volumio[1384]: info: Initializing connection to go-librespot Websocket Aug 29 18:43:19 volumionuc volumio[1384]: info: MRS: Getting audio outputs on start Aug 29 18:43:19 volumionuc volumio[1384]: info: MRS: Requesting all other devices output Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetBrowseSources Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 18:43:19 volumionuc sudo[2404]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Aug 29 18:43:19 volumionuc sudo[2404]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:19 volumionuc volumio[1384]: info: Successfully Updated MyVolumio device Aug 29 18:43:19 volumionuc systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Aug 29 18:43:19 volumionuc sudo[2404]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:19 volumionuc volumio[1384]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Aug 29 18:43:19 volumionuc volumio[1384]: info: MPD Permissions set Aug 29 18:43:19 volumionuc sudo[2408]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Aug 29 18:43:19 volumionuc sudo[2408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:19 volumionuc volumio[1384]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 18:43:19 volumionuc systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Aug 29 18:43:19 volumionuc sudo[2408]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:19 volumionuc volumiobt[2412]: INFO [BTSTART] Ensuring Bluetooth directory exists... Aug 29 18:43:19 volumionuc volumio[1384]: info: Executing endpoint qc_getconfig Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Aug 29 18:43:19 volumionuc sudo[2413]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Aug 29 18:43:19 volumionuc sudo[2413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:19 volumionuc qobuz-connect[2406]: 20260829 18:43:19.724 [2406.2406] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Aug 29 18:43:19 volumionuc sudo[2413]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 29 18:43:19 volumionuc sudo[2418]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Aug 29 18:43:19 volumionuc sudo[2418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:19 volumionuc sudo[2418]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:43:19 volumionuc volumiobt[2428]: INFO [BTSTART] Powering on Bluetooth if needed... Aug 29 18:43:19 volumionuc qobuz-connect[2406]: 20260829 18:43:19.781 [2406.2406] INFO VolumeManager: [0x560f11531b10]: Setting new playback volume: 75 Aug 29 18:43:19 volumionuc qobuz-connect[2406]: 20260829 18:43:19.781 [2406.2406] INFO VolumeManager: [0x560f11531b10]: Setting new mute state: 0 Aug 29 18:43:19 volumionuc qobuz-connect[2406]: 20260829 18:43:19.781 [2406.2406] INFO AudioStreamManager: [0x560f11531670]: Setting new audio download buffer size: 1048576 Aug 29 18:43:19 volumionuc qobuz-connect[2406]: 20260829 18:43:19.781 [2406.2406] INFO QobuzConnect: [0x560f11532b20]: Client initialized! Aug 29 18:43:19 volumionuc qobuz-connect[2406]: 20260829 18:43:19.781 [2406.2406] INFO SampleApp: Starting Avahi advertising, name: Volumio_nuc, service name: _qobuz-connect._tcp Aug 29 18:43:19 volumionuc bluetoothd[975]: Path / reserved for Adv Monitor app :1.43 Aug 29 18:43:19 volumionuc qobuz-connect[2406]: 20260829 18:43:19.791 [2406.2406] INFO LocalConfigManager: [0x560f11531150]: Starting Local Configuration server Aug 29 18:43:19 volumionuc qobuz-connect[2406]: 20260829 18:43:19.791 [2406.2406] INFO SampleApp: Starting Local configuration server Aug 29 18:43:19 volumionuc qobuz-connect[2406]: 20260829 18:43:19.791 [2406.2406] INFO SampleApp: Connected to UNIX socket client 0x560f11507bb0 Aug 29 18:43:19 volumionuc bluetoothd[975]: Adv Monitor app :1.43 disconnected from D-Bus Aug 29 18:43:19 volumionuc volumiobt[2438]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Aug 29 18:43:19 volumionuc volumio[1384]: error: updateQueue error: null Aug 29 18:43:19 volumionuc volumio[1384]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Aug 29 18:43:19 volumionuc volumio[1384]: info: QobuzConnect: QOBUZ Connect daemon connected Aug 29 18:43:19 volumionuc volumio[1384]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Aug 29 18:43:19 volumionuc volumio[1384]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Aug 29 18:43:19 volumionuc volumiobt[2439]: [176B blob data] Aug 29 18:43:19 volumionuc volumiobt[2439]: [157B blob data] Aug 29 18:43:19 volumionuc volumiobt[2439]: [157B blob data] Aug 29 18:43:19 volumionuc volumiobt[2439]: [157B blob data] Aug 29 18:43:19 volumionuc volumiobt[2439]: [113B blob data] Aug 29 18:43:19 volumionuc volumiobt[2439]: [bluetoothctl]> discoverable on Aug 29 18:43:19 volumionuc volumiobt[2439]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended Aug 29 18:43:19 volumionuc volumiobt[2439]: [bluetoothctl]> pairable on Aug 29 18:43:19 volumionuc volumio[1384]: info: Starting Shairport Sync Aug 29 18:43:19 volumionuc volumiobt[2439]: [131B blob data] Aug 29 18:43:19 volumionuc bluetoothd[975]: Path / reserved for Adv Monitor app :1.45 Aug 29 18:43:19 volumionuc bluetoothd[975]: Adv Monitor app :1.45 disconnected from D-Bus Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 18:43:19 volumionuc sudo[2442]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Aug 29 18:43:19 volumionuc volumiobt[2439]: [bluetoothctl]> Aug 29 18:43:19 volumionuc volumiobt[2445]: INFO [BTSTART] Registering Bluetooth agent... Aug 29 18:43:19 volumionuc sudo[2442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 29 18:43:19 volumionuc sudo[2444]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 18:43:19 volumionuc volumiobt[2446]: [NEW] Media /org/bluez/hci0 Aug 29 18:43:19 volumionuc volumiobt[2446]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Aug 29 18:43:19 volumionuc volumiobt[2446]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Aug 29 18:43:19 volumionuc volumiobt[2446]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Aug 29 18:43:19 volumionuc sudo[2444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:19 volumionuc systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 18:43:19 volumionuc systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 18:43:19 volumionuc bluetoothd[975]: Adv Monitor app :1.46 disconnected from D-Bus Aug 29 18:43:19 volumionuc qobuz-connect[2406]: 20260829 18:43:19.873 [2406.2406] INFO SampleApp: Playback volume changed: 75 Aug 29 18:43:19 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:43:19 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:19 volumionuc volumiobt[2449]: No agent is registered Aug 29 18:43:19 volumionuc volumiobt[2449]: [NEW] Media /org/bluez/hci0 Aug 29 18:43:19 volumionuc volumiobt[2449]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Aug 29 18:43:19 volumionuc volumiobt[2449]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Aug 29 18:43:19 volumionuc volumiobt[2449]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Aug 29 18:43:19 volumionuc bluetoothd[975]: Adv Monitor app :1.47 disconnected from D-Bus Aug 29 18:43:19 volumionuc volumiobt[2451]: INFO [BTSTART] Agent registered successfully. Aug 29 18:43:19 volumionuc systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Aug 29 18:43:19 volumionuc volumiobt[2452]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Aug 29 18:43:19 volumionuc sudo[2442]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:19 volumionuc volumio[1384]: info: Remote SSH Started Aug 29 18:43:19 volumionuc systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 18:43:19 volumionuc systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 18:43:19 volumionuc systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 18:43:19 volumionuc autossh[2453]: port set to 0, monitoring disabled Aug 29 18:43:19 volumionuc systemd[1]: shairport-sync.service: Consumed 1.790s CPU time. Aug 29 18:43:19 volumionuc autossh[2453]: starting ssh (count 1) Aug 29 18:43:19 volumionuc autossh[2453]: ssh child pid is 2457 Aug 29 18:43:19 volumionuc systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 18:43:19 volumionuc sudo[2444]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:19 volumionuc volumiossh-tunnel[2457]: ssh: connect to host eu6.myvolumio.org port 2222: Connection refused Aug 29 18:43:19 volumionuc autossh[2453]: ssh exited prematurely with status 255; autossh exiting Aug 29 18:43:19 volumionuc systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:43:19 volumionuc systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Aug 29 18:43:20 volumionuc volumio[1384]: info: Shairport-Sync Started Aug 29 18:43:20 volumionuc volumio[1384]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Aug 29 18:43:20 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:43:20 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:20 volumionuc systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 1. Aug 29 18:43:20 volumionuc systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Aug 29 18:43:20 volumionuc systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Aug 29 18:43:20 volumionuc autossh[2474]: port set to 0, monitoring disabled Aug 29 18:43:20 volumionuc autossh[2474]: starting ssh (count 1) Aug 29 18:43:20 volumionuc autossh[2474]: ssh child pid is 2477 Aug 29 18:43:20 volumionuc volumiossh-tunnel[2477]: ssh: connect to host eu6.myvolumio.org port 2222: Connection refused Aug 29 18:43:20 volumionuc autossh[2474]: ssh exited prematurely with status 255; autossh exiting Aug 29 18:43:20 volumionuc systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:43:20 volumionuc systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Aug 29 18:43:20 volumionuc volumiobt[2455]: 2026-08-29 18:43:20 a2dp-agent [INFO] Connecting to system D-Bus Aug 29 18:43:20 volumionuc volumiobt[2455]: 2026-08-29 18:43:20 a2dp-agent [INFO] Connected to system D-Bus Aug 29 18:43:20 volumionuc volumiobt[2455]: 2026-08-29 18:43:20 bluezutils [INFO] Found adapter at: /org/bluez/hci0 Aug 29 18:43:20 volumionuc volumiobt[2455]: 2026-08-29 18:43:20 a2dp-agent [INFO] Found Bluetooth adapter: /org/bluez/hci0 Aug 29 18:43:20 volumionuc volumiobt[2455]: 2026-08-29 18:43:20 a2dp-agent [INFO] Set DiscoverableTimeout to infinite Aug 29 18:43:20 volumionuc volumiobt[2455]: 2026-08-29 18:43:20 a2dp-agent [INFO] Enabled Discoverable mode Aug 29 18:43:20 volumionuc volumiobt[2455]: 2026-08-29 18:43:20 a2dp-agent [INFO] Agent registered at /local/a2dpagent Aug 29 18:43:20 volumionuc volumiobt[2455]: 2026-08-29 18:43:20 a2dp-agent [INFO] Agent set as default Aug 29 18:43:20 volumionuc volumiobt[2455]: 2026-08-29 18:43:20 a2dp-agent [INFO] A2DP agent running, waiting for connections... Aug 29 18:43:20 volumionuc systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 2. Aug 29 18:43:20 volumionuc systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Aug 29 18:43:20 volumionuc systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Aug 29 18:43:20 volumionuc autossh[2480]: port set to 0, monitoring disabled Aug 29 18:43:20 volumionuc autossh[2480]: starting ssh (count 1) Aug 29 18:43:20 volumionuc autossh[2480]: ssh child pid is 2483 Aug 29 18:43:20 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 18:43:20 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 29 18:43:20 volumionuc volumiossh-tunnel[2483]: ssh: connect to host eu6.myvolumio.org port 2222: Connection refused Aug 29 18:43:20 volumionuc autossh[2480]: ssh exited prematurely with status 255; autossh exiting Aug 29 18:43:20 volumionuc systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:43:20 volumionuc systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Aug 29 18:43:20 volumionuc systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 3. Aug 29 18:43:20 volumionuc systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Aug 29 18:43:20 volumionuc systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Aug 29 18:43:20 volumionuc autossh[2485]: port set to 0, monitoring disabled Aug 29 18:43:20 volumionuc autossh[2485]: starting ssh (count 1) Aug 29 18:43:20 volumionuc autossh[2485]: ssh child pid is 2488 Aug 29 18:43:20 volumionuc volumiossh-tunnel[2488]: ssh: connect to host eu6.myvolumio.org port 2222: Connection refused Aug 29 18:43:20 volumionuc autossh[2485]: ssh exited prematurely with status 255; autossh exiting Aug 29 18:43:20 volumionuc systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:43:20 volumionuc systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Aug 29 18:43:21 volumionuc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Aug 29 18:43:21 volumionuc systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 4. Aug 29 18:43:21 volumionuc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:21 volumionuc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:21 volumionuc systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Aug 29 18:43:21 volumionuc go-librespot[2489]: go-librespot daemon starting... Aug 29 18:43:21 volumionuc systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Aug 29 18:43:21 volumionuc autossh[2495]: port set to 0, monitoring disabled Aug 29 18:43:21 volumionuc go-librespot[2490]: time="2026-08-29T18:43:21+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 18:43:21 volumionuc go-librespot[2490]: time="2026-08-29T18:43:21+02:00" level=debug msg="app state loaded" Aug 29 18:43:21 volumionuc autossh[2495]: starting ssh (count 1) Aug 29 18:43:21 volumionuc autossh[2495]: ssh child pid is 2501 Aug 29 18:43:21 volumionuc go-librespot[2490]: time="2026-08-29T18:43:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 18:43:21 volumionuc volumiossh-tunnel[2501]: ssh: connect to host eu6.myvolumio.org port 2222: Connection refused Aug 29 18:43:21 volumionuc autossh[2495]: ssh exited prematurely with status 255; autossh exiting Aug 29 18:43:21 volumionuc systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:43:21 volumionuc systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Aug 29 18:43:21 volumionuc go-librespot[2490]: time="2026-08-29T18:43:21+02: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 18:43:21 volumionuc go-librespot[2490]: time="2026-08-29T18:43:21+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 18:43:21 volumionuc go-librespot[2490]: time="2026-08-29T18:43:21+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 18:43:21 volumionuc go-librespot[2490]: time="2026-08-29T18:43:21+02:00" level=info msg="zeroconf server listening on port 45329" Aug 29 18:43:21 volumionuc go-librespot[2490]: time="2026-08-29T18:43:21+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 18:43:21 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:21.250+02:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=zFcLoZuuMdc27e5kodxQc3CkGNh2 tokenExpiry=2026-08-29T19:43:21.250+02:00 Aug 29 18:43:21 volumionuc go-librespot[2490]: time="2026-08-29T18:43:21+02:00" level=debug msg="obtained new client token: AAFTZYy59SfQ1hMtiYdtjoKgAn5o7rGUma3tcOXyIiGGkgR8FbHM4kP6cIsr4TFtDkBlAs7tN6O7o7Cqe8tGrMDGcELDadbIf3dJHrcUDJo4kBIBBBGGPY1vnQNJ/L1643bbTmz8mkrOKqLu7yjRN9LATVjfXe83iZBelH+NyzYEtWBWgH98LYpDGWGF/mEAAFOmDp4elj2bMiK/RHAPVmJUKr3A+fauJEwDVH6fB2xzTyEtTcXk" Aug 29 18:43:21 volumionuc go-librespot[2490]: time="2026-08-29T18:43:21+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 18:43:21 volumionuc systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 5. Aug 29 18:43:21 volumionuc systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Aug 29 18:43:21 volumionuc systemd[1]: sshtunnel.service: Start request repeated too quickly. Aug 29 18:43:21 volumionuc systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Aug 29 18:43:21 volumionuc systemd[1]: Failed to start sshtunnel.service - MyVolumio SSH Tunnel. Aug 29 18:43:21 volumionuc go-librespot[2490]: time="2026-08-29T18:43:21+02:00" level=debug msg="completed keyexchange" Aug 29 18:43:21 volumionuc go-librespot[2490]: time="2026-08-29T18:43:21+02:00" level=debug msg="completed challenge" Aug 29 18:43:21 volumionuc go-librespot[2490]: time="2026-08-29T18:43:21+02:00" level=info msg="authenticated AP" username="31************************gu" Aug 29 18:43:21 volumionuc go-librespot[2490]: time="2026-08-29T18:43:21+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 18:43:21 volumionuc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:43:21 volumionuc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 18:43:21 volumionuc volumio[1384]: info: Received Get System Info Aug 29 18:43:21 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:43:21 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:43:21 volumionuc volumio[1384]: info: Discovery: Getting this device information Aug 29 18:43:21 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:43:21 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:21 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:43:21 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 18:43:21 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 18:43:21 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:21.899+02:00 level=INFO msg="enabling local network discovery" Aug 29 18:43:21 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:21.909+02:00 level=INFO msg="enabling BLE discovery" Aug 29 18:43:22 volumionuc volumio[1384]: info: TidalConnect service stoped! Aug 29 18:43:22 volumionuc volumio[1384]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Aug 29 18:43:22 volumionuc volumio[1384]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Aug 29 18:43:22 volumionuc sudo[2517]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Aug 29 18:43:22 volumionuc sudo[2517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:22 volumionuc systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Aug 29 18:43:22 volumionuc sudo[2517]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:22 volumionuc volumio[1384]: info: Initializing connection to go-librespot Websocket Aug 29 18:43:22 volumionuc volumio[1384]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 18:43:22 volumionuc volumio[1384]: info: Executing endpoint tc_getconfig Aug 29 18:43:22 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Aug 29 18:43:22 volumionuc vtcs[2520]: STARTING TidalConnect services, version: 1.6.1 Aug 29 18:43:22 volumionuc vtcs[2520]: STARTED TidalConnect services. Aug 29 18:43:22 volumionuc volumio[1384]: info: Executing endpoint tc_connect Aug 29 18:43:22 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Aug 29 18:43:22 volumionuc volumio[1384]: info: Connecting to TidalConnect Aug 29 18:43:22 volumionuc volumio[1384]: info: CoreCommandRouter::servicePushState Aug 29 18:43:22 volumionuc volumio[1384]: info: CoreStateMachine::pushState Aug 29 18:43:22 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:22 volumionuc volumio[1384]: info: CoreCommandRouter::volumioPushState Aug 29 18:43:22 volumionuc volumio[1384]: info: Stylish Player: pushState → fmt=s16le rate=44100 isDSD=false Aug 29 18:43:22 volumionuc volumio[1384]: info: MRS: Pushing multiroomSync output update for this device Aug 29 18:43:22 volumionuc volumio[1384]: info: MRS: Pushing multiroomSync output Aug 29 18:43:22 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:43:22 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:22 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:22 volumionuc volumio[1384]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect Aug 29 18:43:22 volumionuc volumio[1384]: info: CoreCommandRouter::servicePushState Aug 29 18:43:22 volumionuc volumio[1384]: info: CoreStateMachine::pushState Aug 29 18:43:22 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:22 volumionuc volumio[1384]: info: CoreCommandRouter::volumioPushState Aug 29 18:43:22 volumionuc volumio[1384]: info: Stylish Player: pushState → fmt=s16le rate=44100 isDSD=false Aug 29 18:43:22 volumionuc volumio[1384]: info: MRS: Pushing multiroomSync output update for this device Aug 29 18:43:22 volumionuc volumio[1384]: info: MRS: Pushing multiroomSync output Aug 29 18:43:22 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:43:22 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:22 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:22 volumionuc volumio[1384]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect Aug 29 18:43:22 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:22.824+02:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 29 18:43:24 volumionuc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Aug 29 18:43:24 volumionuc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:24 volumionuc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:24 volumionuc go-librespot[2539]: go-librespot daemon starting... Aug 29 18:43:24 volumionuc go-librespot[2540]: time="2026-08-29T18:43:24+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 18:43:24 volumionuc go-librespot[2540]: time="2026-08-29T18:43:24+02:00" level=debug msg="app state loaded" Aug 29 18:43:24 volumionuc go-librespot[2540]: time="2026-08-29T18:43:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 18:43:24 volumionuc go-librespot[2540]: time="2026-08-29T18:43:24+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 18:43:24 volumionuc go-librespot[2540]: time="2026-08-29T18:43:24+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 18:43:24 volumionuc go-librespot[2540]: time="2026-08-29T18:43:24+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 18:43:24 volumionuc go-librespot[2540]: time="2026-08-29T18:43:24+02:00" level=info msg="zeroconf server listening on port 40753" Aug 29 18:43:24 volumionuc go-librespot[2540]: time="2026-08-29T18:43:24+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 18:43:24 volumionuc go-librespot[2540]: time="2026-08-29T18:43:24+02:00" level=debug msg="obtained new client token: AAHangBNYmAUGHkhwuTtKsj33WMxMQzHRe507PzQsL5kpfU/EW/cFIsUPh4eivMNbAiPZpQk5SMr4Y1rEKaQIEpW+/IjojlkecC3bM4vS/RO/hlD67nljHY+u+P3ipkbDnJVjlGyYIKo2zeElGXE20WbbUWn8Y2yvdlXTlrUwHsXj96MWzPmNzWiQSXEbHX8QFLx61ZbO+H7wHBR+aHBD61sevpdFO04MhIU4rwjeFsuj2uWf+488vk=" Aug 29 18:43:24 volumionuc go-librespot[2540]: time="2026-08-29T18:43:24+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 18:43:24 volumionuc go-librespot[2540]: time="2026-08-29T18:43:24+02:00" level=debug msg="completed keyexchange" Aug 29 18:43:24 volumionuc go-librespot[2540]: time="2026-08-29T18:43:24+02:00" level=debug msg="completed challenge" Aug 29 18:43:24 volumionuc go-librespot[2540]: time="2026-08-29T18:43:24+02:00" level=info msg="authenticated AP" username="31************************gu" Aug 29 18:43:24 volumionuc go-librespot[2540]: time="2026-08-29T18:43:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 18:43:24 volumionuc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:43:24 volumionuc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 18:43:25 volumionuc volumio[1384]: info: TidalConnect service started! Aug 29 18:43:25 volumionuc volumio[1384]: [Metrics] CommandRouter: 49s 272.04ms Aug 29 18:43:25 volumionuc volumio[1384]: info: CoreCommandRouter::volumiosetStartupVolume Aug 29 18:43:25 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 18:43:25 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:43:25 volumionuc volumio[1384]: info: CoreCommandRouter::Close All Modals sent Aug 29 18:43:25 volumionuc volumio[1384]: info: CoreCommandRouter::Close All Modals sent Aug 29 18:43:25 volumionuc volumio[1384]: info: Initializing connection to go-librespot Websocket Aug 29 18:43:25 volumionuc volumio[1384]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 18:43:26 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 29 18:43:26 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 29 18:43:26 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 29 18:43:27 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:27.263+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.83:50085 Aug 29 18:43:27 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:27.286+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.83:50085 @ 0xc000274150" latency=10.046635ms timeout=20s Aug 29 18:43:27 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:27.286+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.83:50085 @ 0xc000274150" Aug 29 18:43:27 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:27.286+02:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.83:50085 @ 0xc000274150" latency=10.10204ms platform=PLATFORM_IOS version=6.260807.0 Aug 29 18:43:27 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 18:43:27 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 18:43:27 volumionuc volumio[1384]: info: Received Get System Info Aug 29 18:43:27 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:43:27 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:43:27 volumionuc volumio[1384]: info: Discovery: Getting this device information Aug 29 18:43:27 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:43:27 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:27 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:43:27 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:27.290+02:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.1.83:50085 @ 0xc000274150" name=Volumio_nuc Aug 29 18:43:27 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:27.293+02:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.1.83:50085 @ 0xc000274150" language=de Aug 29 18:43:27 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Aug 29 18:43:27 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:27.295+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.1.83:50085 @ 0xc000274150" timezone=Europe/Berlin Aug 29 18:43:27 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:27.296+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.83:50085 @ 0xc000274150" available=true connected=false macAddress= ip4Address= ip6Address= Aug 29 18:43:27 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:27.298+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.83:50085 @ 0xc000274150" available=true connected=true macAddress=68:ec:c5:9c:2a:0c ip4Address=192.168.1.86/24 ip6Address= ssid=Family_Wlan Aug 29 18:43:27 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:27.298+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.1.83:50085 @ 0xc000274150" setupComplete=true Aug 29 18:43:27 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Aug 29 18:43:27 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 29 18:43:27 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:43:27 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 29 18:43:27 volumionuc volumio[1384]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 0 -D 1 Aug 29 18:43:27 volumionuc volumio[1384]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 29 18:43:27 volumionuc volumio[1384]: {"cmd":"/usr/local/bin/alsacap -C 0 -D 1","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 0 -D 1\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Aug 29 18:43:27 volumionuc volumio[1384]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 0 -D 0 Aug 29 18:43:27 volumionuc volumio[1384]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 29 18:43:27 volumionuc volumio[1384]: {"cmd":"/usr/local/bin/alsacap -C 0 -D 0","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 0 -D 0\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Aug 29 18:43:27 volumionuc volumio[1384]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Aug 29 18:43:27 volumionuc volumio[1384]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 29 18:43:27 volumionuc volumio[1384]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Aug 29 18:43:27 volumionuc volumio[1384]: amixer -c 5 info | grep "Jabra Link 380" Aug 29 18:43:27 volumionuc volumio[1384]: Card sysdefault:5 'J380'/'Jabra Link 380 at usb-0000:00:15.0-3.1, full speed' Aug 29 18:43:27 volumionuc volumio[1384]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Aug 29 18:43:27 volumionuc volumio[1384]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 29 18:43:27 volumionuc volumio[1384]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Aug 29 18:43:27 volumionuc volumio[1384]: amixer -c 5 info | grep "Jabra Link 380" Aug 29 18:43:27 volumionuc volumio[1384]: Card sysdefault:5 'J380'/'Jabra Link 380 at usb-0000:00:15.0-3.1, full speed' Aug 29 18:43:27 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:27.387+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.1.83:50085 @ 0xc000274150" selectedOutputId=5 Aug 29 18:43:27 volumionuc volumio[1384]: info: Received Get System Info Aug 29 18:43:27 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:43:27 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:43:27 volumionuc volumio[1384]: info: Discovery: Getting this device information Aug 29 18:43:27 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:43:27 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:27 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:43:27 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:27.400+02:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.1.83:50085 @ 0xc000274150" currentVersion=4.119 latestVersion=4.119 Aug 29 18:43:27 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:27.400+02:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.1.83:50085 @ 0xc000274150" status=UPDATE_STATUS_NONE progress=0 Aug 29 18:43:27 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:27.400+02:00 level=INFO msg="emitting user changed event" component=server peer="192.168.1.83:50085 @ 0xc000274150" userId=zFcLoZuuMdc27e5kodxQc3CkGNh2 Aug 29 18:43:27 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:27.400+02:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.1.83:50085 @ 0xc000274150" providers=9 Aug 29 18:43:27 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:27.401+02:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.1.83:50085 @ 0xc000274150" plugins=53 Aug 29 18:43:27 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:43:27 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:27 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:27.403+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.83:50085 @ 0xc000274150" state=STATUS_STOPPED positionMs=0 volume=100 Aug 29 18:43:27 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:27.404+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.83:50085 @ 0xc000274150" id=spotify:track:5WIgMZQdINe1fhGdGDwduX title="Kapitel 1 - Folge 20: Bock auf Party?" Aug 29 18:43:28 volumionuc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Aug 29 18:43:28 volumionuc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:28 volumionuc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:28 volumionuc go-librespot[2590]: go-librespot daemon starting... Aug 29 18:43:28 volumionuc go-librespot[2591]: time="2026-08-29T18:43:28+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 18:43:28 volumionuc go-librespot[2591]: time="2026-08-29T18:43:28+02:00" level=debug msg="app state loaded" Aug 29 18:43:28 volumionuc go-librespot[2591]: time="2026-08-29T18:43:28+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 18:43:28 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:28.115+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.83:50085 @ 0xc000274150" latency=8.820762ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Aug 29 18:43:28 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:28.138+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.83:50085 @ 0xc000274150" latency=11.007707ms timeout=10s Aug 29 18:43:28 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:28.215+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.83:50085 @ 0xc000274150" latency=11.007707ms timeout=10s endpoint=http://pushupdates.volumio.org duration=76.041541ms Aug 29 18:43:28 volumionuc go-librespot[2591]: time="2026-08-29T18:43:28+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 18:43:28 volumionuc go-librespot[2591]: time="2026-08-29T18:43:28+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 18:43:28 volumionuc go-librespot[2591]: time="2026-08-29T18:43:28+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 18:43:28 volumionuc go-librespot[2591]: time="2026-08-29T18:43:28+02:00" level=info msg="zeroconf server listening on port 43361" Aug 29 18:43:28 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:28.228+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.83:50085 @ 0xc000274150" latency=11.007707ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=90.694556ms Aug 29 18:43:28 volumionuc go-librespot[2591]: time="2026-08-29T18:43:28+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 18:43:28 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:28.258+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.83:50085 @ 0xc000274150" latency=11.007707ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=120.023115ms Aug 29 18:43:28 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:28.272+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.83:50085 @ 0xc000274150" latency=11.007707ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=131.004615ms Aug 29 18:43:28 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:28.278+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.83:50085 @ 0xc000274150" latency=11.007707ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=139.787009ms Aug 29 18:43:28 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:28.280+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.83:50085 @ 0xc000274150" latency=11.007707ms timeout=10s endpoint=https://functions.volumio.cloud duration=141.434229ms Aug 29 18:43:28 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:28.284+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.83:50085 @ 0xc000274150" latency=11.007707ms timeout=10s endpoint=https://functions.volumio.cloud duration=142.958003ms Aug 29 18:43:28 volumionuc go-librespot[2591]: time="2026-08-29T18:43:28+02:00" level=debug msg="obtained new client token: AAFvGahKKL8/AGSPSCCzBNSAeRW9JP8z6x4+hm1hVPV7fZWY8+vFGwIcYdh8alU1bfhICIrqPdv2Em+b3OfWYBcv9g+2+991ocvDU6I2TWmmiORhxx5Uf80TOErjtYF0rUpMr/vZSlm1F/oLG8B+g9AFiR35ztCRRWvqjnLmZBBude4c6ojrw2dr3fYlGzHii0sfaEevj3W7S/wcLeqKMEk213ODENyRRgOxvmx+fxEfgW2cJkgjrGs=" Aug 29 18:43:28 volumionuc go-librespot[2591]: time="2026-08-29T18:43:28+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 18:43:28 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:28.325+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.83:50085 @ 0xc000274150" latency=11.007707ms timeout=10s endpoint=https://www.googleapis.com duration=185.075253ms Aug 29 18:43:28 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:43:28 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:43:28 volumionuc volumio[1384]: info: Discovery: Getting this device information Aug 29 18:43:28 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:43:28 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:28 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:43:28 volumionuc go-librespot[2591]: time="2026-08-29T18:43:28+02:00" level=debug msg="completed keyexchange" Aug 29 18:43:28 volumionuc go-librespot[2591]: time="2026-08-29T18:43:28+02:00" level=debug msg="completed challenge" Aug 29 18:43:28 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:28.341+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.83:50085 @ 0xc000274150" latency=11.007707ms timeout=10s endpoint=https://securetoken.googleapis.com duration=200.712475ms Aug 29 18:43:28 volumionuc volumio[1384]: verbose: New Socket.io Connection to 192.168.1.86:3000 from 192.168.1.83 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Aug 29 18:43:28 volumionuc go-librespot[2591]: time="2026-08-29T18:43:28+02:00" level=info msg="authenticated AP" username="31************************gu" Aug 29 18:43:28 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 18:43:28 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 18:43:28 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:28.409+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.83:50085 @ 0xc000274150" latency=11.007707ms timeout=10s endpoint=https://database.volumio.cloud duration=269.519023ms Aug 29 18:43:28 volumionuc go-librespot[2591]: time="2026-08-29T18:43:28+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 18:43:28 volumionuc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:43:28 volumionuc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 18:43:28 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:28.526+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.83:50085 @ 0xc000274150" latency=11.007707ms timeout=10s endpoint=http://cddb.volumio.org duration=386.1114ms Aug 29 18:43:28 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:28.628+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.83:50085 @ 0xc000274150" latency=11.007707ms timeout=10s endpoint=https://google.com duration=489.087674ms Aug 29 18:43:28 volumionuc volumio[1384]: info: Initializing connection to go-librespot Websocket Aug 29 18:43:28 volumionuc volumio[1384]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 18:43:28 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:28.674+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.83:50085 @ 0xc000274150" latency=11.007707ms timeout=10s endpoint=http://plugins.volumio.org duration=536.042505ms Aug 29 18:43:29 volumionuc sudo[2611]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 18:43:29 volumionuc sudo[2611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:29 volumionuc sudo[2611]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:29 volumionuc sudo[2613]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 18:43:29 volumionuc sudo[2613]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:29 volumionuc sudo[2613]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:29 volumionuc volumio[1384]: verbose: New Socket.io Connection to 192.168.1.86 from 192.168.1.83 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 6 Aug 29 18:43:29 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 29 18:43:29 volumionuc sudo[2618]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 18:43:29 volumionuc sudo[2618]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:29 volumionuc sudo[2620]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 18:43:29 volumionuc sudo[2618]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:29 volumionuc sudo[2620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:29 volumionuc sudo[2620]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:29 volumionuc volumio[1384]: verbose: New Socket.io Connection to 192.168.1.86 from 192.168.1.83 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 7 Aug 29 18:43:29 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 29 18:43:29 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 29 18:43:29 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetVisibleSources Aug 29 18:43:29 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 18:43:29 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:43:29 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:29 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 29 18:43:29 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 29 18:43:29 volumionuc volumio[1384]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Aug 29 18:43:29 volumionuc volumio[1384]: info: Received Get System Info Aug 29 18:43:29 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:43:29 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:43:29 volumionuc volumio[1384]: info: Discovery: Getting this device information Aug 29 18:43:29 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:43:29 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:29 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:43:29 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:43:29 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:29 volumionuc volumio[1384]: info: Listing playlists Aug 29 18:43:29 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 29 18:43:29 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 29 18:43:29 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 29 18:43:29 volumionuc rfkill[2625]: unblock set for type bluetooth Aug 29 18:43:31 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 29 18:43:31 volumionuc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Aug 29 18:43:31 volumionuc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:31 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 18:43:31 volumionuc volumio[1384]: info: Received Get System Info Aug 29 18:43:31 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:43:31 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:43:31 volumionuc volumio[1384]: info: Discovery: Getting this device information Aug 29 18:43:31 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:43:31 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:31 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:43:31 volumionuc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 18:43:31 volumionuc go-librespot[2634]: go-librespot daemon starting... Aug 29 18:43:31 volumionuc go-librespot[2635]: time="2026-08-29T18:43:31+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 18:43:31 volumionuc go-librespot[2635]: time="2026-08-29T18:43:31+02:00" level=debug msg="app state loaded" Aug 29 18:43:31 volumionuc go-librespot[2635]: time="2026-08-29T18:43:31+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 18:43:31 volumionuc volumio5-onboarding[2267]: time=2026-08-29T18:43:31.635+02:00 level=INFO msg="new address was allocated" component=ble/conn old=1 new=2 Aug 29 18:43:31 volumionuc volumio[1384]: info: Initializing connection to go-librespot Websocket Aug 29 18:43:31 volumionuc go-librespot[2635]: time="2026-08-29T18:43:31+02:00" level=debug msg="new websocket client" Aug 29 18:43:31 volumionuc volumio[1384]: info: Connection to go-librespot Websocket established Aug 29 18:43:31 volumionuc go-librespot[2635]: time="2026-08-29T18:43:31+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 18:43:31 volumionuc go-librespot[2635]: time="2026-08-29T18:43:31+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 18:43:31 volumionuc go-librespot[2635]: time="2026-08-29T18:43:31+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 18:43:31 volumionuc go-librespot[2635]: time="2026-08-29T18:43:31+02:00" level=info msg="zeroconf server listening on port 39533" Aug 29 18:43:31 volumionuc go-librespot[2635]: time="2026-08-29T18:43:31+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 18:43:31 volumionuc go-librespot[2635]: time="2026-08-29T18:43:31+02:00" level=debug msg="obtained new client token: AAH3g57sLP9BmkiE2yV0wftfu5a0kMA8cFnWa5pNQqU0MArEJe6M4jkF30WRpouOpWOdtFw5va2gYCOkv2kDLwtkfmO15r/b5Pj4QEK3busvf5SmASEq3IgO20QyQt7j9rbEoAOhgWFQ+2rdoiaGpZ4yHtOa2NZpkB8sPMm4R5SaiptXXGm4HYEUBk5o1vayaj8d6u4VSF2IV6wXlig35iaObajfbWS9woDZGP2NRwHdWv28WioFwSM=" Aug 29 18:43:31 volumionuc go-librespot[2635]: time="2026-08-29T18:43:31+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 18:43:31 volumionuc go-librespot[2635]: time="2026-08-29T18:43:31+02:00" level=debug msg="completed keyexchange" Aug 29 18:43:31 volumionuc go-librespot[2635]: time="2026-08-29T18:43:31+02:00" level=debug msg="completed challenge" Aug 29 18:43:31 volumionuc dbus-daemon[976]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.37" (uid=0 pid=2267 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=975 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Aug 29 18:43:31 volumionuc go-librespot[2635]: time="2026-08-29T18:43:31+02:00" level=info msg="authenticated AP" username="31************************gu" Aug 29 18:43:31 volumionuc go-librespot[2635]: time="2026-08-29T18:43:31+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 18:43:31 volumionuc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 18:43:31 volumionuc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 18:43:31 volumionuc volumio[1384]: info: Connection to go-librespot Websocket closed Aug 29 18:43:32 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: multiroom , enableAudioOutput Aug 29 18:43:32 volumionuc volumio[1384]: info: MRS: Starting browser stream Aug 29 18:43:32 volumionuc volumio[1384]: info: MRS: Setting this device as Streaming Server Aug 29 18:43:32 volumionuc volumio[1384]: info: Aug 29 18:43:32 volumionuc volumio[1384]: [1788021812160] ---------------------------- MRS: Setting Streaming Server Aug 29 18:43:32 volumionuc volumio[1384]: info: Enabled audio output: browserPlayback Aug 29 18:43:32 volumionuc volumio[1384]: info: MRS: enable multiroom server output Aug 29 18:43:32 volumionuc volumio[1384]: info: MRS: Set multiroom target PCM to volumioMultiRoom Aug 29 18:43:32 volumionuc volumio[1384]: info: Changed audio target for /tmp/multiroom/server/switch.target to volumioMultiRoom Aug 29 18:43:32 volumionuc volumio[1384]: info: MRS: Set multiroom target PCM to volumioLocalPlayback Aug 29 18:43:32 volumionuc volumio[1384]: info: Changed audio target for /tmp/multiroom/client/switch.target to volumioLocalPlayback Aug 29 18:43:32 volumionuc volumio[1384]: info: MRS: STARTING volumioStreaming Aug 29 18:43:32 volumionuc sudo[2647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Aug 29 18:43:32 volumionuc sudo[2647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:32 volumionuc sudo[2647]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:32 volumionuc sudo[2649]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumioStreaming Aug 29 18:43:32 volumionuc sudo[2649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:32 volumionuc systemd[1]: Started volumioStreaming.service - VolumioStreamingService. Aug 29 18:43:32 volumionuc sudo[2649]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:32 volumionuc volumio[1384]: info: MRS: volumioStreaming STARTED Aug 29 18:43:32 volumionuc sudo[2653]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Aug 29 18:43:32 volumionuc sudo[2653]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 18:43:32 volumionuc sudo[2653]: pam_unix(sudo:session): session closed for user root Aug 29 18:43:32 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 18:43:32 volumionuc volumio[1384]: info: Received Get System Info Aug 29 18:43:32 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:43:32 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:43:32 volumionuc volumio[1384]: info: Discovery: Getting this device information Aug 29 18:43:32 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetState Aug 29 18:43:32 volumionuc volumio[1384]: info: CorePlayQueue::getTrack 0 Aug 29 18:43:32 volumionuc volumio[1384]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:43:32 volumionuc volumio[1384]: info: BOOT COMPLETED Aug 29 18:43:33 volumionuc volumio[1384]: info: CoreCommandRouter::volumioGetQueue Aug 29 18:43:33 volumionuc volumio[1384]: info: CoreStateMachine::getQueue Aug 29 18:43:33 volumionuc volumio[1384]: info: CorePlayQueue::getQueue Aug 29 18:43:34 volumionuc volumio[1384]: info: Preload queue cleared Aug 29 18:43:34 volumionuc volumio[1384]: info: Preloading song: spotify:track:04dhut5mB74hK7Nv1pDOZU Aug 29 18:43:34 volumionuc volumio[1384]: info: Preloading song: spotify:track:6z7EhLacKW31hwi8VZy7eg Aug 29 18:43:34 volumionuc volumio[1384]: info: Preloading song: spotify:track:0okyV1SD4f6uJZ6NPdNEol Aug 29 18:43:34 volumionuc volumio[1384]: info: Preloading song: spotify:track:7Bk0VK59GsrYX6CwfbDsQ9 Aug 29 18:43:34 volumionuc volumio[1384]: info: Preloading song: upnp/folder/http://192.168.188.21:50001/ContentDirectory/control@22$3860 Aug 29 18:43:34 volumionuc volumio[1384]: info: Preloading song: upnp/folder/http://192.168.188.21:50001/ContentDirectory/control@22$3869 Aug 29 18:43:34 volumionuc volumio[1384]: info: Preloading song: spotify:track:2XTrxw7LeA5LaSo2ZDXP8Y Aug 29 18:43:34 volumionuc volumio[1384]: info: Preloading song: spotify:track:4VNkyt5jiwLvcssvgxHU0Q Aug 29 18:43:34 volumionuc volumio[1384]: info: Preloading song: spotify:track:49Zz9oAgTgFhiEZpRhyNJb Aug 29 18:43:34 volumionuc volumio[1384]: info: Preloading song: spotify:track:4VNkyt5jiwLvcssvgxHU0Q Aug 29 18:43:34 volumionuc volumio[1384]: info: Preloading song: spotify:track:4rF4wYdkVmtzRlcGHpB4So Aug 29 18:43:34 volumionuc volumio[1384]: info: Preloading song: spotify:track:33x5mpYpHuD7BvqQN46RvM Aug 29 18:43:34 volumionuc volumio[1384]: info: Preloading song: spotify:track:3fGmN8qMExEx7fIf8iQDNS Aug 29 18:43:34 volumionuc volumio[1384]: info: Getting Spotify volume Aug 29 18:43:34 volumionuc volumio[1384]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 18:43:34 volumionuc volumio[1384]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 18:43:34 volumionuc volumio[1384]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 29 18:43:34 volumionuc volumio[1384]: errno: -111, Aug 29 18:43:34 volumionuc volumio[1384]: code: 'ECONNREFUSED', Aug 29 18:43:34 volumionuc volumio[1384]: syscall: 'connect', Aug 29 18:43:34 volumionuc volumio[1384]: address: '127.0.0.1', Aug 29 18:43:34 volumionuc volumio[1384]: port: 9879, Aug 29 18:43:34 volumionuc volumio[1384]: response: undefined Aug 29 18:43:34 volumionuc volumio[1384]: } Aug 29 18:43:34 volumionuc volumio[1384]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 18:43:34 volumionuc sudo[2673]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-29 18:42' Aug 29 18:43:34 volumionuc sudo[2673]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"