Dec 23 18:35:00 my-volumio-3 sh[973]: wlan0=wlan0 Dec 23 18:35:00 my-volumio-3 bluetoothd[915]: Bluetooth daemon 5.83 Dec 23 18:35:00 my-volumio-3 systemd[1]: Started bluetooth.service - Bluetooth service. Dec 23 18:35:00 my-volumio-3 bluetoothd[915]: Starting SDP server Dec 23 18:35:00 my-volumio-3 bluetoothd[915]: Excluding (cli) sap Dec 23 18:35:00 my-volumio-3 bluetoothd[915]: Excluding (cli) midi Dec 23 18:35:00 my-volumio-3 bluetoothd[915]: Excluding (cli) battery Dec 23 18:35:00 my-volumio-3 systemd[1]: Starting bluealsa.service - BlueALSA service... Dec 23 18:35:00 my-volumio-3 kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Dec 23 18:35:00 my-volumio-3 kernel: Bluetooth: BNEP filters: protocol multicast Dec 23 18:35:00 my-volumio-3 kernel: Bluetooth: BNEP socket layer initialized Dec 23 18:35:00 my-volumio-3 bluetoothd[915]: Bluetooth management interface 1.23 initialized Dec 23 18:35:00 my-volumio-3 dbus-daemon[653]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.4' (uid=0 pid=915 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Dec 23 18:35:00 my-volumio-3 kernel: Bluetooth: MGMT ver 1.23 Dec 23 18:35:00 my-volumio-3 bluetoothd[915]: Battery Provider Manager created Dec 23 18:35:00 my-volumio-3 systemd[1]: Starting systemd-hostnamed.service - Hostname Service... Dec 23 18:35:00 my-volumio-3 kernel: NET: Registered PF_ALG protocol family Dec 23 18:35:00 my-volumio-3 kernel: cryptd: max_cpu_qlen set to 1000 Dec 23 18:35:00 my-volumio-3 ntpd[873]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 23 18:35:00 my-volumio-3 ntpd[873]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Dec 23 18:35:00 my-volumio-3 ntpd[873]: DNS: dns_check: DNS error: -11, System error Dec 23 18:35:00 my-volumio-3 ntpd[873]: DNS: dns_take_status: 0.debian.pool.ntp.org=>error, 12 Dec 23 18:35:01 my-volumio-3 dbus-daemon[653]: [system] Successfully activated service 'org.freedesktop.hostname1' Dec 23 18:35:01 my-volumio-3 systemd[1]: Started systemd-hostnamed.service - Hostname Service. Dec 23 18:35:01 my-volumio-3 bluetoothd[915]: profiles/audio/bap.c:bap_adapter_probe() BAP requires ISO Socket which is not enabled Dec 23 18:35:01 my-volumio-3 bluetoothd[915]: bap: Operation not supported (95) Dec 23 18:35:01 my-volumio-3 bluetoothd[915]: Adv Monitor Manager created with supported features:0x00000000, enabled features:0x00000000, max number of supported monitors:32, max number of supported patterns:16 Dec 23 18:35:01 my-volumio-3 bluealsa[974]: ../src/storage.c:90: Initializing persistent storage: /var/lib/bluealsa Dec 23 18:35:01 my-volumio-3 bluealsa[974]: main.c:663: Starting main dispatching loop Dec 23 18:35:01 my-volumio-3 systemd[1]: Started bluealsa.service - BlueALSA service. Dec 23 18:35:01 my-volumio-3 systemd[1]: Reached target bluetooth.target - Bluetooth Support. Dec 23 18:35:01 my-volumio-3 bluealsa[974]: main.c:118: Acquired D-Bus service name: org.bluealsa Dec 23 18:35:01 my-volumio-3 bluealsa[974]: bluealsa-dbus.c:358: Registering BlueALSA D-Bus manager: /org/bluealsa Dec 23 18:35:01 my-volumio-3 bluealsa[974]: bluez.c:153: Registering media application: /org/bluez/hci0 Dec 23 18:35:01 my-volumio-3 bluealsa[974]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/source/1 Dec 23 18:35:01 my-volumio-3 bluealsa[974]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/source/2 Dec 23 18:35:01 my-volumio-3 bluealsa[974]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/1 Dec 23 18:35:01 my-volumio-3 bluealsa[974]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/2 Dec 23 18:35:01 my-volumio-3 dbus-daemon[653]: [system] Activating via systemd: service name='org.freedesktop.UPower' unit='upower.service' requested by ':1.8' (uid=0 pid=974 comm="/usr/bin/bluealsa -S -p a2dp-source -p a2dp-sink") Dec 23 18:35:01 my-volumio-3 ntpd[873]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 23 18:35:01 my-volumio-3 ntpd[873]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Dec 23 18:35:01 my-volumio-3 ntpd[873]: DNS: dns_check: DNS error: -11, System error Dec 23 18:35:01 my-volumio-3 ntpd[873]: DNS: dns_take_status: 1.debian.pool.ntp.org=>error, 12 Dec 23 18:35:01 my-volumio-3 bluetoothd[915]: Endpoint registered: sender=:1.8 path=/org/bluez/hci0/A2DP/SBC/sink/2 Dec 23 18:35:01 my-volumio-3 systemd[1]: Starting upower.service - Daemon for power management... Dec 23 18:35:02 my-volumio-3 systemd[1]: samba-ad-dc.service: Skipped due to 'exec-condition'. Dec 23 18:35:02 my-volumio-3 systemd[1]: Condition check resulted in samba-ad-dc.service - Samba AD Daemon being skipped. Dec 23 18:35:02 my-volumio-3 dbus-daemon[653]: [system] Successfully activated service 'org.freedesktop.UPower' Dec 23 18:35:02 my-volumio-3 systemd[1]: Started upower.service - Daemon for power management. Dec 23 18:35:02 my-volumio-3 bluetoothd[915]: Endpoint registered: sender=:1.8 path=/org/bluez/hci0/A2DP/SBC/source/1 Dec 23 18:35:02 my-volumio-3 bluetoothd[915]: Endpoint registered: sender=:1.8 path=/org/bluez/hci0/A2DP/SBC/source/2 Dec 23 18:35:02 my-volumio-3 bluetoothd[915]: Endpoint registered: sender=:1.8 path=/org/bluez/hci0/A2DP/SBC/sink/1 Dec 23 18:35:02 my-volumio-3 nmbd[1027]: [2025/12/23 18:35:02.758731, 0] ../../source3/nmbd/nmbd.c:901(main) Dec 23 18:35:02 my-volumio-3 nmbd[1027]: nmbd version 4.17.8-Raspbian started. Dec 23 18:35:02 my-volumio-3 nmbd[1027]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Dec 23 18:35:02 my-volumio-3 nmbd[1027]: [2025/12/23 18:35:02.781468, 0] ../../source3/nmbd/asyncdns.c:158(start_async_dns) Dec 23 18:35:02 my-volumio-3 nmbd[1027]: started asyncdns process 1029 Dec 23 18:35:02 my-volumio-3 nmbd[1027]: [2025/12/23 18:35:02.782813, 0] ../../lib/util/become_daemon.c:150(daemon_status) Dec 23 18:35:02 my-volumio-3 nmbd[1027]: daemon_status: daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Dec 23 18:35:02 my-volumio-3 nmbd[1027]: [2025/12/23 18:35:02.782965, 0] ../../source3/nmbd/nmbd_subnetdb.c:252(create_subnets) Dec 23 18:35:02 my-volumio-3 nmbd[1027]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Dec 23 18:35:02 my-volumio-3 ntpd[873]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 23 18:35:02 my-volumio-3 ntpd[873]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Dec 23 18:35:02 my-volumio-3 ntpd[873]: DNS: dns_check: DNS error: -11, System error Dec 23 18:35:02 my-volumio-3 ntpd[873]: DNS: dns_take_status: 2.debian.pool.ntp.org=>error, 12 Dec 23 18:35:03 my-volumio-3 wireless.js[687]: WIRELESS.JS: Single Network Mode enabled, only one network device can be active at a time between ethernet and wireless Dec 23 18:35:03 my-volumio-3 wireless.js[687]: WIRELESS.JS: Wireless.js initializing wireless flow Dec 23 18:35:03 my-volumio-3 wireless.js[687]: WIRELESS.JS: Cleaning previous... Dec 23 18:35:03 my-volumio-3 volumio-remote-updater[684]: [2025-12-23 18:35:03] [info] asio async_connect error: asio.system:111 (Connection refused) Dec 23 18:35:03 my-volumio-3 volumio-remote-updater[684]: [2025-12-23 18:35:03] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Dec 23 18:35:03 my-volumio-3 volumio-remote-updater[684]: [2025-12-23 18:35:03] [error] handle_connect error: Connection refused Dec 23 18:35:03 my-volumio-3 ntpd[873]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 23 18:35:03 my-volumio-3 ntpd[873]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Dec 23 18:35:03 my-volumio-3 ntpd[873]: DNS: dns_check: DNS error: -11, System error Dec 23 18:35:03 my-volumio-3 ntpd[873]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12 Dec 23 18:35:03 my-volumio-3 sudo[1045]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Dec 23 18:35:03 my-volumio-3 sudo[1045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 23 18:35:03 my-volumio-3 sudo[1045]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:03 my-volumio-3 sudo[1053]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Dec 23 18:35:04 my-volumio-3 sudo[1053]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 23 18:35:04 my-volumio-3 systemd[1]: systemd-rfkill.service: Deactivated successfully. Dec 23 18:35:04 my-volumio-3 sudo[1053]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:04 my-volumio-3 wireless.js[687]: WIRELESS.JS: Stopped aP Dec 23 18:35:04 my-volumio-3 sudo[1062]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 23 18:35:04 my-volumio-3 sudo[1062]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:35:04 my-volumio-3 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 23 18:35:04 my-volumio-3 sudo[1062]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:04 my-volumio-3 sudo[1064]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Dec 23 18:35:04 my-volumio-3 sudo[1064]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:35:05 my-volumio-3 sudo[1064]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:05 my-volumio-3 sudo[1077]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 23 18:35:05 my-volumio-3 sudo[1077]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:35:05 my-volumio-3 sudo[1077]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:05 my-volumio-3 sudo[1080]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Dec 23 18:35:05 my-volumio-3 sudo[1080]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:35:07 my-volumio-3 sudo[1080]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:07 my-volumio-3 wireless.js[687]: WIRELESS.JS: SETTING APPROPRIATE REG DOMAIN: PK Dec 23 18:35:08 my-volumio-3 sudo[1098]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 23 18:35:08 my-volumio-3 sudo[1098]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:35:08 my-volumio-3 sudo[1098]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:08 my-volumio-3 sudo[1100]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set PK Dec 23 18:35:08 my-volumio-3 sudo[1100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:35:08 my-volumio-3 sudo[1100]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:08 my-volumio-3 kernel: ieee80211 phy0: brcmf_cfg80211_reg_notifier: Firmware rejected country setting Dec 23 18:35:08 my-volumio-3 wireless.js[687]: WIRELESS.JS: SUCCESSFULLY SET NEW REGDOMAIN: PK Dec 23 18:35:08 my-volumio-3 wireless.js[687]: WIRELESS.JS: Start wireless flow Dec 23 18:35:08 my-volumio-3 wireless.js[687]: WIRELESS.JS: Stopped hotspot (if there).. Dec 23 18:35:08 my-volumio-3 sudo[1108]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Dec 23 18:35:08 my-volumio-3 sudo[1108]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 23 18:35:08 my-volumio-3 sudo[1108]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:08 my-volumio-3 bash[850]: setdatetime-helper: all HTTPS Date fallbacks failed Dec 23 18:35:08 my-volumio-3 systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 23 18:35:08 my-volumio-3 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 23 18:35:08 my-volumio-3 systemd[1]: setdatetime-helper.service: Consumed 1.416s CPU time. Dec 23 18:35:08 my-volumio-3 sudo[1110]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Dec 23 18:35:08 my-volumio-3 sudo[1110]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 23 18:35:08 my-volumio-3 sudo[1110]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:08 my-volumio-3 wireless.js[687]: WIRELESS.JS: DHCP IP fallback Dec 23 18:35:08 my-volumio-3 wireless.js[687]: WIRELESS.JS: Start ap Dec 23 18:35:08 my-volumio-3 wpa_supplicant[1116]: Successfully initialized wpa_supplicant Dec 23 18:35:08 my-volumio-3 sudo[1117]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Dec 23 18:35:08 my-volumio-3 sudo[1117]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 23 18:35:08 my-volumio-3 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 23 18:35:08 my-volumio-3 dhcpcd[804]: control command: /sbin/dhcpcd Dec 23 18:35:08 my-volumio-3 sudo[1117]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:08 my-volumio-3 dhcpcd[804]: control_free: No such file or directory Dec 23 18:35:08 my-volumio-3 dhcpcd[804]: lo: IAID 00:00:00:00 Dec 23 18:35:08 my-volumio-3 dhcpcd[804]: lo: adding address fe80::b168:f2db:70ba:e2d7 Dec 23 18:35:08 my-volumio-3 dhcpcd[804]: ipv6_addaddr1: Permission denied Dec 23 18:35:08 my-volumio-3 dhcpcd[804]: lo: using static address 127.0.0.1/8 Dec 23 18:35:08 my-volumio-3 dhcpcd[804]: lo: adding route to 127.0.0.0/8 Dec 23 18:35:08 my-volumio-3 systemd[1]: Reached target ip-changed@lo.target - IP Address changed on lo. Dec 23 18:35:09 my-volumio-3 wpa_supplicant[1116]: nl80211: kernel reports: Registration to specific type not supported Dec 23 18:35:09 my-volumio-3 wireless.js[687]: WIRELESS.JS: trying... Dec 23 18:35:09 my-volumio-3 sudo[1143]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 23 18:35:09 my-volumio-3 sudo[1143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:35:09 my-volumio-3 sudo[1143]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:10 my-volumio-3 wireless.js[687]: WIRELESS.JS: trying... Dec 23 18:35:10 my-volumio-3 sudo[1147]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 23 18:35:10 my-volumio-3 sudo[1147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:35:10 my-volumio-3 sudo[1147]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:11 my-volumio-3 volumio-remote-updater[684]: [2025-12-23 18:35:11] [info] asio async_connect error: asio.system:111 (Connection refused) Dec 23 18:35:11 my-volumio-3 volumio-remote-updater[684]: [2025-12-23 18:35:11] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Dec 23 18:35:11 my-volumio-3 volumio-remote-updater[684]: [2025-12-23 18:35:11] [error] handle_connect error: Connection refused Dec 23 18:35:11 my-volumio-3 wireless.js[687]: WIRELESS.JS: trying... Dec 23 18:35:11 my-volumio-3 sudo[1151]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 23 18:35:11 my-volumio-3 sudo[1151]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:35:11 my-volumio-3 sudo[1151]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:12 my-volumio-3 wpa_supplicant[1140]: wlan0: Trying to associate with 60:32:b1:fe:5b:fd (SSID='TP-Link_2BFD' freq=2417 MHz) Dec 23 18:35:12 my-volumio-3 wpa_supplicant[1140]: wlan0: Associated with 60:32:b1:fe:5b:fd Dec 23 18:35:12 my-volumio-3 wpa_supplicant[1140]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Dec 23 18:35:12 my-volumio-3 wpa_supplicant[1140]: wlan0: WPA: Key negotiation completed with 60:32:b1:fe:5b:fd [PTK=CCMP GTK=CCMP] Dec 23 18:35:12 my-volumio-3 wpa_supplicant[1140]: wlan0: CTRL-EVENT-CONNECTED - Connection to 60:32:b1:fe:5b:fd completed [id=0 id_str=] Dec 23 18:35:12 my-volumio-3 dhcpcd[804]: wlan0: carrier acquired Dec 23 18:35:12 my-volumio-3 dhcpcd[804]: wlan0: connected to Access Point: TP-Link_2BFD Dec 23 18:35:12 my-volumio-3 dhcpcd[804]: wlan0: IAID eb:e6:5e:29 Dec 23 18:35:12 my-volumio-3 dhcpcd[804]: wlan0: adding address fe80::a6a0:89e2:3441:f637 Dec 23 18:35:12 my-volumio-3 dhcpcd[804]: ipv6_addaddr1: Permission denied Dec 23 18:35:12 my-volumio-3 dhcpcd[804]: wlan0: soliciting an IPv6 router Dec 23 18:35:12 my-volumio-3 wireless.js[687]: WIRELESS.JS: trying... Dec 23 18:35:12 my-volumio-3 sudo[1156]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 23 18:35:12 my-volumio-3 sudo[1156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:35:12 my-volumio-3 sudo[1156]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:13 my-volumio-3 dhcpcd[804]: wlan0: rebinding lease of 192.168.11.182 Dec 23 18:35:13 my-volumio-3 dhcpcd[804]: wlan0: probing address 192.168.11.182/24 Dec 23 18:35:13 my-volumio-3 wireless.js[687]: WIRELESS.JS: trying... Dec 23 18:35:13 my-volumio-3 sudo[1162]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 23 18:35:13 my-volumio-3 sudo[1162]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:35:13 my-volumio-3 sudo[1162]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:14 my-volumio-3 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Dec 23 18:35:14 my-volumio-3 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 23 18:35:14 my-volumio-3 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 23 18:35:14 my-volumio-3 upmpdcli[1164]: Could not open config: /tmp/upmpdcli.conf Dec 23 18:35:14 my-volumio-3 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 23 18:35:14 my-volumio-3 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 23 18:35:14 my-volumio-3 wireless.js[687]: WIRELESS.JS: trying... Dec 23 18:35:14 my-volumio-3 sudo[1167]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 23 18:35:14 my-volumio-3 sudo[1167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:35:14 my-volumio-3 sudo[1167]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:15 my-volumio-3 wireless.js[687]: WIRELESS.JS: trying... Dec 23 18:35:15 my-volumio-3 sudo[1171]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 23 18:35:15 my-volumio-3 sudo[1171]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:35:15 my-volumio-3 sudo[1171]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:16 my-volumio-3 wireless.js[687]: WIRELESS.JS: trying... Dec 23 18:35:16 my-volumio-3 sudo[1175]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 23 18:35:16 my-volumio-3 sudo[1175]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:35:16 my-volumio-3 sudo[1175]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:17 my-volumio-3 wireless.js[687]: WIRELESS.JS: trying... Dec 23 18:35:17 my-volumio-3 sudo[1179]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 23 18:35:17 my-volumio-3 dhcpcd[804]: wlan0: leased 192.168.11.182 for 7200 seconds Dec 23 18:35:17 my-volumio-3 avahi-daemon[650]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.11.182. Dec 23 18:35:17 my-volumio-3 sudo[1179]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:35:17 my-volumio-3 avahi-daemon[650]: New relevant interface wlan0.IPv4 for mDNS. Dec 23 18:35:17 my-volumio-3 avahi-daemon[650]: Registering new address record for 192.168.11.182 on wlan0.IPv4. Dec 23 18:35:17 my-volumio-3 dhcpcd[804]: wlan0: adding route to 192.168.11.0/24 Dec 23 18:35:17 my-volumio-3 dhcpcd[804]: wlan0: adding default route via 192.168.11.1 Dec 23 18:35:17 my-volumio-3 sudo[1179]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:17 my-volumio-3 systemd[1]: welcome.service: Deactivated successfully. Dec 23 18:35:17 my-volumio-3 wireless.js[687]: WIRELESS.JS: Connected to: ----TP-Link_2BFD---- Dec 23 18:35:17 my-volumio-3 systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 23 18:35:17 my-volumio-3 systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 23 18:35:18 my-volumio-3 systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 23 18:35:18 my-volumio-3 sudo[1193]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 23 18:35:18 my-volumio-3 sudo[1193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 23 18:35:18 my-volumio-3 welcome[1187]: Resolved ip:[1] 192.168.11.182 Dec 23 18:35:18 my-volumio-3 systemd[1]: Started nmbd.service - Samba NMB Daemon. Dec 23 18:35:18 my-volumio-3 sudo[1193]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:18 my-volumio-3 systemd[1]: Starting winbind.service - Samba Winbind Daemon... Dec 23 18:35:18 my-volumio-3 wireless.js[687]: WIRELESS.JS: ... joined AP, wlan0 IPv4 is 192.168.11.182, ipV6 is undefined Dec 23 18:35:18 my-volumio-3 wireless.js[687]: WIRELESS.JS: It's done! AP Dec 23 18:35:18 my-volumio-3 systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 23 18:35:18 my-volumio-3 systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 23 18:35:18 my-volumio-3 wireless.js[687]: WIRELESS.JS: Restarting avahi-daemon... Dec 23 18:35:18 my-volumio-3 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 23 18:35:18 my-volumio-3 systemd[1]: shairport-sync.service: Deactivated successfully. Dec 23 18:35:18 my-volumio-3 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 23 18:35:18 my-volumio-3 systemd[1]: shairport-sync.service: Consumed 1.447s CPU time. Dec 23 18:35:18 my-volumio-3 avahi-daemon[650]: Got SIGTERM, quitting. Dec 23 18:35:18 my-volumio-3 avahi-daemon[650]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.11.182. Dec 23 18:35:18 my-volumio-3 avahi-daemon[650]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Dec 23 18:35:18 my-volumio-3 systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Dec 23 18:35:18 my-volumio-3 avahi-daemon[650]: avahi-daemon 0.8 exiting. Dec 23 18:35:18 my-volumio-3 systemd[1]: avahi-daemon.service: Deactivated successfully. Dec 23 18:35:18 my-volumio-3 systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Dec 23 18:35:18 my-volumio-3 wireless.js[687]: WIRELESS.JS: Notified systemd about wireless ready Dec 23 18:35:18 my-volumio-3 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 23 18:35:18 my-volumio-3 systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Dec 23 18:35:18 my-volumio-3 systemd[1]: Started wireless.service - Wireless Services. Dec 23 18:35:18 my-volumio-3 avahi-daemon[1218]: Process 650 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) Dec 23 18:35:18 my-volumio-3 avahi-daemon[1218]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Dec 23 18:35:18 my-volumio-3 avahi-daemon[1218]: Successfully dropped root privileges. Dec 23 18:35:18 my-volumio-3 avahi-daemon[1218]: avahi-daemon 0.8 starting up. Dec 23 18:35:18 my-volumio-3 systemd[1]: Started volumio.service - Volumio Backend Module. Dec 23 18:35:18 my-volumio-3 systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... Dec 23 18:35:18 my-volumio-3 avahi-daemon[1218]: Successfully called chroot(). Dec 23 18:35:18 my-volumio-3 avahi-daemon[1218]: Successfully dropped remaining capabilities. Dec 23 18:35:18 my-volumio-3 avahi-daemon[1218]: Loading service file /services/volumio.service. Dec 23 18:35:18 my-volumio-3 avahi-daemon[1218]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.11.182. Dec 23 18:35:18 my-volumio-3 avahi-daemon[1218]: New relevant interface wlan0.IPv4 for mDNS. Dec 23 18:35:18 my-volumio-3 avahi-daemon[1218]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Dec 23 18:35:18 my-volumio-3 avahi-daemon[1218]: New relevant interface lo.IPv4 for mDNS. Dec 23 18:35:18 my-volumio-3 avahi-daemon[1218]: Network interface enumeration completed. Dec 23 18:35:18 my-volumio-3 avahi-daemon[1218]: Registering new address record for 192.168.11.182 on wlan0.IPv4. Dec 23 18:35:18 my-volumio-3 avahi-daemon[1218]: Registering new address record for 127.0.0.1 on lo.IPv4. Dec 23 18:35:18 my-volumio-3 systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker. Dec 23 18:35:18 my-volumio-3 systemd[1]: Received SIGRTMIN+21 from PID 283 (plymouthd). Dec 23 18:35:18 my-volumio-3 systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Dec 23 18:35:18 my-volumio-3 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 23 18:35:18 my-volumio-3 systemd[1]: Received SIGRTMIN+21 from PID 283 (plymouthd). Dec 23 18:35:18 my-volumio-3 systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. Dec 23 18:35:18 my-volumio-3 systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. Dec 23 18:35:18 my-volumio-3 systemd[1]: Started getty@tty1.service - Getty on tty1. Dec 23 18:35:18 my-volumio-3 systemd[1]: Reached target getty.target - Login Prompts. Dec 23 18:35:18 my-volumio-3 volumio-cpu-tweak[1222]: Setting RT Priority for mpd Dec 23 18:35:18 my-volumio-3 volumio-cpu-tweak[1250]: pid 35's current scheduling policy: SCHED_OTHER Dec 23 18:35:18 my-volumio-3 volumio-cpu-tweak[1250]: pid 35's current scheduling priority: 0 Dec 23 18:35:18 my-volumio-3 volumio-cpu-tweak[1222]: Setting MPD Affinity Dec 23 18:35:18 my-volumio-3 volumio-cpu-tweak[1252]: pid 3's current affinity mask: f Dec 23 18:35:18 my-volumio-3 volumio-cpu-tweak[1222]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Dec 23 18:35:18 my-volumio-3 volumio-cpu-tweak[1222]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Dec 23 18:35:18 my-volumio-3 systemd[1]: volumio_cpu_tweak.service: Deactivated successfully. Dec 23 18:35:18 my-volumio-3 winbindd[1216]: [2025/12/23 18:35:18.965671, 0] ../../source3/winbindd/winbindd.c:1440(main) Dec 23 18:35:18 my-volumio-3 winbindd[1216]: winbindd version 4.17.8-Raspbian started. Dec 23 18:35:18 my-volumio-3 winbindd[1216]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Dec 23 18:35:18 my-volumio-3 winbindd[1216]: [2025/12/23 18:35:18.987311, 0] ../../source3/winbindd/winbindd_cache.c:3116(initialize_winbindd_cache) Dec 23 18:35:18 my-volumio-3 winbindd[1216]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Dec 23 18:35:19 my-volumio-3 systemd[1]: Started winbind.service - Samba Winbind Daemon. Dec 23 18:35:19 my-volumio-3 systemd[1]: Starting smbd.service - Samba SMB Daemon... Dec 23 18:35:19 my-volumio-3 avahi-daemon[1218]: Server startup complete. Host name is my-volumio-3.local. Local service cookie is 2094798116. Dec 23 18:35:19 my-volumio-3 ntpd[873]: IO: Listen normally on 3 wlan0 192.168.11.182:123 Dec 23 18:35:19 my-volumio-3 ntpd[873]: IO: new interface(s) found: waking up resolver Dec 23 18:35:19 my-volumio-3 ntpd[873]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 23 18:35:19 my-volumio-3 ntpd[873]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Dec 23 18:35:19 my-volumio-3 ntpd[873]: DNS: Pool taking: 203.99.62.214 Dec 23 18:35:19 my-volumio-3 ntpd[873]: DNS: Pool taking: 203.80.128.20 Dec 23 18:35:19 my-volumio-3 ntpd[873]: DNS: Pool taking: 103.152.101.249 Dec 23 18:35:19 my-volumio-3 ntpd[873]: DNS: Pool taking: 103.55.68.158 Dec 23 18:35:19 my-volumio-3 ntpd[873]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Dec 23 18:35:19 my-volumio-3 smbd[1273]: [2025/12/23 18:35:19.980420, 0] ../../source3/smbd/server.c:1741(main) Dec 23 18:35:19 my-volumio-3 smbd[1273]: smbd version 4.17.8-Raspbian started. Dec 23 18:35:19 my-volumio-3 smbd[1273]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Dec 23 18:35:20 my-volumio-3 avahi-daemon[1218]: Service "My Volumio 3" (/services/volumio.service) successfully established. Dec 23 18:35:20 my-volumio-3 ntpd[873]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 23 18:35:20 my-volumio-3 ntpd[873]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Dec 23 18:35:20 my-volumio-3 ntpd[873]: DNS: Pool skipping: 203.99.62.214 Dec 23 18:35:20 my-volumio-3 ntpd[873]: DNS: Pool skipping: 203.80.128.20 Dec 23 18:35:20 my-volumio-3 ntpd[873]: DNS: Pool skipping: 103.55.68.158 Dec 23 18:35:20 my-volumio-3 ntpd[873]: DNS: Pool skipping: 103.152.101.249 Dec 23 18:35:20 my-volumio-3 ntpd[873]: DNS: Pool taking: 2001:da8:a807::25 Dec 23 18:35:20 my-volumio-3 ntpd[873]: DNS: Pool taking: 240b:400e:5d:6d00:46e6:5a9e:75d6:461f Dec 23 18:35:20 my-volumio-3 ntpd[873]: DNS: Pool taking: 2405:8d40:f27:cd00:1620:c0:5bed:33c Dec 23 18:35:20 my-volumio-3 ntpd[873]: DNS: Pool taking: 2401:b60:5:3fd:d6d7:afdb:a38a:aa1 Dec 23 18:35:20 my-volumio-3 ntpd[873]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Dec 23 18:35:21 my-volumio-3 volumio-remote-updater[684]: [2025-12-23 18:35:21] [info] asio async_connect error: asio.system:111 (Connection refused) Dec 23 18:35:21 my-volumio-3 volumio-remote-updater[684]: [2025-12-23 18:35:21] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Dec 23 18:35:21 my-volumio-3 volumio-remote-updater[684]: [2025-12-23 18:35:21] [error] handle_connect error: Connection refused Dec 23 18:35:21 my-volumio-3 systemd[1]: Started smbd.service - Samba SMB Daemon. Dec 23 18:35:21 my-volumio-3 systemd[1]: Reached target multi-user.target - Multi-User System. Dec 23 18:35:21 my-volumio-3 systemd[1]: Reached target graphical.target - Graphical Interface. Dec 23 18:35:21 my-volumio-3 ntpd[873]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 23 18:35:21 my-volumio-3 ntpd[873]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Dec 23 18:35:21 my-volumio-3 ntpd[873]: DNS: Pool skipping: 203.99.62.214 Dec 23 18:35:21 my-volumio-3 ntpd[873]: DNS: Pool skipping: 203.80.128.20 Dec 23 18:35:21 my-volumio-3 ntpd[873]: DNS: Pool skipping: 103.55.68.158 Dec 23 18:35:21 my-volumio-3 ntpd[873]: DNS: Pool skipping: 103.152.101.249 Dec 23 18:35:21 my-volumio-3 ntpd[873]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Dec 23 18:35:21 my-volumio-3 systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Dec 23 18:35:21 my-volumio-3 systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Dec 23 18:35:21 my-volumio-3 systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Dec 23 18:35:21 my-volumio-3 systemd[1]: Startup finished in 16.584s (kernel) + 29.817s (userspace) = 46.402s. Dec 23 18:35:22 my-volumio-3 ntpd[873]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 23 18:35:22 my-volumio-3 ntpd[873]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Dec 23 18:35:22 my-volumio-3 ntpd[873]: DNS: Pool skipping: 203.99.62.214 Dec 23 18:35:22 my-volumio-3 ntpd[873]: DNS: Pool skipping: 203.80.128.20 Dec 23 18:35:22 my-volumio-3 ntpd[873]: DNS: Pool skipping: 103.152.101.249 Dec 23 18:35:22 my-volumio-3 ntpd[873]: DNS: Pool skipping: 103.55.68.158 Dec 23 18:35:22 my-volumio-3 ntpd[873]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Dec 23 18:35:25 my-volumio-3 volumio[1219]: info: ------------------------------------------- Dec 23 18:35:25 my-volumio-3 volumio[1219]: info: ----- Volumio3 ---- Dec 23 18:35:25 my-volumio-3 volumio[1219]: info: ------------------------------------------- Dec 23 18:35:25 my-volumio-3 volumio[1219]: info: ----- System startup ---- Dec 23 18:35:25 my-volumio-3 volumio[1219]: info: ------------------------------------------- Dec 23 18:35:25 my-volumio-3 systemd[1]: systemd-fsckd.service: Deactivated successfully. Dec 23 18:35:50 my-volumio-3 ntpd[873]: CLOCK: time stepped by 24.799058 Dec 23 18:35:50 my-volumio-3 ntpd[873]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: MYVOLUMIO Environment detected Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Plugin folders cleanup Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Scanning into folder /volumio/app/plugins/ Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Scanning category audio_interface Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Scanning category miscellanea Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Scanning category music_service Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Scanning category plugins.json Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Scanning category system_controller Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Scanning category user_interface Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Scanning into folder /data/plugins/ Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Scanning category music_service Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Scanning category system_hardware Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Scanning category user_interface Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Plugin folders cleanup completed Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: ------------------------------------------- Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: ----- Core plugins startup ---- Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: ------------------------------------------- Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Loading plugins from folder /volumio/app/plugins/ Dec 23 18:35:51 my-volumio-3 sh[618]: timed out Dec 23 18:35:51 my-volumio-3 dhcpcd[627]: timed out Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Adding plugin upnp to MyMusic Plugins Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 23 18:35:51 my-volumio-3 sh[563]: ifup: failed to bring up eth0 Dec 23 18:35:51 my-volumio-3 systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Dec 23 18:35:51 my-volumio-3 systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Loading plugins from folder /data/plugins/ Dec 23 18:35:51 my-volumio-3 volumio[1219]: info: Loading plugin "system"... Dec 23 18:35:52 my-volumio-3 volumio[1219]: info: Loading plugin "appearance"... Dec 23 18:35:54 my-volumio-3 volumio[1219]: info: Loading plugin "network"... Dec 23 18:35:54 my-volumio-3 volumio[1219]: info: Refreshing Cached IP Addresses Dec 23 18:35:54 my-volumio-3 sudo[1303]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 23 18:35:54 my-volumio-3 sudo[1303]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:35:54 my-volumio-3 sudo[1303]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:54 my-volumio-3 sudo[1305]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 23 18:35:54 my-volumio-3 sudo[1305]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:35:54 my-volumio-3 sudo[1305]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:54 my-volumio-3 volumio[1219]: info: Loading plugin "services"... Dec 23 18:35:54 my-volumio-3 volumio[1219]: info: Loading plugin "alsa_controller"... Dec 23 18:35:54 my-volumio-3 sudo[1318]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 23 18:35:54 my-volumio-3 sudo[1318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:35:54 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 23 18:35:54 my-volumio-3 volumio[1219]: info: Loading plugin "wizard"... Dec 23 18:35:54 my-volumio-3 volumio[1219]: info: Loading plugin "networkfs"... Dec 23 18:35:54 my-volumio-3 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Dec 23 18:35:54 my-volumio-3 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 23 18:35:54 my-volumio-3 volumio[1219]: info: Starting Udev Watcher for removable devices Dec 23 18:35:54 my-volumio-3 volumio[1219]: info: Ignoring mount for partition: boot Dec 23 18:35:54 my-volumio-3 volumio[1219]: info: Ignoring mount for partition: volumio Dec 23 18:35:54 my-volumio-3 volumio[1219]: info: Ignoring mount for partition: volumio_data Dec 23 18:35:54 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 23 18:35:54 my-volumio-3 volumio[1219]: info: Loading plugin "volumio_command_line_client"... Dec 23 18:35:54 my-volumio-3 volumio[1219]: info: Loading plugin "upnp"... Dec 23 18:35:54 my-volumio-3 volumio[1219]: info: [1766496954785] Starting Upmpd Daemon Dec 23 18:35:54 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 23 18:35:54 my-volumio-3 volumio[1219]: info: Loading plugin "my_music"... Dec 23 18:35:54 my-volumio-3 volumio[1219]: info: Loading plugin "mpd"... Dec 23 18:35:54 my-volumio-3 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 23 18:35:54 my-volumio-3 upmpdcli[1337]: Could not open config: /tmp/upmpdcli.conf Dec 23 18:35:54 my-volumio-3 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 23 18:35:54 my-volumio-3 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 23 18:35:55 my-volumio-3 volumio[1219]: info: Loading plugin "upnp_browser"... Dec 23 18:35:56 my-volumio-3 volumio-remote-updater[684]: [2025-12-23 18:35:56] [connect] Successful connection Dec 23 18:35:56 my-volumio-3 systemd[1]: systemd-hostnamed.service: Deactivated successfully. Dec 23 18:35:57 my-volumio-3 volumio[1219]: info: Starting UPNP Browser Dec 23 18:35:57 my-volumio-3 volumio[1219]: info: Loading plugin "alarm-clock"... Dec 23 18:35:58 my-volumio-3 volumio[1219]: info: Plugin airplay_emulation is not enabled Dec 23 18:35:58 my-volumio-3 volumio[1219]: info: Loading plugin "last_100"... Dec 23 18:35:58 my-volumio-3 volumio[1219]: info: Loading plugin "webradio"... Dec 23 18:35:58 my-volumio-3 volumio[1219]: info: Loading plugin "i2s_dacs"... Dec 23 18:35:58 my-volumio-3 volumio[1219]: info: I2S DAC not set, start Auto-detection Dec 23 18:35:58 my-volumio-3 volumio[1219]: info: Loading plugin "volumiodiscovery"... Dec 23 18:35:58 my-volumio-3 volumio[1219]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 23 18:35:58 my-volumio-3 volumio[1219]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 23 18:35:58 my-volumio-3 volumio[1219]: *** WARNING *** For more information see Dec 23 18:35:58 my-volumio-3 volumio[1219]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 23 18:35:58 my-volumio-3 volumio[1219]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 23 18:35:58 my-volumio-3 volumio[1219]: *** WARNING *** For more information see Dec 23 18:35:58 my-volumio-3 node[1219]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 23 18:35:58 my-volumio-3 node[1219]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 23 18:35:58 my-volumio-3 node[1219]: *** WARNING *** For more information see Dec 23 18:35:58 my-volumio-3 node[1219]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 23 18:35:58 my-volumio-3 node[1219]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 23 18:35:58 my-volumio-3 node[1219]: *** WARNING *** For more information see Dec 23 18:35:58 my-volumio-3 volumio[1219]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 23 18:35:58 my-volumio-3 volumio[1219]: info: Discovery: Started advertising with name: My Volumio 3 Dec 23 18:35:58 my-volumio-3 sudo[1318]: pam_unix(sudo:session): session closed for user root Dec 23 18:35:58 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 23 18:35:58 my-volumio-3 volumio[1219]: info: Loading plugin "spop"... Dec 23 18:36:01 my-volumio-3 volumio[1219]: info: Loading plugin "youtube2"... Dec 23 18:36:02 my-volumio-3 systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 23 18:36:03 my-volumio-3 volumio[1219]: info: Loading plugin "ytmusic"... Dec 23 18:36:05 my-volumio-3 volumio[1219]: info: Loading plugin "outputs"... Dec 23 18:36:05 my-volumio-3 volumio[1219]: info: Loading plugin "albumart"... Dec 23 18:36:05 my-volumio-3 volumio[1219]: info: Plugin example_plugin is not enabled Dec 23 18:36:05 my-volumio-3 volumio[1219]: info: Loading plugin "inputs"... Dec 23 18:36:05 my-volumio-3 volumio[1219]: info: Loading plugin "updater_comm"... Dec 23 18:36:05 my-volumio-3 volumio[1219]: info: Plugin mpdemulation is not enabled Dec 23 18:36:05 my-volumio-3 volumio[1219]: info: Loading plugin "rest_api"... Dec 23 18:36:05 my-volumio-3 volumio[1219]: info: Loading plugin "websocket"... Dec 23 18:36:06 my-volumio-3 volumio[1219]: info: Starting Socket.io Server version 1.7.4 Dec 23 18:36:06 my-volumio-3 volumio[1219]: info: Loading plugin "RoonBridge"... Dec 23 18:36:07 my-volumio-3 systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 23 18:36:07 my-volumio-3 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 23 18:36:07 my-volumio-3 volumio[1373]: Forking 3 albumart workers Dec 23 18:36:07 my-volumio-3 volumio[1219]: info: Applying required configuration parameters for plugin RoonBridge Dec 23 18:36:07 my-volumio-3 volumio[1219]: info: Loading plugin "mpd_oled"... Dec 23 18:36:10 my-volumio-3 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Dec 23 18:36:10 my-volumio-3 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 23 18:36:10 my-volumio-3 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 23 18:36:10 my-volumio-3 upmpdcli[1422]: Could not open config: /tmp/upmpdcli.conf Dec 23 18:36:10 my-volumio-3 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 23 18:36:10 my-volumio-3 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 23 18:36:10 my-volumio-3 volumio[1219]: info: Applying required configuration parameters for plugin mpd_oled Dec 23 18:36:10 my-volumio-3 volumio[1219]: info: [MPD_OLED Plugin] Reading configuration file at: /data/configuration/system_hardware/mpd_oled/config.json Dec 23 18:36:10 my-volumio-3 volumio[1219]: info: Loading plugin "Systeminfo"... Dec 23 18:36:11 my-volumio-3 volumio-remote-updater[684]: [2025-12-23 18:36:11] [connect] Successful connection Dec 23 18:36:15 my-volumio-3 volumio[1219]: info: Plugin touch_display is not enabled Dec 23 18:36:15 my-volumio-3 volumio[1219]: info: Loading i18n strings for locale en Dec 23 18:36:16 my-volumio-3 volumio[1219]: Updating browse sources language Dec 23 18:36:16 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 23 18:36:17 my-volumio-3 volumio[1392]: Starting albumart workers Dec 23 18:36:17 my-volumio-3 volumio[1394]: Starting albumart workers Dec 23 18:36:17 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 23 18:36:17 my-volumio-3 volumio[1219]: info: CoreCommandRouter::initPlayerControls Dec 23 18:36:17 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:17 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:18 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:18 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:18 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:18 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:18 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:18 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:18 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 23 18:36:18 my-volumio-3 volumio[1219]: Express server listening on port 3000 Dec 23 18:36:18 my-volumio-3 volumio[1219]: [Metrics] WebUI: 29s 378.26ms Dec 23 18:36:18 my-volumio-3 volumio[1219]: info: CoreStateMachine::resetVolumioState Dec 23 18:36:18 my-volumio-3 volumio[1219]: info: CoreStateMachine::getcurrentVolume Dec 23 18:36:18 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioRetrievevolume Dec 23 18:36:18 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 23 18:36:18 my-volumio-3 volumio[1393]: Starting albumart workers Dec 23 18:36:18 my-volumio-3 sudo[1442]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 23 18:36:18 my-volumio-3 sudo[1442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:36:18 my-volumio-3 sudo[1444]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 23 18:36:18 my-volumio-3 sudo[1444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:36:18 my-volumio-3 sudo[1442]: pam_unix(sudo:session): session closed for user root Dec 23 18:36:19 my-volumio-3 sudo[1444]: pam_unix(sudo:session): session closed for user root Dec 23 18:36:19 my-volumio-3 volumio[1219]: info: Volumio Network Manager: Network status updated: 2 Dec 23 18:36:20 my-volumio-3 volumio[1219]: verbose: New Socket.io Connection to 192.168.11.182 from 192.168.11.245 UA: Mozilla/5.0 (Linux; Android 14; KB2003 Build/UKQ1.230924.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.34 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Dec 23 18:36:20 my-volumio-3 volumio[1219]: info: VolumeController:: Volume=34 Mute =false Dec 23 18:36:20 my-volumio-3 volumio[1219]: info: CoreStateMachine::pushState Dec 23 18:36:20 my-volumio-3 volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 23 18:36:20 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 23 18:36:20 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioPushState Dec 23 18:36:20 my-volumio-3 volumio[1219]: info: CoreStateMachine::updateTrackBlock Dec 23 18:36:20 my-volumio-3 volumio[1219]: info: CorePlayQueue::getTrackBlock Dec 23 18:36:20 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioRetrievevolume Dec 23 18:36:21 my-volumio-3 volumio[1219]: info: Reloading queue from file Dec 23 18:36:21 my-volumio-3 volumio[1219]: verbose: New Socket.io Connection to 192.168.11.182 from 192.168.11.245 UA: Mozilla/5.0 (Linux; Android 14; KB2003 Build/UKQ1.230924.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.34 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Dec 23 18:36:21 my-volumio-3 volumio[1219]: info: CoreStateMachine::setRepeat null single undefined Dec 23 18:36:21 my-volumio-3 volumio[1219]: info: CoreStateMachine::pushState Dec 23 18:36:21 my-volumio-3 volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 23 18:36:21 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 23 18:36:21 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioPushState Dec 23 18:36:21 my-volumio-3 volumio[1219]: info: CoreStateMachine::setRandom null Dec 23 18:36:21 my-volumio-3 volumio[1219]: info: CoreStateMachine::pushState Dec 23 18:36:21 my-volumio-3 volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 23 18:36:21 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioPushState Dec 23 18:36:21 my-volumio-3 volumio[1219]: info: Setting Device type: Raspberry PI Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: Discovery: Getting this device information Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 23 18:36:22 my-volumio-3 volumio[1219]: verbose: New Socket.io Connection to 192.168.11.182 from 192.168.11.245 UA: Mozilla/5.0 (Linux; Android 14; KB2003 Build/UKQ1.230924.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.34 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: VolumeController:: Volume=34 Mute =false Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: CoreStateMachine::pushState Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioPushState Dec 23 18:36:22 my-volumio-3 sudo[1459]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 23 18:36:22 my-volumio-3 sudo[1459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: Discovery: Getting this device information Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: Discovery: adding 0cfdddb0-c359-42c7-b78a-bb65ae9b5c0b Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: Discovery: Found device My Volumio 3 Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 23 18:36:22 my-volumio-3 volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: Discovery: this is already registered, 0cfdddb0-c359-42c7-b78a-bb65ae9b5c0b Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: Discovery: Found device My Volumio 3 Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: Completed loading Core Plugins Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: Preparing to generate the ALSA configuration file Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: Discovery: Getting this device information Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: Reading ALSA contributions from plugins. Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: Asound.conf file unchanged, so no further update is needed Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: Output device has changed, restarting MPD Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: ___________ START PLUGINS ___________ Dec 23 18:36:23 my-volumio-3 sudo[1474]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 23 18:36:23 my-volumio-3 sudo[1474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:36:23 my-volumio-3 sudo[1474]: pam_unix(sudo:session): session closed for user root Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: ControllerMpd::onStart: Initializing MPD Dec 23 18:36:23 my-volumio-3 volumio[1219]: info: Creating MPD Configuration file Dec 23 18:36:23 my-volumio-3 sudo[1476]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 23 18:36:23 my-volumio-3 sudo[1476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:36:24 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 23 18:36:24 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 23 18:36:24 my-volumio-3 volumio[1219]: info: [1766496984058] CoreMusicLibrary::Adding element Media Servers Dec 23 18:36:24 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 23 18:36:24 my-volumio-3 volumio[1219]: info: UPNP Browser: Client initialized successfully Dec 23 18:36:24 my-volumio-3 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 23 18:36:24 my-volumio-3 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 23 18:36:24 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 23 18:36:24 my-volumio-3 volumio[1219]: info: [1766496984126] CoreMusicLibrary::Adding element Last_100 Dec 23 18:36:24 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 23 18:36:24 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 23 18:36:24 my-volumio-3 volumio[1219]: info: [1766496984136] CoreMusicLibrary::Adding element Webradio Dec 23 18:36:24 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 23 18:36:24 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 23 18:36:24 my-volumio-3 sudo[1481]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 23 18:36:24 my-volumio-3 volumio[1219]: info: Initializing BBC Radios Dec 23 18:36:24 my-volumio-3 sudo[1481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:36:24 my-volumio-3 sudo[1481]: pam_unix(sudo:session): session closed for user root Dec 23 18:36:24 my-volumio-3 sudo[1484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 23 18:36:24 my-volumio-3 sudo[1484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:36:24 my-volumio-3 sudo[1490]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 23 18:36:24 my-volumio-3 sudo[1490]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 23 18:36:24 my-volumio-3 sudo[1506]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 23 18:36:24 my-volumio-3 sudo[1490]: pam_unix(sudo:session): session closed for user root Dec 23 18:36:24 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 23 18:36:24 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 23 18:36:24 my-volumio-3 volumio[1219]: info: Creating Spotify config file Dec 23 18:36:24 my-volumio-3 systemd[1]: mpd.service: Deactivated successfully. Dec 23 18:36:24 my-volumio-3 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 23 18:36:24 my-volumio-3 systemd[1]: mpd.socket: Deactivated successfully. Dec 23 18:36:24 my-volumio-3 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 23 18:36:24 my-volumio-3 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 23 18:36:24 my-volumio-3 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 23 18:36:24 my-volumio-3 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 23 18:36:24 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:24 my-volumio-3 sudo[1509]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 23 18:36:24 my-volumio-3 sudo[1509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 23 18:36:24 my-volumio-3 sudo[1510]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 23 18:36:24 my-volumio-3 sudo[1509]: pam_unix(sudo:session): session closed for user root Dec 23 18:36:25 my-volumio-3 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 4. Dec 23 18:36:25 my-volumio-3 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 23 18:36:25 my-volumio-3 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 23 18:36:25 my-volumio-3 sudo[1459]: pam_unix(sudo:session): session closed for user root Dec 23 18:36:26 my-volumio-3 volumio-remote-updater[684]: [2025-12-23 18:36:26] [connect] Successful connection Dec 23 18:36:26 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 23 18:36:26 my-volumio-3 volumio[1219]: info: [1766496986415] CoreMusicLibrary::Adding element YouTube2 Dec 23 18:36:26 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 23 18:36:26 my-volumio-3 volumio[1219]: Cannot find translation for source YouTube2 Dec 23 18:36:26 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 23 18:36:26 my-volumio-3 volumio[1219]: info: [1766496986598] CoreMusicLibrary::Adding element YouTube Music Dec 23 18:36:26 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 23 18:36:26 my-volumio-3 volumio[1219]: Cannot find translation for source YouTube2 Dec 23 18:36:26 my-volumio-3 volumio[1219]: Cannot find translation for source YouTube Music Dec 23 18:36:26 my-volumio-3 sudo[1538]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Dec 23 18:36:26 my-volumio-3 sudo[1538]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:36:26 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 23 18:36:27 my-volumio-3 systemd[1]: /lib/systemd/system/roonbridge.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 23 18:36:27 my-volumio-3 systemd[1]: /lib/systemd/system/roonbridge.service:8: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 23 18:36:27 my-volumio-3 sudo[1544]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod +x /tmp/mpd_oled_plugin.sh Dec 23 18:36:27 my-volumio-3 sudo[1544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:36:27 my-volumio-3 volumio[1219]: info: Volumio Calling Home Dec 23 18:36:27 my-volumio-3 sudo[1544]: pam_unix(sudo:session): session closed for user root Dec 23 18:36:27 my-volumio-3 systemd[1]: Started roonbridge.service - RoonBridge. Dec 23 18:36:27 my-volumio-3 sudo[1538]: pam_unix(sudo:session): session closed for user root Dec 23 18:36:27 my-volumio-3 sudo[1547]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start mpd_oled_plugin.service Dec 23 18:36:27 my-volumio-3 sudo[1547]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:36:27 my-volumio-3 volumio[1219]: info: Preparing to generate the ALSA configuration file Dec 23 18:36:28 my-volumio-3 volumio[1219]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf Dec 23 18:36:28 my-volumio-3 volumio[1219]: info: Reading ALSA contributions from plugins. Dec 23 18:36:28 my-volumio-3 volumio[1219]: info: [MPD_OLED Plugin] Set execute permissions on /tmp/mpd_oled_plugin.sh Dec 23 18:36:28 my-volumio-3 volumio[1219]: info: MPD Permissions set Dec 23 18:36:28 my-volumio-3 volumio[1219]: info: MPD Permissions set Dec 23 18:36:28 my-volumio-3 volumio[1219]: info: Upmpdcli Daemon Started Dec 23 18:36:28 my-volumio-3 volumio-remote-updater[684]: [2025-12-23 18:36:28] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1766496986 101 Dec 23 18:36:28 my-volumio-3 volumio[1219]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 4 Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: [MPD_OLED Plugin] tmp script created /tmp/mpd_oled_plugin.sh Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: Spotify config file written Dec 23 18:36:29 my-volumio-3 volumio[1219]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:29 my-volumio-3 sudo[1566]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 23 18:36:29 my-volumio-3 sudo[1566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:36:29 my-volumio-3 RoonBridge[1553]: 00:00:00.025 Warn: get lock file path: /tmp/.rnbgem0- Dec 23 18:36:29 my-volumio-3 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. Dec 23 18:36:29 my-volumio-3 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. Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:29 my-volumio-3 volumio[1219]: info: No need to fix Spotify hosts Dec 23 18:36:29 my-volumio-3 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 23 18:36:29 my-volumio-3 go-librespot[1578]: go-librespot daemon starting... Dec 23 18:36:29 my-volumio-3 sudo[1566]: pam_unix(sudo:session): session closed for user root Dec 23 18:36:30 my-volumio-3 RoonBridge[1553]: 00:00:01.018 Trace: [childprocess] using unix child process Dec 23 18:36:30 my-volumio-3 RoonBridge[1553]: 00:00:01.200 Debug: PathForResource, filename: ../.update Dec 23 18:36:30 my-volumio-3 go-librespot[1579]: time="2025-12-23T18:36:30+05:00" level=info msg="running go-librespot 0.4.0" Dec 23 18:36:30 my-volumio-3 go-librespot[1579]: time="2025-12-23T18:36:30+05:00" level=debug msg="app state loaded" Dec 23 18:36:30 my-volumio-3 go-librespot[1579]: time="2025-12-23T18:36:30+05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 23 18:36:30 my-volumio-3 RoonBridge[1553]: 00:00:01.519 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/../.update Dec 23 18:36:30 my-volumio-3 RoonBridge[1553]: 00:00:01.541 Debug: PathForResource, filename: RAATServer Dec 23 18:36:30 my-volumio-3 RoonBridge[1553]: 00:00:01.541 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RAATServer Dec 23 18:36:30 my-volumio-3 RoonBridge[1553]: 00:00:01.542 Debug: PathForResource, filename: RoonBridgeHelper Dec 23 18:36:30 my-volumio-3 RoonBridge[1553]: 00:00:01.543 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RoonBridgeHelper Dec 23 18:36:30 my-volumio-3 RoonBridge[1553]: Initializing Dec 23 18:36:30 my-volumio-3 RoonBridge[1553]: 00:00:01.667 Info: Starting /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RoonBridgeHelper Dec 23 18:36:31 my-volumio-3 RoonBridge[1553]: 00:00:01.846 Info: ConnectOrStartAndWaitForExit RAATServer, path: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RAATServer Dec 23 18:36:31 my-volumio-3 RoonBridge[1553]: Not Running (.o) Dec 23 18:36:31 my-volumio-3 go-librespot[1579]: time="2025-12-23T18:36:31+05:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 23 18:36:31 my-volumio-3 go-librespot[1579]: time="2025-12-23T18:36:31+05:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 23 18:36:31 my-volumio-3 go-librespot[1579]: time="2025-12-23T18:36:31+05:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 23 18:36:31 my-volumio-3 go-librespot[1579]: time="2025-12-23T18:36:31+05:00" level=info msg="zeroconf server listening on port 39229" Dec 23 18:36:31 my-volumio-3 volumio[1219]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 23 18:36:31 my-volumio-3 volumio[1219]: SPOTIFY: BQA7rbOmQiRsWJYlm84umfoB_jsRgzVn1MWLSniGRq1By-kNNApnFpASueYfI2_6FnC8DlnYsjEIF9cuD1UI5Sr6X9knw_fxqOkk96Bv4Z54beptyvYsOm_Tyxhrp_rUEMQRh-Zfl0OlRTTCVewXklcT4lk_17abW2ryC6TVBPwIdy1c2Ms0W5fv4m84Ip-4OL6pH9OwuMKfrCSlHHzbO6tBenSxMobJW4LJ9jecNjT5tPUW7msRJjbhWQG1VJABxgiZcOAG6QwlB-i2R0etJCMMcXaLiO3cetgxOPX_-jifmH6d2H1odWSyV5FB Dec 23 18:36:31 my-volumio-3 volumio[1219]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 23 18:36:31 my-volumio-3 volumio[1219]: info: New Spotify access token = BQA7rbOmQiRsWJYlm84umfoB_jsRgzVn1MWLSniGRq1By-kNNApnFpASueYfI2_6FnC8DlnYsjEIF9cuD1UI5Sr6X9knw_fxqOkk96Bv4Z54beptyvYsOm_Tyxhrp_rUEMQRh-Zfl0OlRTTCVewXklcT4lk_17abW2ryC6TVBPwIdy1c2Ms0W5fv4m84Ip-4OL6pH9OwuMKfrCSlHHzbO6tBenSxMobJW4LJ9jecNjT5tPUW7msRJjbhWQG1VJABxgiZcOAG6QwlB-i2R0etJCMMcXaLiO3cetgxOPX_-jifmH6d2H1odWSyV5FB Dec 23 18:36:31 my-volumio-3 volumio[1219]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 23 18:36:32 my-volumio-3 go-librespot[1579]: time="2025-12-23T18:36:32+05:00" level=debug msg="obtained new client token: AAB2tsx3xGnDueTGEgw3CQaTXrceJQuF2JZkNenrkBPGNPOMyJfZVMnailljpPsDbi0/i2TR4nXgTMVjl9abPjKExFS0JTCo+QxIq5AVZQA7wiap/MQ0fBHhUDvd9aUocLYJbNGicjVyf3uxKzZu+TLQe8vh6m8GDJSOA86rLg+l9HON6Kxo1JhtutqbO6L8QsXp6iZ8VMEOMH+pgcAqd7h138AWnN674tJWaRlLiw0SGmv4eUvO3ZCV" Dec 23 18:36:32 my-volumio-3 volumio[1219]: info: Asound.conf file unchanged, so no further update is needed Dec 23 18:36:32 my-volumio-3 volumio[1219]: info: Output device has changed, restarting MPD Dec 23 18:36:32 my-volumio-3 go-librespot[1579]: time="2025-12-23T18:36:32+05:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 23 18:36:32 my-volumio-3 RoonBridge[1553]: Running Dec 23 18:36:32 my-volumio-3 sudo[1604]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 23 18:36:32 my-volumio-3 sudo[1604]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:36:32 my-volumio-3 sudo[1603]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 23 18:36:32 my-volumio-3 sudo[1603]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 23 18:36:32 my-volumio-3 sudo[1603]: pam_unix(sudo:session): session closed for user root Dec 23 18:36:32 my-volumio-3 go-librespot[1579]: time="2025-12-23T18:36:32+05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Dec 23 18:36:32 my-volumio-3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 23 18:36:32 my-volumio-3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 23 18:36:33 my-volumio-3 systemd[1]: mpd.service: Deactivated successfully. Dec 23 18:36:33 my-volumio-3 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 23 18:36:33 my-volumio-3 systemd[1]: mpd.service: Consumed 5.425s CPU time. Dec 23 18:36:33 my-volumio-3 systemd[1]: mpd.socket: Deactivated successfully. Dec 23 18:36:33 my-volumio-3 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 23 18:36:33 my-volumio-3 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 23 18:36:33 my-volumio-3 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 23 18:36:33 my-volumio-3 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 23 18:36:33 my-volumio-3 volumio[1219]: info: MPD Permissions set Dec 23 18:36:33 my-volumio-3 volumio[1219]: info: Volumio called home Dec 23 18:36:33 my-volumio-3 sudo[1615]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 23 18:36:33 my-volumio-3 sudo[1615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 23 18:36:33 my-volumio-3 sudo[1616]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 23 18:36:33 my-volumio-3 sudo[1615]: pam_unix(sudo:session): session closed for user root Dec 23 18:36:33 my-volumio-3 volumio[1219]: error: Upnp client error: Error: read ECONNRESET Dec 23 18:36:33 my-volumio-3 volumio[1219]: error: Upnp client error: Error: read ECONNRESET Dec 23 18:36:33 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 23 18:36:33 my-volumio-3 volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 23 18:36:33 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:33 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:33 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:33 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:33 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:33 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:33 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:33 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:34 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 23 18:36:34 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 23 18:36:34 my-volumio-3 volumio[1219]: info: go-librespot daemon successfully initialized Dec 23 18:36:34 my-volumio-3 RoonBridge[1591]: 00:00:00.115 Warn: get lock file path: /tmp/.rnbhgem0- Dec 23 18:36:34 my-volumio-3 volumio[1219]: SPOTIFY: User informations: {"country":"PK","display_name":"Farrukhs","email":"farrukhshahzad61@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31zsvq76i3476thrzr4dj4fonn4a"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31zsvq76i3476thrzr4dj4fonn4a","id":"31zsvq76i3476thrzr4dj4fonn4a","images":[],"product":"premium","type":"user","uri":"spotify:user:31zsvq76i3476thrzr4dj4fonn4a"} Dec 23 18:36:34 my-volumio-3 volumio[1219]: info: Spotify Successfully logged in Dec 23 18:36:34 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 23 18:36:34 my-volumio-3 volumio[1219]: info: [1766496994962] CoreMusicLibrary::Adding element Spotify Dec 23 18:36:34 my-volumio-3 volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 23 18:36:34 my-volumio-3 volumio[1219]: Cannot find translation for source YouTube2 Dec 23 18:36:34 my-volumio-3 volumio[1219]: Cannot find translation for source YouTube Music Dec 23 18:36:34 my-volumio-3 volumio[1219]: Cannot find translation for source Spotify Dec 23 18:36:35 my-volumio-3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 23 18:36:35 my-volumio-3 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 23 18:36:36 my-volumio-3 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 23 18:36:36 my-volumio-3 go-librespot[1640]: go-librespot daemon starting... Dec 23 18:36:36 my-volumio-3 go-librespot[1641]: time="2025-12-23T18:36:36+05:00" level=info msg="running go-librespot 0.4.0" Dec 23 18:36:36 my-volumio-3 go-librespot[1641]: time="2025-12-23T18:36:36+05:00" level=debug msg="app state loaded" Dec 23 18:36:36 my-volumio-3 go-librespot[1641]: time="2025-12-23T18:36:36+05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 23 18:36:37 my-volumio-3 go-librespot[1641]: time="2025-12-23T18:36:37+05:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 23 18:36:37 my-volumio-3 go-librespot[1641]: time="2025-12-23T18:36:37+05:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 23 18:36:37 my-volumio-3 go-librespot[1641]: time="2025-12-23T18:36:37+05:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 23 18:36:37 my-volumio-3 go-librespot[1641]: time="2025-12-23T18:36:37+05:00" level=info msg="zeroconf server listening on port 38477" Dec 23 18:36:37 my-volumio-3 volumio[1219]: info: Initializing connection to go-librespot Websocket Dec 23 18:36:37 my-volumio-3 go-librespot[1641]: time="2025-12-23T18:36:37+05:00" level=debug msg="obtained new client token: AABf7XkFm+VBkt1nPZqoQBpqfmpKQsqXb3FD6RkOC/yGbPiWVwdyVh1WjVROZ4+tQjz1Wp3LBldx2og4OuUlvcIOFlQpuQ/JXHmRFy/P/UsNXevykI7AXWUiq+hIb4FOtzg0OiM9PQKcKQlk942FBaD6VenSq5FPj33Lc4Y8CUOUokD+/HDbx0YWRKftmn+jtw6up8znUUb+o2QAtgH2qDn6hxLi+1+9T+Hxs+ayGHGYKZAwH57iIovf" Dec 23 18:36:37 my-volumio-3 go-librespot[1641]: time="2025-12-23T18:36:37+05:00" level=debug msg="new websocket client" Dec 23 18:36:37 my-volumio-3 volumio[1219]: info: Connection to go-librespot Websocket established Dec 23 18:36:37 my-volumio-3 go-librespot[1641]: time="2025-12-23T18:36:37+05:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 23 18:36:38 my-volumio-3 go-librespot[1641]: time="2025-12-23T18:36:38+05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Dec 23 18:36:38 my-volumio-3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 23 18:36:38 my-volumio-3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 23 18:36:38 my-volumio-3 volumio[1219]: info: Connection to go-librespot Websocket closed Dec 23 18:36:38 my-volumio-3 mpd[1617]: 2025-12-23T18:36:38 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 23 18:36:38 my-volumio-3 systemd[1]: Started mpd.service - Music Player Daemon. Dec 23 18:36:38 my-volumio-3 sudo[1484]: pam_unix(sudo:session): session closed for user root Dec 23 18:36:38 my-volumio-3 sudo[1476]: pam_unix(sudo:session): session closed for user root Dec 23 18:36:38 my-volumio-3 sudo[1604]: pam_unix(sudo:session): session closed for user root Dec 23 18:36:38 my-volumio-3 systemd[1]: Started mpd_oled_plugin.service - MPD OLED Plugin. Dec 23 18:36:38 my-volumio-3 sudo[1547]: pam_unix(sudo:session): session closed for user root Dec 23 18:36:38 my-volumio-3 volumio[1219]: info: Completed starting Core Plugins Dec 23 18:36:38 my-volumio-3 volumio[1219]: info: ------------------------------------------- Dec 23 18:36:38 my-volumio-3 volumio[1219]: info: ----- MyVolumio plugins startup ---- Dec 23 18:36:38 my-volumio-3 volumio[1219]: info: ------------------------------------------- Dec 23 18:36:38 my-volumio-3 volumio[1219]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 23 18:36:38 my-volumio-3 volumio[1219]: info: [MPD_OLED Plugin] Started mpd_oled_plugin service Dec 23 18:36:38 my-volumio-3 RoonBridge[1553]: 00:00:09.679 Warn: exception starting raatserver: System.Net.Sockets.SocketException (0x80004005): Connection refused Dec 23 18:36:38 my-volumio-3 RoonBridge[1553]: at System.Net.Sockets.TcpClient..ctor (System.String hostname, System.Int32 port) [0x0006d] in :0 Dec 23 18:36:38 my-volumio-3 RoonBridge[1553]: at Sooloos.RAATServer.ConnectOrStartAndWaitForExit (System.String path, System.String args, System.Action`1[T] status, Base.ChildProcess& p) [0x00165] in :0 Dec 23 18:36:38 my-volumio-3 RoonBridge[1553]: Not Running (.o) Dec 23 18:36:39 my-volumio-3 RoonBridge[1553]: 00:00:09.727 Debug: PathForResource, filename: ../.update Dec 23 18:36:39 my-volumio-3 RoonBridge[1553]: 00:00:09.732 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/../.update Dec 23 18:36:39 my-volumio-3 volumio[1219]: error: MPD error: The expression evaluated to a falsy value: Dec 23 18:36:39 my-volumio-3 volumio[1219]: assert.ok(self.idling) Dec 23 18:36:39 my-volumio-3 volumio[1219]: error: The expression evaluated to a falsy value: Dec 23 18:36:39 my-volumio-3 volumio[1219]: assert.ok(self.idling) Dec 23 18:36:39 my-volumio-3 volumio[1219]: error: MPD error: The expression evaluated to a falsy value: Dec 23 18:36:39 my-volumio-3 volumio[1219]: assert.ok(self.idling) Dec 23 18:36:39 my-volumio-3 volumio[1219]: error: The expression evaluated to a falsy value: Dec 23 18:36:39 my-volumio-3 volumio[1219]: assert.ok(self.idling) Dec 23 18:36:39 my-volumio-3 volumio[1219]: info: MPD running with PID1617 Dec 23 18:36:39 my-volumio-3 volumio[1219]: ,establishing connection Dec 23 18:36:39 my-volumio-3 volumio[1219]: error: updateQueue error: null Dec 23 18:36:39 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 23 18:36:39 my-volumio-3 volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 23 18:36:39 my-volumio-3 volumio[1219]: error: updateQueue error: null Dec 23 18:36:39 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 23 18:36:39 my-volumio-3 volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 23 18:36:39 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 23 18:36:39 my-volumio-3 volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 23 18:36:39 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 23 18:36:39 my-volumio-3 volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 23 18:36:40 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 23 18:36:40 my-volumio-3 volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 23 18:36:40 my-volumio-3 volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 23 18:36:40 my-volumio-3 volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 23 18:36:41 my-volumio-3 RoonBridge[1553]: 00:00:11.737 Info: ConnectOrStartAndWaitForExit RAATServer, path: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RAATServer Dec 23 18:36:41 my-volumio-3 RoonBridge[1553]: Running Dec 23 18:36:41 my-volumio-3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 23 18:36:41 my-volumio-3 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 23 18:36:41 my-volumio-3 volumio[1219]: info: Getting Spotify volume Dec 23 18:36:41 my-volumio-3 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 23 18:36:41 my-volumio-3 go-librespot[1686]: go-librespot daemon starting... Dec 23 18:36:41 my-volumio-3 go-librespot[1688]: time="2025-12-23T18:36:41+05:00" level=info msg="running go-librespot 0.4.0" Dec 23 18:36:41 my-volumio-3 go-librespot[1688]: time="2025-12-23T18:36:41+05:00" level=debug msg="app state loaded" Dec 23 18:36:41 my-volumio-3 go-librespot[1688]: time="2025-12-23T18:36:41+05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 23 18:36:41 my-volumio-3 volumio[1219]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 23 18:36:41 my-volumio-3 volumio[1219]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 23 18:36:41 my-volumio-3 volumio[1219]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 23 18:36:41 my-volumio-3 volumio[1219]: errno: -111, Dec 23 18:36:41 my-volumio-3 volumio[1219]: code: 'ECONNREFUSED', Dec 23 18:36:41 my-volumio-3 volumio[1219]: syscall: 'connect', Dec 23 18:36:41 my-volumio-3 volumio[1219]: address: '127.0.0.1', Dec 23 18:36:41 my-volumio-3 volumio[1219]: port: 9879, Dec 23 18:36:41 my-volumio-3 volumio[1219]: response: undefined Dec 23 18:36:41 my-volumio-3 volumio[1219]: } Dec 23 18:36:41 my-volumio-3 volumio[1219]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 23 18:36:42 my-volumio-3 go-librespot[1688]: time="2025-12-23T18:36:42+05:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 23 18:36:42 my-volumio-3 go-librespot[1688]: time="2025-12-23T18:36:42+05:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 23 18:36:42 my-volumio-3 go-librespot[1688]: time="2025-12-23T18:36:42+05:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 23 18:36:42 my-volumio-3 go-librespot[1688]: time="2025-12-23T18:36:42+05:00" level=info msg="zeroconf server listening on port 38197" Dec 23 18:36:42 my-volumio-3 go-librespot[1688]: time="2025-12-23T18:36:42+05:00" level=debug msg="obtained new client token: AADtfkKEBxRdP/Tejx/qXeKdiFq0FG1slF6HU0TyrgNod1CVazB1QsASMSj99kisZ0RuhuT9HCf1h84ZKyI2lFk5A4KplNxUnnu0Z2cV4+fW64VTSxtKPdlEFLtErhKJly2sjmjaBRiZwnmHERIjG6J7EmxPjRxKhLddj+lLTvpzEJp1UKIoe7SvFO+AkwY3ES7yrUNq7YxtHGXBt7etWR5pSf0XSeJVmHAlHMbVpZ5x9cDa1t0skCkH" Dec 23 18:36:42 my-volumio-3 go-librespot[1688]: time="2025-12-23T18:36:42+05:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 23 18:36:42 my-volumio-3 go-librespot[1688]: time="2025-12-23T18:36:42+05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Dec 23 18:36:42 my-volumio-3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 23 18:36:42 my-volumio-3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 23 18:36:46 my-volumio-3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 23 18:36:46 my-volumio-3 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 23 18:36:46 my-volumio-3 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 23 18:36:46 my-volumio-3 go-librespot[1737]: go-librespot daemon starting... Dec 23 18:36:46 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:46+05:00" level=info msg="running go-librespot 0.4.0" Dec 23 18:36:46 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:46+05:00" level=debug msg="app state loaded" Dec 23 18:36:46 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:46+05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 23 18:36:47 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:47+05:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 23 18:36:47 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:47+05:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 23 18:36:47 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:47+05:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 23 18:36:47 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:47+05:00" level=info msg="zeroconf server listening on port 45199" Dec 23 18:36:47 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:47+05:00" level=debug msg="obtained new client token: AACxyD2/GV14oBJO/voIE1Hp9M3PASfOm0BVcUMW9oRF3EBZAVgbCrs/NeLSVIXnlj0Kb+RIZgvf+1ZpftNbf5zQK0ywgeNkgdEzBCslV6DjQhZKWkjdQlN7lIyqjL2Mgw6KsYkVRW3VpGVtEfanlIjgzwgbZeh/yCl4EYAojbCYV3Lwz/3rh6sk/ENxF/GtKYSm3/IUcNhhiu4I0a/rRLiRqk5BoxKQJx4jmDNFVE/Z4Br79VNzjPjg" Dec 23 18:36:47 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:47+05:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 23 18:36:48 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:48+05:00" level=debug msg="completed keyexchange" Dec 23 18:36:48 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:48+05:00" level=debug msg="completed challenge" Dec 23 18:36:48 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:48+05:00" level=info msg="authenticated AP" username="31************************4a" Dec 23 18:36:48 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:48+05:00" level=info msg="authenticated Login5" username="31************************4a" Dec 23 18:36:48 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:48+05:00" level=debug msg="initializing zeroconf session" username="31************************4a" Dec 23 18:36:49 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:49+05:00" level=debug msg="dealer connection opened" Dec 23 18:36:49 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:49+05:00" level=trace msg="starting accesspoint recv loop" Dec 23 18:36:49 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:49+05:00" level=trace msg="starting dealer recv loop" Dec 23 18:36:49 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:49+05:00" level=trace msg="received accesspoint ping" Dec 23 18:36:49 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:49+05:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 23 18:36:49 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:49+05:00" level=debug msg="received connection id: YTRiMDZjYTgtMzIy...Q0QyQjQzNDBDOA==" Dec 23 18:36:49 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:49+05:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 23 18:36:49 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:49+05:00" level=debug msg="put connect state because NEW_DEVICE" Dec 23 18:36:49 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:49+05:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 23 18:36:49 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:49+05:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 23 18:36:49 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:49+05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 23 18:36:49 my-volumio-3 go-librespot[1738]: time="2025-12-23T18:36:49+05:00" level=trace msg="received accesspoint pong ack" Dec 23 18:36:52 my-volumio-3 sudo[1755]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-23 18:35' Dec 23 18:36:52 my-volumio-3 sudo[1755]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"