Dec 16 22:20:00 volumio-elutuba ntpd[881]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 16 22:20:00 volumio-elutuba systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 16 22:20:00 volumio-elutuba systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 16 22:20:00 volumio-elutuba systemd[1]: setdatetime-helper.service: Consumed 1.594s CPU time. Dec 16 22:20:00 volumio-elutuba ntpd[881]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Dec 16 22:20:00 volumio-elutuba ntpd[881]: DNS: Pool taking: 193.40.134.137 Dec 16 22:20:00 volumio-elutuba ntpd[881]: DNS: Pool taking: 45.12.28.227 Dec 16 22:20:00 volumio-elutuba ntpd[881]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Dec 16 22:20:00 volumio-elutuba systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Dec 16 22:20:00 volumio-elutuba systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Dec 16 22:20:00 volumio-elutuba systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Dec 16 22:20:00 volumio-elutuba winbindd[1055]: [2025/12/16 22:20:00.489400, 0] ../../source3/winbindd/winbindd.c:1440(main) Dec 16 22:20:00 volumio-elutuba winbindd[1055]: winbindd version 4.17.8-Raspbian started. Dec 16 22:20:00 volumio-elutuba winbindd[1055]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Dec 16 22:20:00 volumio-elutuba systemd[1]: systemd-rfkill.service: Deactivated successfully. Dec 16 22:20:00 volumio-elutuba dhcpcd[656]: eth0: leased 192.168.0.98 for 7200 seconds Dec 16 22:20:00 volumio-elutuba sh[648]: eth0: leased 192.168.0.98 for 7200 seconds Dec 16 22:20:00 volumio-elutuba sh[648]: eth0: adding route to 192.168.0.0/24 Dec 16 22:20:00 volumio-elutuba sh[648]: eth0: adding default route via 192.168.0.1 Dec 16 22:20:00 volumio-elutuba dhcpcd[656]: eth0: adding route to 192.168.0.0/24 Dec 16 22:20:00 volumio-elutuba dhcpcd[656]: eth0: adding default route via 192.168.0.1 Dec 16 22:20:00 volumio-elutuba wireless.js[708]: WIRELESS.JS: Single Network Mode enabled, only one network device can be active at a time between ethernet and wireless Dec 16 22:20:00 volumio-elutuba wireless.js[708]: WIRELESS.JS: Wired network status changed to: ---connected--- Dec 16 22:20:00 volumio-elutuba winbindd[1055]: [2025/12/16 22:20:00.562595, 0] ../../source3/winbindd/winbindd_cache.c:3116(initialize_winbindd_cache) Dec 16 22:20:00 volumio-elutuba winbindd[1055]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Dec 16 22:20:00 volumio-elutuba wireless.js[708]: WIRELESS.JS: Wireless.js initializing wireless flow Dec 16 22:20:00 volumio-elutuba wireless.js[708]: WIRELESS.JS: Cleaning previous... Dec 16 22:20:00 volumio-elutuba systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 16 22:20:00 volumio-elutuba systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 16 22:20:00 volumio-elutuba systemd[1]: welcome.service: Deactivated successfully. Dec 16 22:20:00 volumio-elutuba systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 16 22:20:00 volumio-elutuba systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 16 22:20:00 volumio-elutuba sh[648]: forked to background, child pid 654 Dec 16 22:20:00 volumio-elutuba systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 16 22:20:00 volumio-elutuba welcome[1098]: Resolved ip:[1] 192.168.0.98 Dec 16 22:20:00 volumio-elutuba systemd[1]: Started winbind.service - Samba Winbind Daemon. Dec 16 22:20:00 volumio-elutuba systemd[1]: Starting smbd.service - Samba SMB Daemon... Dec 16 22:20:00 volumio-elutuba systemd[1]: dpkg-db-backup.service: Deactivated successfully. Dec 16 22:20:00 volumio-elutuba systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Dec 16 22:20:00 volumio-elutuba systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 16 22:20:00 volumio-elutuba systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 16 22:20:01 volumio-elutuba ifplugd(eth0)[888]: client: ifup: interface eth0 already configured Dec 16 22:20:01 volumio-elutuba sh[1145]: eth0=eth0 Dec 16 22:20:01 volumio-elutuba ifplugd(eth0)[888]: Program executed successfully. Dec 16 22:20:01 volumio-elutuba ifplugd[819]: Network Interface Plugging Daemon...start eth0...done. Dec 16 22:20:01 volumio-elutuba systemd[1]: Started ifplugd.service - LSB: Brings up/down network automatically. Dec 16 22:20:01 volumio-elutuba sudo[1131]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Dec 16 22:20:01 volumio-elutuba sudo[1131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 16 22:20:01 volumio-elutuba sudo[1131]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:01 volumio-elutuba sudo[1154]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Dec 16 22:20:01 volumio-elutuba sudo[1154]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 16 22:20:01 volumio-elutuba sudo[1154]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:01 volumio-elutuba smbd[1144]: [2025/12/16 22:20:01.917916, 0] ../../source3/smbd/server.c:1741(main) Dec 16 22:20:01 volumio-elutuba smbd[1144]: smbd version 4.17.8-Raspbian started. Dec 16 22:20:01 volumio-elutuba smbd[1144]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Dec 16 22:20:02 volumio-elutuba wireless.js[708]: WIRELESS.JS: Stopped aP Dec 16 22:20:02 volumio-elutuba sudo[1166]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 16 22:20:02 volumio-elutuba sudo[1166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:02 volumio-elutuba sudo[1166]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:02 volumio-elutuba kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 16 22:20:02 volumio-elutuba sudo[1168]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Dec 16 22:20:02 volumio-elutuba sudo[1168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:02 volumio-elutuba sudo[1168]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:02 volumio-elutuba sudo[1178]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 16 22:20:02 volumio-elutuba sudo[1178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:02 volumio-elutuba sudo[1178]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:02 volumio-elutuba systemd[1]: Started smbd.service - Samba SMB Daemon. Dec 16 22:20:02 volumio-elutuba sudo[1181]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Dec 16 22:20:02 volumio-elutuba sudo[1181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:03 volumio-elutuba sudo[1181]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:03 volumio-elutuba wireless.js[708]: WIRELESS.JS: SETTING APPROPRIATE REG DOMAIN: DE Dec 16 22:20:03 volumio-elutuba sudo[1188]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 16 22:20:03 volumio-elutuba sudo[1188]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:03 volumio-elutuba sudo[1188]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:03 volumio-elutuba sudo[1190]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set DE Dec 16 22:20:03 volumio-elutuba sudo[1190]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:03 volumio-elutuba sudo[1190]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:03 volumio-elutuba wireless.js[708]: WIRELESS.JS: SUCCESSFULLY SET NEW REGDOMAIN: DE Dec 16 22:20:03 volumio-elutuba wireless.js[708]: WIRELESS.JS: Single Network Mode: Wired network active, not starting wireless flow Dec 16 22:20:03 volumio-elutuba wireless.js[708]: WIRELESS.JS: Notified systemd about wireless ready Dec 16 22:20:03 volumio-elutuba systemd[1]: Started wireless.service - Wireless Services. Dec 16 22:20:03 volumio-elutuba kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 16 22:20:03 volumio-elutuba systemd[1]: Started volumio.service - Volumio Backend Module. Dec 16 22:20:03 volumio-elutuba systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... Dec 16 22:20:03 volumio-elutuba systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker. Dec 16 22:20:03 volumio-elutuba systemd[1]: Received SIGRTMIN+21 from PID 298 (plymouthd). Dec 16 22:20:03 volumio-elutuba systemd[1]: Received SIGRTMIN+21 from PID 298 (plymouthd). Dec 16 22:20:03 volumio-elutuba systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. Dec 16 22:20:03 volumio-elutuba systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. Dec 16 22:20:03 volumio-elutuba systemd[1]: Started getty@tty1.service - Getty on tty1. Dec 16 22:20:03 volumio-elutuba systemd[1]: Reached target getty.target - Login Prompts. Dec 16 22:20:03 volumio-elutuba systemd[1]: Reached target multi-user.target - Multi-User System. Dec 16 22:20:03 volumio-elutuba systemd[1]: Reached target graphical.target - Graphical Interface. Dec 16 22:20:03 volumio-elutuba volumio-cpu-tweak[1199]: Setting RT Priority for mpd Dec 16 22:20:03 volumio-elutuba systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Dec 16 22:20:03 volumio-elutuba volumio-cpu-tweak[1215]: pid 35's current scheduling policy: SCHED_OTHER Dec 16 22:20:03 volumio-elutuba volumio-cpu-tweak[1215]: pid 35's current scheduling priority: 0 Dec 16 22:20:03 volumio-elutuba volumio-cpu-tweak[1199]: Setting MPD Affinity Dec 16 22:20:03 volumio-elutuba volumio-cpu-tweak[1216]: pid 3's current affinity mask: f Dec 16 22:20:03 volumio-elutuba volumio-cpu-tweak[1199]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Dec 16 22:20:03 volumio-elutuba volumio-cpu-tweak[1199]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Dec 16 22:20:03 volumio-elutuba systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Dec 16 22:20:03 volumio-elutuba systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Dec 16 22:20:03 volumio-elutuba systemd[1]: Startup finished in 16.191s (kernel) + 15.441s (userspace) = 31.632s. Dec 16 22:20:03 volumio-elutuba systemd[1]: volumio_cpu_tweak.service: Deactivated successfully. Dec 16 22:20:05 volumio-elutuba ntpd[881]: IO: Listen normally on 3 eth0 192.168.0.98:123 Dec 16 22:20:05 volumio-elutuba ntpd[881]: IO: new interface(s) found: waking up resolver Dec 16 22:20:05 volumio-elutuba ntpd[881]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 16 22:20:05 volumio-elutuba ntpd[881]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Dec 16 22:20:05 volumio-elutuba ntpd[881]: DNS: Pool skipping: 193.40.134.137 Dec 16 22:20:05 volumio-elutuba ntpd[881]: DNS: Pool skipping: 45.12.28.227 Dec 16 22:20:05 volumio-elutuba ntpd[881]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Dec 16 22:20:06 volumio-elutuba ntpd[881]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 16 22:20:06 volumio-elutuba ntpd[881]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Dec 16 22:20:06 volumio-elutuba ntpd[881]: DNS: Pool taking: 193.40.0.5 Dec 16 22:20:06 volumio-elutuba ntpd[881]: DNS: Pool taking: 185.194.53.27 Dec 16 22:20:06 volumio-elutuba ntpd[881]: DNS: Pool taking: 2001:470:59e5::7 Dec 16 22:20:06 volumio-elutuba ntpd[881]: DNS: Pool taking: 2001:1b28:1:5::132 Dec 16 22:20:06 volumio-elutuba ntpd[881]: DNS: Pool taking: 2a10:1fc0:1::34f9:5fcf Dec 16 22:20:06 volumio-elutuba ntpd[881]: DNS: Pool taking: 2001:1b28:1:5::131 Dec 16 22:20:06 volumio-elutuba ntpd[881]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Dec 16 22:20:07 volumio-elutuba ntpd[881]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 16 22:20:07 volumio-elutuba ntpd[881]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Dec 16 22:20:07 volumio-elutuba ntpd[881]: DNS: Pool taking: 193.40.133.134 Dec 16 22:20:07 volumio-elutuba ntpd[881]: DNS: Pool taking: 91.235.234.207 Dec 16 22:20:07 volumio-elutuba ntpd[881]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Dec 16 22:20:07 volumio-elutuba volumio-remote-updater[703]: [2025-12-16 22:20:07] [connect] Successful connection Dec 16 22:20:08 volumio-elutuba ntpd[881]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 16 22:20:08 volumio-elutuba ntpd[881]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Dec 16 22:20:08 volumio-elutuba ntpd[881]: DNS: Pool taking: 212.7.1.132 Dec 16 22:20:08 volumio-elutuba ntpd[881]: DNS: Pool skipping: 45.12.28.227 Dec 16 22:20:08 volumio-elutuba ntpd[881]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Dec 16 22:20:08 volumio-elutuba volumio[1197]: info: ------------------------------------------- Dec 16 22:20:08 volumio-elutuba volumio[1197]: info: ----- Volumio3 ---- Dec 16 22:20:08 volumio-elutuba volumio[1197]: info: ------------------------------------------- Dec 16 22:20:08 volumio-elutuba volumio[1197]: info: ----- System startup ---- Dec 16 22:20:08 volumio-elutuba volumio[1197]: info: ------------------------------------------- Dec 16 22:20:10 volumio-elutuba systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Dec 16 22:20:10 volumio-elutuba systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 16 22:20:10 volumio-elutuba systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 16 22:20:10 volumio-elutuba upmpdcli[1230]: Could not open config: /tmp/upmpdcli.conf Dec 16 22:20:10 volumio-elutuba systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 16 22:20:10 volumio-elutuba systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 16 22:20:10 volumio-elutuba volumio[1197]: info: MYVOLUMIO Environment detected Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: Plugin folders cleanup Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: Scanning into folder /volumio/app/plugins/ Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: Scanning category audio_interface Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: Scanning category miscellanea Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: Scanning category music_service Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: Scanning category plugins.json Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: Scanning category system_controller Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: Scanning category user_interface Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: Scanning into folder /data/plugins/ Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: Scanning category music_service Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: Plugin folders cleanup completed Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: ------------------------------------------- Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: ----- Core plugins startup ---- Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: ------------------------------------------- Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: Loading plugins from folder /volumio/app/plugins/ Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: Adding plugin upnp to MyMusic Plugins Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: Loading plugins from folder /data/plugins/ Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: Loading plugin "system"... Dec 16 22:20:11 volumio-elutuba volumio[1197]: info: Loading plugin "appearance"... Dec 16 22:20:13 volumio-elutuba ntpd[881]: CLOCK: time stepped by 0.349544 Dec 16 22:20:13 volumio-elutuba ntpd[881]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Dec 16 22:20:13 volumio-elutuba volumio[1197]: info: Loading plugin "network"... Dec 16 22:20:13 volumio-elutuba volumio[1197]: info: Refreshing Cached IP Addresses Dec 16 22:20:13 volumio-elutuba sudo[1240]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 16 22:20:13 volumio-elutuba sudo[1240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:13 volumio-elutuba volumio[1197]: info: Loading plugin "services"... Dec 16 22:20:13 volumio-elutuba volumio[1197]: info: Loading plugin "alsa_controller"... Dec 16 22:20:13 volumio-elutuba sudo[1240]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:13 volumio-elutuba sudo[1241]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 16 22:20:13 volumio-elutuba sudo[1241]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:14 volumio-elutuba sudo[1241]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:14 volumio-elutuba sudo[1248]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 16 22:20:14 volumio-elutuba sudo[1248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:14 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 16 22:20:14 volumio-elutuba volumio[1197]: info: Loading plugin "wizard"... Dec 16 22:20:14 volumio-elutuba volumio[1197]: info: Loading plugin "networkfs"... Dec 16 22:20:14 volumio-elutuba volumio[1197]: info: Starting Udev Watcher for removable devices Dec 16 22:20:14 volumio-elutuba sudo[1270]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=muzz,password=Karutyra123,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.155/Media/mp3 /mnt/NAS/Media Dec 16 22:20:14 volumio-elutuba sudo[1270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:14 volumio-elutuba volumio[1197]: info: Ignoring mount for partition: boot Dec 16 22:20:14 volumio-elutuba volumio[1197]: info: Ignoring mount for partition: volumio Dec 16 22:20:14 volumio-elutuba volumio[1197]: info: Ignoring mount for partition: volumio_data Dec 16 22:20:14 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 16 22:20:14 volumio-elutuba volumio[1197]: info: Loading plugin "volumio_command_line_client"... Dec 16 22:20:14 volumio-elutuba volumio[1197]: info: Loading plugin "upnp"... Dec 16 22:20:14 volumio-elutuba volumio[1197]: info: [1765916414458] Starting Upmpd Daemon Dec 16 22:20:14 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 16 22:20:14 volumio-elutuba kernel: netfs: FS-Cache loaded Dec 16 22:20:14 volumio-elutuba volumio[1197]: info: Loading plugin "my_music"... Dec 16 22:20:14 volumio-elutuba volumio[1197]: info: Loading plugin "mpd"... Dec 16 22:20:14 volumio-elutuba kernel: Key type cifs.spnego registered Dec 16 22:20:14 volumio-elutuba kernel: Key type cifs.idmap registered Dec 16 22:20:14 volumio-elutuba kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Dec 16 22:20:14 volumio-elutuba kernel: CIFS: Attempting to mount //192.168.0.155/Media/mp3 Dec 16 22:20:14 volumio-elutuba sudo[1248]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:15 volumio-elutuba sudo[1270]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:15 volumio-elutuba volumio[1197]: info: Loading plugin "upnp_browser"... Dec 16 22:20:18 volumio-elutuba volumio[1197]: info: Starting UPNP Browser Dec 16 22:20:18 volumio-elutuba volumio[1197]: info: Loading plugin "alarm-clock"... Dec 16 22:20:18 volumio-elutuba volumio[1197]: info: Loading plugin "airplay_emulation"... Dec 16 22:20:18 volumio-elutuba volumio[1197]: info: Starting Shairport Sync Dec 16 22:20:18 volumio-elutuba volumio[1197]: info: Loading plugin "last_100"... Dec 16 22:20:18 volumio-elutuba volumio[1197]: info: Loading plugin "webradio"... Dec 16 22:20:18 volumio-elutuba volumio[1197]: info: Loading plugin "i2s_dacs"... Dec 16 22:20:18 volumio-elutuba volumio[1197]: info: I2S DAC not set, start Auto-detection Dec 16 22:20:18 volumio-elutuba volumio[1197]: info: Loading plugin "volumiodiscovery"... Dec 16 22:20:18 volumio-elutuba volumio[1197]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 16 22:20:18 volumio-elutuba volumio[1197]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 16 22:20:18 volumio-elutuba volumio[1197]: *** WARNING *** For more information see Dec 16 22:20:18 volumio-elutuba volumio[1197]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 16 22:20:18 volumio-elutuba volumio[1197]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 16 22:20:18 volumio-elutuba volumio[1197]: *** WARNING *** For more information see Dec 16 22:20:18 volumio-elutuba node[1197]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 16 22:20:18 volumio-elutuba node[1197]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 16 22:20:18 volumio-elutuba node[1197]: *** WARNING *** For more information see Dec 16 22:20:18 volumio-elutuba node[1197]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 16 22:20:18 volumio-elutuba node[1197]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 16 22:20:18 volumio-elutuba node[1197]: *** WARNING *** For more information see Dec 16 22:20:18 volumio-elutuba volumio[1197]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 16 22:20:18 volumio-elutuba volumio[1197]: info: Discovery: Started advertising with name: Volumio Elutuba Dec 16 22:20:19 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 16 22:20:19 volumio-elutuba volumio[1197]: info: Loading plugin "spop"... Dec 16 22:20:22 volumio-elutuba systemd[1]: systemd-fsckd.service: Deactivated successfully. Dec 16 22:20:22 volumio-elutuba volumio[1197]: info: Loading plugin "outputs"... Dec 16 22:20:22 volumio-elutuba volumio[1197]: info: Loading plugin "albumart"... Dec 16 22:20:22 volumio-elutuba volumio[1197]: info: Plugin example_plugin is not enabled Dec 16 22:20:22 volumio-elutuba volumio[1197]: info: Loading plugin "inputs"... Dec 16 22:20:22 volumio-elutuba volumio[1197]: info: Loading plugin "updater_comm"... Dec 16 22:20:22 volumio-elutuba volumio-remote-updater[703]: [2025-12-16 22:20:22] [connect] Successful connection Dec 16 22:20:23 volumio-elutuba volumio[1197]: info: Plugin mpdemulation is not enabled Dec 16 22:20:23 volumio-elutuba volumio[1197]: info: Loading plugin "rest_api"... Dec 16 22:20:23 volumio-elutuba volumio[1197]: info: Loading plugin "websocket"... Dec 16 22:20:23 volumio-elutuba volumio[1197]: info: Starting Socket.io Server version 1.7.4 Dec 16 22:20:23 volumio-elutuba volumio[1197]: info: Loading i18n strings for locale en Dec 16 22:20:23 volumio-elutuba volumio[1197]: Updating browse sources language Dec 16 22:20:23 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 16 22:20:24 volumio-elutuba volumio[1300]: Forking 3 albumart workers Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CoreCommandRouter::initPlayerControls Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 16 22:20:24 volumio-elutuba volumio[1197]: Express server listening on port 3000 Dec 16 22:20:24 volumio-elutuba volumio[1197]: [Metrics] WebUI: 16s 827.94ms Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CoreStateMachine::resetVolumioState Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CoreStateMachine::getcurrentVolume Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioRetrievevolume Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CoreStateMachine::pushState Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CorePlayQueue::getTrack 0 Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioPushState Dec 16 22:20:24 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 16 22:20:25 volumio-elutuba sudo[1356]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 16 22:20:25 volumio-elutuba sudo[1357]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 16 22:20:25 volumio-elutuba sudo[1357]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:25 volumio-elutuba sudo[1356]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:25 volumio-elutuba sudo[1357]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:25 volumio-elutuba sudo[1356]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:25 volumio-elutuba volumio[1197]: info: Volumio Network Manager: Network status updated: 1 Dec 16 22:20:25 volumio-elutuba systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Dec 16 22:20:25 volumio-elutuba systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 16 22:20:25 volumio-elutuba systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 16 22:20:26 volumio-elutuba upmpdcli[1365]: :3:../libupnpp/upnpplib.cxx:273::LibUPnP: Using IPV4 192.168.0.98 port 49152 IPV6 port 49152 Dec 16 22:20:26 volumio-elutuba upmpdcli[1365]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Connection refused Dec 16 22:20:26 volumio-elutuba upmpdcli[1365]: :2:../src/main.cxx:728::MPD connection failed Dec 16 22:20:26 volumio-elutuba volumio[1197]: verbose: New Socket.io Connection to 192.168.0.98:3000 from 192.168.0.85 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Dec 16 22:20:26 volumio-elutuba volumio[1197]: info: Reloading queue from file Dec 16 22:20:27 volumio-elutuba volumio[1197]: verbose: New Socket.io Connection to 192.168.0.98 from 192.168.0.144 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Dec 16 22:20:27 volumio-elutuba volumio[1197]: info: CoreStateMachine::setRepeat null single undefined Dec 16 22:20:27 volumio-elutuba volumio[1197]: info: CoreStateMachine::pushState Dec 16 22:20:27 volumio-elutuba volumio[1197]: info: CorePlayQueue::getTrack 0 Dec 16 22:20:27 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 16 22:20:27 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioPushState Dec 16 22:20:27 volumio-elutuba volumio[1197]: info: CoreStateMachine::setRandom null Dec 16 22:20:27 volumio-elutuba volumio[1197]: info: CoreStateMachine::pushState Dec 16 22:20:27 volumio-elutuba volumio[1197]: info: CorePlayQueue::getTrack 0 Dec 16 22:20:27 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioPushState Dec 16 22:20:27 volumio-elutuba volumio[1197]: info: Setting Device type: Raspberry PI Dec 16 22:20:27 volumio-elutuba volumio[1197]: verbose: New Socket.io Connection to 192.168.0.98 from 192.168.0.144 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 16 22:20:27 volumio-elutuba volumio[1197]: verbose: New Socket.io Connection to 192.168.0.98:3000 from 192.168.0.85 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 16 22:20:27 volumio-elutuba volumio[1197]: info: Discovery: adding 7794f19c-746b-4192-b06f-eca3305a3cb5 Dec 16 22:20:27 volumio-elutuba volumio[1197]: info: Discovery: Found device Volumio Garaaz Dec 16 22:20:27 volumio-elutuba sudo[1386]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 16 22:20:27 volumio-elutuba sudo[1386]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:27 volumio-elutuba sudo[1386]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:28 volumio-elutuba upmpdcli[1365]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Connection refused Dec 16 22:20:28 volumio-elutuba upmpdcli[1365]: :2:../src/main.cxx:728::MPD connection failed Dec 16 22:20:28 volumio-elutuba volumio[1197]: info: Discovery: Connecting to remote: 192.168.0.85 Dec 16 22:20:28 volumio-elutuba systemd[1]: systemd-hostnamed.service: Deactivated successfully. Dec 16 22:20:28 volumio-elutuba volumio[1197]: info: Discovery: adding 64f6dff1-8013-4085-9664-eea37ddbb490 Dec 16 22:20:28 volumio-elutuba volumio[1197]: info: Discovery: Found device Volumio Elutuba Dec 16 22:20:28 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioGetState Dec 16 22:20:28 volumio-elutuba volumio[1197]: info: CorePlayQueue::getTrack 0 Dec 16 22:20:28 volumio-elutuba volumio[1197]: verbose: New Socket.io Connection to 192.168.0.98:3000 from 192.168.0.85 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 16 22:20:28 volumio-elutuba volumio[1197]: verbose: New Socket.io Connection to 192.168.0.98 from 192.168.0.144 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Dec 16 22:20:28 volumio-elutuba volumio[1197]: info: Upmpdcli Daemon Started Dec 16 22:20:28 volumio-elutuba volumio[1197]: info: Discovery: this is already registered, 64f6dff1-8013-4085-9664-eea37ddbb490 Dec 16 22:20:28 volumio-elutuba volumio[1197]: info: Discovery: Found device Volumio Elutuba Dec 16 22:20:28 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioGetState Dec 16 22:20:28 volumio-elutuba volumio[1197]: info: CorePlayQueue::getTrack 0 Dec 16 22:20:28 volumio-elutuba volumio[1197]: verbose: New Socket.io Connection to 192.168.0.98:3000 from 192.168.0.85 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 16 22:20:29 volumio-elutuba volumio[1197]: info: Completed loading Core Plugins Dec 16 22:20:29 volumio-elutuba volumio[1197]: info: Preparing to generate the ALSA configuration file Dec 16 22:20:29 volumio-elutuba volumio[1197]: info: Discovery: Connected to remote: 192.168.0.85 Dec 16 22:20:29 volumio-elutuba volumio[1197]: info: Asound.conf file unchanged, so no further update is needed Dec 16 22:20:29 volumio-elutuba volumio[1197]: info: Output device has changed, restarting MPD Dec 16 22:20:29 volumio-elutuba volumio[1197]: info: Output device has changed, restarting Shairport Sync Dec 16 22:20:29 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:29 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 16 22:20:30 volumio-elutuba sudo[1394]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 16 22:20:30 volumio-elutuba sudo[1392]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 16 22:20:30 volumio-elutuba sudo[1392]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:30 volumio-elutuba sudo[1394]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:30 volumio-elutuba volumio[1197]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 16 22:20:30 volumio-elutuba volumio[1197]: info: ___________ START PLUGINS ___________ Dec 16 22:20:30 volumio-elutuba sudo[1392]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:30 volumio-elutuba volumio[1197]: info: ControllerMpd::onStart: Initializing MPD Dec 16 22:20:30 volumio-elutuba volumio[1197]: info: Creating MPD Configuration file Dec 16 22:20:30 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 16 22:20:30 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 16 22:20:30 volumio-elutuba volumio[1197]: info: [1765916430386] CoreMusicLibrary::Adding element Media Servers Dec 16 22:20:30 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 16 22:20:30 volumio-elutuba systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 16 22:20:30 volumio-elutuba systemd[1]: Starting mpd.service - Music Player Daemon... Dec 16 22:20:30 volumio-elutuba volumio[1197]: info: UPNP Browser: Client initialized successfully Dec 16 22:20:30 volumio-elutuba sudo[1402]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 16 22:20:30 volumio-elutuba sudo[1404]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 16 22:20:30 volumio-elutuba sudo[1404]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:30 volumio-elutuba sudo[1402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:30 volumio-elutuba sudo[1402]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:30 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:30 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 16 22:20:30 volumio-elutuba sudo[1406]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 16 22:20:30 volumio-elutuba sudo[1406]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 16 22:20:30 volumio-elutuba sudo[1411]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 16 22:20:30 volumio-elutuba sudo[1406]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:30 volumio-elutuba systemd[1]: mpd.service: Deactivated successfully. Dec 16 22:20:30 volumio-elutuba systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 16 22:20:30 volumio-elutuba systemd[1]: mpd.socket: Deactivated successfully. Dec 16 22:20:30 volumio-elutuba systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 16 22:20:30 volumio-elutuba systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 16 22:20:30 volumio-elutuba systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 16 22:20:30 volumio-elutuba systemd[1]: Starting mpd.service - Music Player Daemon... Dec 16 22:20:31 volumio-elutuba volumio[1197]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 16 22:20:31 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:31 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 16 22:20:31 volumio-elutuba volumio[1197]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 16 22:20:31 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 16 22:20:31 volumio-elutuba volumio[1197]: info: [1765916431106] CoreMusicLibrary::Adding element Last_100 Dec 16 22:20:31 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 16 22:20:31 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 16 22:20:31 volumio-elutuba volumio[1197]: info: [1765916431111] CoreMusicLibrary::Adding element Webradio Dec 16 22:20:31 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 16 22:20:31 volumio-elutuba sudo[1416]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 16 22:20:31 volumio-elutuba sudo[1416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 16 22:20:31 volumio-elutuba sudo[1421]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 16 22:20:31 volumio-elutuba sudo[1416]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:31 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 16 22:20:31 volumio-elutuba volumio[1197]: info: Initializing BBC Radios Dec 16 22:20:32 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 16 22:20:32 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 16 22:20:32 volumio-elutuba volumio[1197]: info: Creating Spotify config file Dec 16 22:20:32 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:33 volumio-elutuba systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 16 22:20:34 volumio-elutuba upmpdcli[1365]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Dec 16 22:20:34 volumio-elutuba upmpdcli[1365]: :2:../src/main.cxx:728::MPD connection failed Dec 16 22:20:35 volumio-elutuba volumio[1197]: info: Volumio Calling Home Dec 16 22:20:35 volumio-elutuba systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 16 22:20:35 volumio-elutuba systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 16 22:20:35 volumio-elutuba systemd[1]: setdatetime-helper.service: Consumed 1.074s CPU time. Dec 16 22:20:35 volumio-elutuba volumio[1324]: Starting albumart workers Dec 16 22:20:35 volumio-elutuba volumio[1325]: Starting albumart workers Dec 16 22:20:36 volumio-elutuba volumio[1326]: Starting albumart workers Dec 16 22:20:37 volumio-elutuba volumio-remote-updater[703]: [2025-12-16 22:20:37] [connect] Successful connection Dec 16 22:20:38 volumio-elutuba volumio[1197]: verbose: New Socket.io Connection to 192.168.0.98 from 192.168.0.144 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Dec 16 22:20:39 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Dec 16 22:20:39 volumio-elutuba volumio[1197]: info: MPD Permissions set Dec 16 22:20:39 volumio-elutuba volumio[1197]: info: MPD Permissions set Dec 16 22:20:39 volumio-elutuba volumio[1197]: verbose: New Socket.io Connection to 192.168.0.98 from 192.168.0.144 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Dec 16 22:20:40 volumio-elutuba volumio[1197]: info: Volumio called home Dec 16 22:20:40 volumio-elutuba mpd[1422]: 2025-12-16T22:20:40 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 16 22:20:40 volumio-elutuba volumio[1197]: info: Spotify config file written Dec 16 22:20:40 volumio-elutuba sudo[1488]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 16 22:20:40 volumio-elutuba sudo[1488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:40 volumio-elutuba systemd[1]: Started mpd.service - Music Player Daemon. Dec 16 22:20:40 volumio-elutuba sudo[1394]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:40 volumio-elutuba sudo[1404]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:40 volumio-elutuba 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 16 22:20:40 volumio-elutuba 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 16 22:20:40 volumio-elutuba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 16 22:20:40 volumio-elutuba go-librespot[1493]: go-librespot daemon starting... Dec 16 22:20:40 volumio-elutuba sudo[1488]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:41 volumio-elutuba volumio-remote-updater[703]: [2025-12-16 22:20:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765916437 101 Dec 16 22:20:41 volumio-elutuba volumio[1197]: 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: 10 Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:41 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:41+02:00" level=info msg="running go-librespot 0.4.0" Dec 16 22:20:41 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:41+02:00" level=debug msg="app state loaded" Dec 16 22:20:41 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:41+02:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: No need to fix Spotify hosts Dec 16 22:20:41 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:41+02: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 16 22:20:41 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:41+02: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 16 22:20:41 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:41+02: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 16 22:20:41 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:41+02:00" level=info msg="zeroconf server listening on port 44231" Dec 16 22:20:41 volumio-elutuba volumio[1197]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: Completed starting Core Plugins Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: ------------------------------------------- Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: ----- MyVolumio plugins startup ---- Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: ------------------------------------------- Dec 16 22:20:41 volumio-elutuba volumio[1197]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 16 22:20:41 volumio-elutuba volumio[1197]: verbose: New Socket.io Connection to 192.168.0.98 from 192.168.0.144 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Dec 16 22:20:42 volumio-elutuba volumio[1197]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 16 22:20:42 volumio-elutuba volumio[1197]: SPOTIFY: BQBsTUmDheZ0fEs2ipWmlS4LrJHCKzwhNuO0j4D7b5yFJHziuJNh9bPLp9lTZXfBjKTfvN1RrmSjyZZAhJ26QMQm1f0csjvtBemmYnCi29DcwJ25FXE5TcBhtaPpqYh2vAe_8sgQB7aBIirYJeD1HUU5flu53VuH3lBu_oKkV2zQAGMPiXixxQtaUu4svYGM8jnluhcFnc3hzrLXHs_scGO1zmRENrUb4hjMjnMQ1Z-KkWW3dox4faZZHG8vg_eNS2ZwOwa5tFmN-p3FuYIjAhIGjmziavUxpOoluA3xdcyU_LbotQ2mZcGq Dec 16 22:20:42 volumio-elutuba volumio[1197]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 16 22:20:42 volumio-elutuba volumio[1197]: info: New Spotify access token = BQBsTUmDheZ0fEs2ipWmlS4LrJHCKzwhNuO0j4D7b5yFJHziuJNh9bPLp9lTZXfBjKTfvN1RrmSjyZZAhJ26QMQm1f0csjvtBemmYnCi29DcwJ25FXE5TcBhtaPpqYh2vAe_8sgQB7aBIirYJeD1HUU5flu53VuH3lBu_oKkV2zQAGMPiXixxQtaUu4svYGM8jnluhcFnc3hzrLXHs_scGO1zmRENrUb4hjMjnMQ1Z-KkWW3dox4faZZHG8vg_eNS2ZwOwa5tFmN-p3FuYIjAhIGjmziavUxpOoluA3xdcyU_LbotQ2mZcGq Dec 16 22:20:42 volumio-elutuba volumio[1197]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=debug msg="obtained new client token: AABlasj6suHSnE2Sl5cGnGTmgtgcyM2KwLXMpz0uaO18n6/QIme/nHmG6RhIPRi+yzGKGlbRApKtVmFagMRMRGMV7hrexBE/TSv8FcxHhJDKzUZ9R8jydGYKigh7stAjrDkm+EAvRiXg+5+U65nEHNm3VtBPQyNH9Z3lwMQiTiljAXHlW5sawqtsYXNnfBhuqKPxC+eh4cfCkErNG6TKvd9FuSAi4KSECuRITw9TLpe735pQydR+Aw==" Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 16 22:20:42 volumio-elutuba upmpdcli[1527]: writing RSA key Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=debug msg="completed keyexchange" Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=debug msg="completed challenge" Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=info msg="authenticated AP" username="rp*********************io" Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=info msg="authenticated Login5" username="rp*********************io" Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=debug msg="initializing zeroconf session" username="rp*********************io" Dec 16 22:20:42 volumio-elutuba volumio[1197]: error: MPD error: The expression evaluated to a falsy value: Dec 16 22:20:42 volumio-elutuba volumio[1197]: assert.ok(self.idling) Dec 16 22:20:42 volumio-elutuba volumio[1197]: error: The expression evaluated to a falsy value: Dec 16 22:20:42 volumio-elutuba volumio[1197]: assert.ok(self.idling) Dec 16 22:20:42 volumio-elutuba volumio[1197]: info: Starting Shairport Sync Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=debug msg="dealer connection opened" Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=trace msg="starting accesspoint recv loop" Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=trace msg="starting dealer recv loop" Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=trace msg="received accesspoint ping" Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=debug msg="received connection id: YWRiMzVjMTctMDM0...N0MyQzg4Q0FDMQ==" Dec 16 22:20:42 volumio-elutuba volumio[1197]: info: Starting Shairport Sync Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=trace msg="received accesspoint pong ack" Dec 16 22:20:42 volumio-elutuba volumio[1197]: info: Starting Shairport Sync Dec 16 22:20:42 volumio-elutuba sudo[1533]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 16 22:20:42 volumio-elutuba sudo[1533]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:42 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=debug msg="put connect state because NEW_DEVICE" Dec 16 22:20:42 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:42+02:00" level=debug msg="update volume requested to 65535/65535" Dec 16 22:20:42 volumio-elutuba sudo[1535]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 16 22:20:42 volumio-elutuba sudo[1535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:42 volumio-elutuba volumio[1197]: error: updateQueue error: null Dec 16 22:20:42 volumio-elutuba systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 16 22:20:42 volumio-elutuba systemd[1]: shairport-sync.service: Deactivated successfully. Dec 16 22:20:42 volumio-elutuba systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 16 22:20:42 volumio-elutuba systemd[1]: shairport-sync.service: Consumed 1.992s CPU time. Dec 16 22:20:42 volumio-elutuba sudo[1537]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 16 22:20:42 volumio-elutuba sudo[1537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:42 volumio-elutuba volumio[1197]: info: MPD running with PID1422 Dec 16 22:20:42 volumio-elutuba volumio[1197]: ,establishing connection Dec 16 22:20:43 volumio-elutuba systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 16 22:20:43 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:43+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 16 22:20:43 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:20:43+02:00" level=trace msg="emitting websocket event: volume" Dec 16 22:20:43 volumio-elutuba sudo[1533]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:43 volumio-elutuba systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 16 22:20:43 volumio-elutuba systemd[1]: shairport-sync.service: Deactivated successfully. Dec 16 22:20:43 volumio-elutuba systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 16 22:20:43 volumio-elutuba systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 16 22:20:43 volumio-elutuba sudo[1537]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:43 volumio-elutuba sudo[1535]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: Received Get System Info Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: Discovery: Getting this device information Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioGetState Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CorePlayQueue::getTrack 0 Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioGetVisibleSources Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioGetState Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CorePlayQueue::getTrack 0 Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioGetState Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CorePlayQueue::getTrack 0 Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioGetQueue Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CoreStateMachine::getQueue Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CorePlayQueue::getQueue Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: Listing playlists Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: Received Get System Info Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: Discovery: Getting this device information Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioGetState Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CorePlayQueue::getTrack 0 Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioGetState Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: CorePlayQueue::getTrack 0 Dec 16 22:20:43 volumio-elutuba volumio[1197]: info: Shairport-Sync Started Dec 16 22:20:43 volumio-elutuba volumio[1197]: Error adding Membership: Error: addMembership EINVAL Dec 16 22:20:44 volumio-elutuba volumio[1197]: info: Shairport-Sync Started Dec 16 22:20:44 volumio-elutuba volumio[1197]: info: Shairport-Sync Started Dec 16 22:20:44 volumio-elutuba volumio[1197]: error: updateQueue error: null Dec 16 22:20:44 volumio-elutuba volumio[1197]: verbose: New Socket.io Connection to 192.168.0.98:3000 from 192.168.0.85 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Dec 16 22:20:44 volumio-elutuba volumio[1197]: info: go-librespot daemon successfully initialized Dec 16 22:20:45 volumio-elutuba sudo[1577]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 16 22:20:45 volumio-elutuba sudo[1577]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:45 volumio-elutuba systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 16 22:20:45 volumio-elutuba mpd_monitor.sh[1579]: MPD Monitor Service: Starting MPD Monitor Service Dec 16 22:20:45 volumio-elutuba sudo[1577]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:45 volumio-elutuba volumio[1197]: info: Successfully started MPD Monitor Dec 16 22:20:45 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioGetState Dec 16 22:20:45 volumio-elutuba volumio[1197]: info: CorePlayQueue::getTrack 0 Dec 16 22:20:45 volumio-elutuba sudo[1584]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 16 22:20:45 volumio-elutuba sudo[1584]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 16 22:20:45 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Dec 16 22:20:45 volumio-elutuba systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 16 22:20:45 volumio-elutuba systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 16 22:20:45 volumio-elutuba systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 16 22:20:45 volumio-elutuba volumio[1197]: verbose: New Socket.io Connection to 192.168.0.98:3000 from 192.168.0.85 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Dec 16 22:20:45 volumio-elutuba systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 16 22:20:45 volumio-elutuba mpd_monitor.sh[1586]: MPD Monitor Service: Starting MPD Monitor Service Dec 16 22:20:45 volumio-elutuba sudo[1584]: pam_unix(sudo:session): session closed for user root Dec 16 22:20:46 volumio-elutuba volumio[1197]: info: Successfully started MPD Monitor Dec 16 22:20:46 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Dec 16 22:20:46 volumio-elutuba volumio[1197]: SPOTIFY: User informations: {"country":"EE","display_name":"Laur","email":"pajulalaur@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/rptya6vrwqlidgjw1flqx1oio"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/rptya6vrwqlidgjw1flqx1oio","id":"rptya6vrwqlidgjw1flqx1oio","images":[],"product":"premium","type":"user","uri":"spotify:user:rptya6vrwqlidgjw1flqx1oio"} Dec 16 22:20:46 volumio-elutuba volumio[1197]: info: Spotify Successfully logged in Dec 16 22:20:46 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 16 22:20:46 volumio-elutuba volumio[1197]: info: [1765916446217] CoreMusicLibrary::Adding element Spotify Dec 16 22:20:46 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 16 22:20:46 volumio-elutuba volumio[1197]: Cannot find translation for source Spotify Dec 16 22:20:46 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumioGetState Dec 16 22:20:46 volumio-elutuba volumio[1197]: info: CorePlayQueue::getTrack 0 Dec 16 22:20:47 volumio-elutuba volumio[1197]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 16 22:20:51 volumio-elutuba volumio[1197]: info: Initializing connection to go-librespot Websocket Dec 16 22:21:05 volumio-elutuba volumio[1197]: Cannot compose Albumart path Dec 16 22:21:08 volumio-elutuba volumio[1197]: Cannot compose Albumart path Dec 16 22:21:09 volumio-elutuba volumio[1197]: Cannot compose Albumart path Dec 16 22:21:09 volumio-elutuba volumio[1197]: Cannot compose Albumart path Dec 16 22:21:10 volumio-elutuba volumio[1197]: Cannot compose Albumart path Dec 16 22:21:10 volumio-elutuba volumio[1197]: Cannot compose Albumart path Dec 16 22:21:12 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:21:12+02:00" level=trace msg="sent dealer ping" Dec 16 22:21:12 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:21:12+02:00" level=trace msg="received dealer pong" Dec 16 22:21:13 volumio-elutuba volumio[1197]: Cannot compose Albumart path Dec 16 22:21:13 volumio-elutuba volumio[1197]: Cannot compose Albumart path Dec 16 22:21:13 volumio-elutuba volumio[1197]: Cannot compose Albumart path Dec 16 22:21:13 volumio-elutuba volumio[1197]: Cannot compose Albumart path Dec 16 22:21:13 volumio-elutuba volumio[1197]: Cannot compose Albumart path Dec 16 22:21:13 volumio-elutuba volumio[1197]: Cannot compose Albumart path Dec 16 22:21:14 volumio-elutuba volumio[1197]: Cannot compose Albumart path Dec 16 22:21:14 volumio-elutuba volumio[1197]: Cannot compose Albumart path Dec 16 22:21:16 volumio-elutuba go-librespot[1499]: time="2025-12-16T22:21:16+02:00" level=debug msg="new websocket client" Dec 16 22:21:16 volumio-elutuba volumio[1197]: error: MyVolumio Plugin failed to start in a timely fashion Dec 16 22:21:16 volumio-elutuba volumio[1197]: [Metrics] CommandRouter: 67s 348.91ms Dec 16 22:21:16 volumio-elutuba volumio[1197]: info: CoreCommandRouter::volumiosetStartupVolume Dec 16 22:21:16 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 16 22:21:16 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 16 22:21:16 volumio-elutuba volumio[1197]: info: CoreCommandRouter::Close All Modals sent Dec 16 22:21:16 volumio-elutuba volumio[1197]: info: CoreCommandRouter::Close All Modals sent Dec 16 22:21:16 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 16 22:21:16 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 16 22:21:16 volumio-elutuba volumio[1197]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 16 22:21:17 volumio-elutuba volumio[1197]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 16 22:21:17 volumio-elutuba volumio[1197]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals. Dec 16 22:21:17 volumio-elutuba volumio[1197]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues Dec 16 22:21:17 volumio-elutuba volumio[1197]: at new NodeError (node:internal/errors:405:5) Dec 16 22:21:17 volumio-elutuba volumio[1197]: at assert (node:internal/assert:14:11) Dec 16 22:21:17 volumio-elutuba volumio[1197]: at internalConnectMultiple (node:net:1118:3) Dec 16 22:21:17 volumio-elutuba volumio[1197]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3) Dec 16 22:21:17 volumio-elutuba volumio[1197]: at listOnTimeout (node:internal/timers:575:11) Dec 16 22:21:17 volumio-elutuba volumio[1197]: at process.processTimers (node:internal/timers:514:7) { Dec 16 22:21:17 volumio-elutuba volumio[1197]: code: 'ERR_INTERNAL_ASSERTION' Dec 16 22:21:17 volumio-elutuba volumio[1197]: } Dec 16 22:21:17 volumio-elutuba volumio[1197]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 16 22:21:23 volumio-elutuba sudo[1658]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-16 22:20' Dec 16 22:21:23 volumio-elutuba sudo[1658]: 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"