Dec 11 12:52:12 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 11 12:52:12 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 11 12:52:12 volumio systemd[1]: setdatetime-helper.service: Consumed 1.670s CPU time. Dec 11 12:52:12 volumio systemd[1]: Started winbind.service - Samba Winbind Daemon. Dec 11 12:52:12 volumio sudo[1178]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Dec 11 12:52:12 volumio sudo[1178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 11 12:52:12 volumio sudo[1178]: pam_unix(sudo:session): session closed for user root Dec 11 12:52:12 volumio systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Dec 11 12:52:12 volumio systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Dec 11 12:52:12 volumio systemd[1]: Starting smbd.service - Samba SMB Daemon... Dec 11 12:52:12 volumio sudo[1189]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Dec 11 12:52:12 volumio systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Dec 11 12:52:12 volumio sudo[1189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 11 12:52:12 volumio systemd[1]: dpkg-db-backup.service: Deactivated successfully. Dec 11 12:52:12 volumio systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Dec 11 12:52:12 volumio ntpd[1005]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 11 12:52:12 volumio ntpd[1005]: IO: Listen normally on 3 eth0 192.168.1.175:123 Dec 11 12:52:12 volumio ntpd[1005]: IO: new interface(s) found: waking up resolver Dec 11 12:52:12 volumio ntpd[1005]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Dec 11 12:52:12 volumio ntpd[1005]: DNS: Pool taking: 152.53.173.111 Dec 11 12:52:12 volumio ntpd[1005]: DNS: Pool taking: 136.243.177.133 Dec 11 12:52:12 volumio ntpd[1005]: DNS: Pool taking: 158.180.28.150 Dec 11 12:52:12 volumio ntpd[1005]: DNS: Pool taking: 89.57.40.248 Dec 11 12:52:12 volumio ntpd[1005]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Dec 11 12:52:12 volumio sudo[1189]: pam_unix(sudo:session): session closed for user root Dec 11 12:52:13 volumio smbd[1203]: [2025/12/11 12:52:13.000215, 0] ../../source3/smbd/server.c:1741(main) Dec 11 12:52:13 volumio smbd[1203]: smbd version 4.17.8-Raspbian started. Dec 11 12:52:13 volumio smbd[1203]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Dec 11 12:52:13 volumio wireless.js[682]: WIRELESS.JS: Stopped aP Dec 11 12:52:13 volumio wireless.js[682]: WIRELESS.JS: Wireless Networking DISABLED, not starting wireless flow Dec 11 12:52:13 volumio ntpd[1005]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 11 12:52:13 volumio ntpd[1005]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Dec 11 12:52:13 volumio ntpd[1005]: DNS: Pool skipping: 141.144.246.224 Dec 11 12:52:13 volumio ntpd[1005]: DNS: Pool skipping: 5.75.181.179 Dec 11 12:52:13 volumio ntpd[1005]: DNS: Pool skipping: 81.3.27.46 Dec 11 12:52:13 volumio ntpd[1005]: DNS: Pool skipping: 116.202.118.202 Dec 11 12:52:13 volumio ntpd[1005]: DNS: Pool skipping: 2a00:f48:2000:102c::8:2 Dec 11 12:52:13 volumio ntpd[1005]: DNS: Pool skipping: 240b:4005:12b:fb00:d11d:fbb7:f895:76be Dec 11 12:52:13 volumio ntpd[1005]: DNS: Pool skipping: 2a01:239:307:2200::1 Dec 11 12:52:13 volumio ntpd[1005]: DNS: Pool skipping: 2a01:4f8:1c1a:4548::123 Dec 11 12:52:13 volumio ntpd[1005]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Dec 11 12:52:13 volumio wireless.js[682]: WIRELESS.JS: Notified systemd about wireless ready Dec 11 12:52:13 volumio systemd[1]: Started wireless.service - Wireless Services. Dec 11 12:52:13 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Dec 11 12:52:13 volumio systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... Dec 11 12:52:13 volumio systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker. Dec 11 12:52:13 volumio systemd[1]: Received SIGRTMIN+21 from PID 307 (plymouthd). Dec 11 12:52:13 volumio systemd[1]: Received SIGRTMIN+21 from PID 307 (plymouthd). Dec 11 12:52:13 volumio systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. Dec 11 12:52:13 volumio systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. Dec 11 12:52:13 volumio volumio-cpu-tweak[1229]: Setting RT Priority for mpd Dec 11 12:52:13 volumio volumio-cpu-tweak[1243]: pid 35's current scheduling policy: SCHED_OTHER Dec 11 12:52:13 volumio volumio-cpu-tweak[1243]: pid 35's current scheduling priority: 0 Dec 11 12:52:13 volumio volumio-cpu-tweak[1229]: Setting MPD Affinity Dec 11 12:52:13 volumio volumio-cpu-tweak[1244]: pid 3's current affinity mask: f Dec 11 12:52:13 volumio volumio-cpu-tweak[1229]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Dec 11 12:52:13 volumio volumio-cpu-tweak[1229]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Dec 11 12:52:14 volumio systemd[1]: volumio_cpu_tweak.service: Deactivated successfully. Dec 11 12:52:14 volumio ntpd[1005]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 11 12:52:14 volumio ntpd[1005]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Dec 11 12:52:14 volumio ntpd[1005]: DNS: Pool taking: 141.144.241.16 Dec 11 12:52:14 volumio ntpd[1005]: DNS: Pool skipping: 5.75.181.179 Dec 11 12:52:14 volumio ntpd[1005]: DNS: Pool taking: 131.188.3.220 Dec 11 12:52:14 volumio ntpd[1005]: DNS: Pool taking: 82.165.53.158 Dec 11 12:52:14 volumio ntpd[1005]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Dec 11 12:52:14 volumio systemd[1]: Started smbd.service - Samba SMB Daemon. Dec 11 12:52:14 volumio systemd[1]: Reached target multi-user.target - Multi-User System. Dec 11 12:52:14 volumio systemd[1]: Reached target graphical.target - Graphical Interface. Dec 11 12:52:15 volumio systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Dec 11 12:52:15 volumio systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Dec 11 12:52:15 volumio systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Dec 11 12:52:15 volumio systemd[1]: Startup finished in 18.213s (kernel) + 15.383s (userspace) = 33.596s. Dec 11 12:52:18 volumio volumio-remote-updater[679]: [2025-12-11 12:52:18] [connect] Successful connection Dec 11 12:52:19 volumio ntpd[1005]: CLOCK: time stepped by 1.033779 Dec 11 12:52:19 volumio ntpd[1005]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Dec 11 12:52:20 volumio volumio[1227]: info: ------------------------------------------- Dec 11 12:52:20 volumio volumio[1227]: info: ----- Volumio3 ---- Dec 11 12:52:20 volumio volumio[1227]: info: ------------------------------------------- Dec 11 12:52:20 volumio volumio[1227]: info: ----- System startup ---- Dec 11 12:52:20 volumio volumio[1227]: info: ------------------------------------------- Dec 11 12:52:21 volumio volumio[1227]: info: MYVOLUMIO Environment detected Dec 11 12:52:21 volumio volumio[1227]: info: Plugin folders cleanup Dec 11 12:52:21 volumio volumio[1227]: info: Scanning into folder /volumio/app/plugins/ Dec 11 12:52:21 volumio volumio[1227]: info: Scanning category audio_interface Dec 11 12:52:21 volumio volumio[1227]: info: Scanning category miscellanea Dec 11 12:52:21 volumio volumio[1227]: info: Scanning category music_service Dec 11 12:52:21 volumio volumio[1227]: info: Scanning category plugins.json Dec 11 12:52:21 volumio volumio[1227]: info: Scanning category system_controller Dec 11 12:52:21 volumio volumio[1227]: info: Scanning category user_interface Dec 11 12:52:21 volumio volumio[1227]: info: Scanning into folder /data/plugins/ Dec 11 12:52:21 volumio volumio[1227]: info: Scanning category music_service Dec 11 12:52:21 volumio volumio[1227]: info: Scanning category system_hardware Dec 11 12:52:21 volumio volumio[1227]: info: Scanning category user_interface Dec 11 12:52:21 volumio volumio[1227]: info: Plugin folders cleanup completed Dec 11 12:52:21 volumio volumio[1227]: info: ------------------------------------------- Dec 11 12:52:21 volumio volumio[1227]: info: ----- Core plugins startup ---- Dec 11 12:52:21 volumio volumio[1227]: info: ------------------------------------------- Dec 11 12:52:21 volumio volumio[1227]: info: Loading plugins from folder /volumio/app/plugins/ Dec 11 12:52:21 volumio volumio[1227]: info: Adding plugin upnp to MyMusic Plugins Dec 11 12:52:21 volumio volumio[1227]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 11 12:52:21 volumio volumio[1227]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 11 12:52:21 volumio volumio[1227]: info: Loading plugins from folder /data/plugins/ Dec 11 12:52:22 volumio volumio[1227]: info: Loading plugin "system"... Dec 11 12:52:22 volumio volumio[1227]: info: Loading plugin "appearance"... Dec 11 12:52:22 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Dec 11 12:52:22 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 11 12:52:22 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 11 12:52:22 volumio upmpdcli[1268]: Could not open config: /tmp/upmpdcli.conf Dec 11 12:52:22 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 11 12:52:22 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 11 12:52:24 volumio volumio[1227]: info: Loading plugin "network"... Dec 11 12:52:24 volumio volumio[1227]: info: Refreshing Cached IP Addresses Dec 11 12:52:25 volumio sudo[1271]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 11 12:52:25 volumio sudo[1272]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 11 12:52:25 volumio sudo[1272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 11 12:52:25 volumio sudo[1271]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 11 12:52:25 volumio volumio[1227]: info: Loading plugin "services"... Dec 11 12:52:25 volumio sudo[1272]: pam_unix(sudo:session): session closed for user root Dec 11 12:52:25 volumio sudo[1271]: pam_unix(sudo:session): session closed for user root Dec 11 12:52:25 volumio volumio[1227]: info: Loading plugin "alsa_controller"... Dec 11 12:52:25 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 11 12:52:25 volumio volumio[1227]: info: Loading plugin "wizard"... Dec 11 12:52:25 volumio volumio[1227]: info: Loading plugin "networkfs"... Dec 11 12:52:25 volumio volumio[1227]: info: Starting Udev Watcher for removable devices Dec 11 12:52:25 volumio sudo[1301]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Andi,password=Steve55Jobs,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.70/Unterhaltung\\__music\\__Musik_Sammlung /mnt/NAS/Musik Dec 11 12:52:25 volumio sudo[1303]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Andi,password=Steve55Jobs,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.70/Unterhaltung\\__music\\__Musik_Trekstore /mnt/NAS/Trekstore Dec 11 12:52:25 volumio sudo[1303]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 11 12:52:25 volumio sudo[1301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 11 12:52:25 volumio volumio[1227]: info: Ignoring mount for partition: boot Dec 11 12:52:25 volumio volumio[1227]: info: Ignoring mount for partition: volumio Dec 11 12:52:25 volumio volumio[1227]: info: Ignoring mount for partition: volumio_data Dec 11 12:52:25 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 11 12:52:25 volumio volumio[1227]: info: Loading plugin "volumio_command_line_client"... Dec 11 12:52:25 volumio kernel: netfs: FS-Cache loaded Dec 11 12:52:25 volumio volumio[1227]: info: Loading plugin "upnp"... Dec 11 12:52:25 volumio volumio[1227]: info: [1765453945729] Starting Upmpd Daemon Dec 11 12:52:25 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 11 12:52:25 volumio volumio[1227]: info: Loading plugin "my_music"... Dec 11 12:52:25 volumio volumio[1227]: info: Loading plugin "mpd"... Dec 11 12:52:25 volumio kernel: Key type cifs.spnego registered Dec 11 12:52:25 volumio kernel: Key type cifs.idmap registered Dec 11 12:52:25 volumio 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 11 12:52:25 volumio kernel: CIFS: Attempting to mount //192.168.1.70/Unterhaltung/__music/__Musik_Sammlung Dec 11 12:52:26 volumio volumio[1227]: info: Plugin upnp_browser is not enabled Dec 11 12:52:26 volumio volumio[1227]: info: Loading plugin "alarm-clock"... Dec 11 12:52:26 volumio sudo[1301]: pam_unix(sudo:session): session closed for user root Dec 11 12:52:26 volumio kernel: CIFS: Attempting to mount //192.168.1.70/Unterhaltung/__music/__Musik_Trekstore Dec 11 12:52:27 volumio sudo[1303]: pam_unix(sudo:session): session closed for user root Dec 11 12:52:27 volumio volumio[1227]: info: Plugin airplay_emulation is not enabled Dec 11 12:52:27 volumio volumio[1227]: info: Loading plugin "last_100"... Dec 11 12:52:27 volumio volumio[1227]: info: Loading plugin "webradio"... Dec 11 12:52:30 volumio volumio[1227]: info: Loading plugin "i2s_dacs"... Dec 11 12:52:30 volumio volumio[1227]: info: Loading plugin "volumiodiscovery"... Dec 11 12:52:30 volumio volumio[1227]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 11 12:52:30 volumio volumio[1227]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 11 12:52:30 volumio volumio[1227]: *** WARNING *** For more information see Dec 11 12:52:30 volumio volumio[1227]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 11 12:52:30 volumio volumio[1227]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 11 12:52:30 volumio volumio[1227]: *** WARNING *** For more information see Dec 11 12:52:30 volumio node[1227]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 11 12:52:30 volumio node[1227]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 11 12:52:30 volumio node[1227]: *** WARNING *** For more information see Dec 11 12:52:30 volumio node[1227]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 11 12:52:30 volumio node[1227]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 11 12:52:30 volumio node[1227]: *** WARNING *** For more information see Dec 11 12:52:30 volumio volumio[1227]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 11 12:52:30 volumio volumio[1227]: info: Discovery: Started advertising with name: Volumio Dec 11 12:52:30 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 11 12:52:30 volumio volumio[1227]: info: Loading plugin "bandcamp"... Dec 11 12:52:34 volumio volumio[1227]: info: Loading plugin "soundcloud"... Dec 11 12:52:34 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully. Dec 11 12:52:34 volumio volumio-remote-updater[679]: [2025-12-11 12:52:34] [connect] Successful connection Dec 11 12:52:35 volumio volumio[1227]: info: Loading plugin "spop"... Dec 11 12:52:37 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Dec 11 12:52:37 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 11 12:52:37 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 11 12:52:37 volumio upmpdcli[1361]: Could not open config: /tmp/upmpdcli.conf Dec 11 12:52:37 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 11 12:52:37 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 11 12:52:39 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully. Dec 11 12:52:39 volumio volumio[1227]: info: Loading plugin "outputs"... Dec 11 12:52:39 volumio volumio[1227]: info: Loading plugin "albumart"... Dec 11 12:52:39 volumio volumio[1227]: info: Plugin example_plugin is not enabled Dec 11 12:52:39 volumio volumio[1227]: info: Loading plugin "inputs"... Dec 11 12:52:39 volumio volumio[1227]: info: Loading plugin "updater_comm"... Dec 11 12:52:40 volumio volumio[1227]: info: Plugin mpdemulation is not enabled Dec 11 12:52:40 volumio volumio[1227]: info: Loading plugin "rest_api"... Dec 11 12:52:40 volumio volumio[1227]: info: Loading plugin "websocket"... Dec 11 12:52:40 volumio volumio[1227]: info: Starting Socket.io Server version 1.7.4 Dec 11 12:52:40 volumio volumio[1227]: info: Loading plugin "radio_paradise"... Dec 11 12:52:40 volumio sshd[1362]: Accepted password for volumio from 192.168.1.186 port 57918 ssh2 Dec 11 12:52:40 volumio sshd[1362]: pam_unix(sshd:session): session opened for user volumio(uid=1000) by (uid=0) Dec 11 12:52:40 volumio systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. Dec 11 12:52:40 volumio systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... Dec 11 12:52:40 volumio systemd-logind[676]: New session 1 of user volumio. Dec 11 12:52:40 volumio systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. Dec 11 12:52:40 volumio systemd[1]: Starting user@1000.service - User Manager for UID 1000... Dec 11 12:52:40 volumio (systemd)[1378]: pam_unix(systemd-user:session): session opened for user volumio(uid=1000) by (uid=0) Dec 11 12:52:41 volumio volumio[1227]: info: Applying required configuration parameters for plugin radio_paradise Dec 11 12:52:41 volumio volumio[1227]: info: [1765453961344] [RadioParadise] API delay: 5 Dec 11 12:52:41 volumio volumio[1227]: info: Loading plugin "Bluetoothremote"... Dec 11 12:52:41 volumio systemd[1378]: Queued start job for default target default.target. Dec 11 12:52:41 volumio systemd[1378]: Created slice app.slice - User Application Slice. Dec 11 12:52:41 volumio systemd[1378]: Reached target paths.target - Paths. Dec 11 12:52:41 volumio systemd[1378]: Reached target timers.target - Timers. Dec 11 12:52:41 volumio systemd[1378]: Starting dbus.socket - D-Bus User Message Bus Socket... Dec 11 12:52:41 volumio systemd[1378]: Listening on dirmngr.socket - GnuPG network certificate management daemon. Dec 11 12:52:41 volumio systemd[1378]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Dec 11 12:52:41 volumio systemd[1378]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Dec 11 12:52:41 volumio systemd[1378]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Dec 11 12:52:41 volumio systemd[1378]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Dec 11 12:52:41 volumio systemd[1378]: Listening on dbus.socket - D-Bus User Message Bus Socket. Dec 11 12:52:41 volumio volumio[1367]: Forking 3 albumart workers Dec 11 12:52:41 volumio systemd[1378]: Reached target sockets.target - Sockets. Dec 11 12:52:41 volumio systemd[1378]: Reached target basic.target - Basic System. Dec 11 12:52:41 volumio systemd[1]: Started user@1000.service - User Manager for UID 1000. Dec 11 12:52:41 volumio systemd[1378]: Started mpris-proxy.service - Bluetooth mpris proxy. Dec 11 12:52:41 volumio systemd[1378]: Reached target default.target - Main User Target. Dec 11 12:52:41 volumio systemd[1378]: Startup finished in 1.123s. Dec 11 12:52:41 volumio systemd[1]: Started session-1.scope - Session 1 of User volumio. Dec 11 12:52:42 volumio systemd[1378]: Created slice session.slice - User Core Session Slice. Dec 11 12:52:42 volumio systemd[1378]: Starting dbus.service - D-Bus User Message Bus... Dec 11 12:52:42 volumio systemd[1378]: Started dbus.service - D-Bus User Message Bus. Dec 11 12:52:42 volumio sshd[1362]: pam_env(sshd:session): deprecated reading of user environment enabled Dec 11 12:52:43 volumio volumio[1227]: info: Applying required configuration parameters for plugin Bluetoothremote Dec 11 12:52:43 volumio volumio[1227]: info: Loading plugin "Systeminfo"... Dec 11 12:52:45 volumio volumio[1227]: info: Loading i18n strings for locale de Dec 11 12:52:45 volumio volumio[1227]: Updating browse sources language Dec 11 12:52:46 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 11 12:52:46 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 11 12:52:46 volumio volumio[1227]: info: CoreCommandRouter::initPlayerControls Dec 11 12:52:46 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:46 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:46 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:46 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:46 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:46 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:46 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:46 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:46 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 11 12:52:46 volumio volumio[1227]: Express server listening on port 3000 Dec 11 12:52:46 volumio volumio[1227]: [Metrics] WebUI: 27s 718.55ms Dec 11 12:52:46 volumio volumio[1227]: info: CoreStateMachine::resetVolumioState Dec 11 12:52:46 volumio volumio[1227]: info: CoreStateMachine::getcurrentVolume Dec 11 12:52:46 volumio volumio[1227]: info: CoreCommandRouter::volumioRetrievevolume Dec 11 12:52:46 volumio sudo[1462]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 11 12:52:46 volumio sudo[1462]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 11 12:52:46 volumio sudo[1463]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 11 12:52:46 volumio sudo[1463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 11 12:52:46 volumio sudo[1462]: pam_unix(sudo:session): session closed for user root Dec 11 12:52:46 volumio sudo[1463]: pam_unix(sudo:session): session closed for user root Dec 11 12:52:46 volumio volumio[1227]: info: Volumio Network Manager: Network status updated: 1 Dec 11 12:52:47 volumio volumio[1227]: info: VolumeController:: Volume=100 Mute =false Dec 11 12:52:47 volumio volumio[1227]: info: CoreStateMachine::pushState Dec 11 12:52:47 volumio volumio[1227]: info: CorePlayQueue::getTrack 0 Dec 11 12:52:47 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 11 12:52:47 volumio volumio[1227]: info: CoreCommandRouter::volumioPushState Dec 11 12:52:47 volumio volumio[1227]: info: CoreStateMachine::updateTrackBlock Dec 11 12:52:47 volumio volumio[1227]: info: CorePlayQueue::getTrackBlock Dec 11 12:52:47 volumio volumio[1227]: info: CoreCommandRouter::volumioRetrievevolume Dec 11 12:52:48 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 11 12:52:48 volumio volumio[1227]: info: Reloading queue from file Dec 11 12:52:48 volumio volumio[1227]: info: CoreStateMachine::setRepeat null single undefined Dec 11 12:52:48 volumio volumio[1227]: info: CoreStateMachine::pushState Dec 11 12:52:48 volumio volumio[1227]: info: CorePlayQueue::getTrack 0 Dec 11 12:52:48 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 11 12:52:48 volumio volumio[1227]: info: CoreCommandRouter::volumioPushState Dec 11 12:52:48 volumio volumio[1227]: info: CoreStateMachine::setRandom true Dec 11 12:52:48 volumio volumio[1227]: info: CoreStateMachine::pushState Dec 11 12:52:48 volumio volumio[1227]: info: CorePlayQueue::getTrack 0 Dec 11 12:52:48 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 11 12:52:48 volumio volumio[1227]: info: CoreCommandRouter::volumioPushState Dec 11 12:52:48 volumio volumio[1227]: info: Setting Device type: Raspberry PI Dec 11 12:52:48 volumio volumio[1227]: info: Completed loading Core Plugins Dec 11 12:52:48 volumio volumio[1227]: info: Preparing to generate the ALSA configuration file Dec 11 12:52:48 volumio volumio[1227]: info: VolumeController:: Volume=100 Mute =false Dec 11 12:52:48 volumio volumio[1227]: info: CoreStateMachine::pushState Dec 11 12:52:49 volumio volumio[1227]: info: CorePlayQueue::getTrack 0 Dec 11 12:52:49 volumio volumio[1227]: info: CoreCommandRouter::volumioPushState Dec 11 12:52:49 volumio volumio[1227]: info: Discovery: adding 4f12fa0f-3f69-4775-84e3-74790cde9db8 Dec 11 12:52:49 volumio volumio[1227]: info: Discovery: Found device Volumio Dec 11 12:52:49 volumio volumio[1227]: info: CoreCommandRouter::volumioGetState Dec 11 12:52:49 volumio volumio[1227]: info: CorePlayQueue::getTrack 0 Dec 11 12:52:49 volumio volumio[1227]: info: Asound.conf file unchanged, so no further update is needed Dec 11 12:52:49 volumio sudo[1478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 11 12:52:49 volumio volumio[1227]: info: Output device has changed, restarting MPD Dec 11 12:52:49 volumio sudo[1478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 11 12:52:49 volumio volumio[1227]: info: ___________ START PLUGINS ___________ Dec 11 12:52:49 volumio volumio[1227]: info: ControllerMpd::onStart: Initializing MPD Dec 11 12:52:49 volumio sudo[1481]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 11 12:52:49 volumio volumio[1227]: info: Creating MPD Configuration file Dec 11 12:52:49 volumio sudo[1481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 11 12:52:49 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 11 12:52:49 volumio sudo[1481]: pam_unix(sudo:session): session closed for user root Dec 11 12:52:49 volumio volumio[1227]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 11 12:52:49 volumio volumio[1227]: info: [1765453969486] CoreMusicLibrary::Adding element Last_100 Dec 11 12:52:49 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 11 12:52:49 volumio volumio-remote-updater[679]: [2025-12-11 12:52:49] [connect] Successful connection Dec 11 12:52:49 volumio sudo[1483]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 11 12:52:49 volumio sudo[1483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 11 12:52:49 volumio volumio[1227]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 11 12:52:49 volumio volumio[1227]: info: [1765453969544] CoreMusicLibrary::Adding element Webradio Dec 11 12:52:49 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 11 12:52:49 volumio sudo[1487]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 11 12:52:49 volumio sudo[1487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 11 12:52:49 volumio sudo[1487]: pam_unix(sudo:session): session closed for user root Dec 11 12:52:49 volumio sudo[1490]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 11 12:52:49 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 11 12:52:49 volumio sudo[1490]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 11 12:52:49 volumio volumio[1227]: info: Initializing BBC Radios Dec 11 12:52:49 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 11 12:52:49 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 11 12:52:49 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 11 12:52:49 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 11 12:52:49 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 11 12:52:49 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 11 12:52:49 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 11 12:52:49 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 11 12:52:49 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 11 12:52:49 volumio volumio[1397]: Starting albumart workers Dec 11 12:52:50 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 11 12:52:50 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 11 12:52:50 volumio volumio[1227]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 11 12:52:50 volumio volumio[1227]: info: [1765453970173] CoreMusicLibrary::Adding element Bandcamp Discover Dec 11 12:52:50 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 11 12:52:50 volumio volumio[1227]: Cannot find translation for source Bandcamp Discover Dec 11 12:52:50 volumio volumio[1227]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 11 12:52:50 volumio volumio[1227]: info: [1765453970267] CoreMusicLibrary::Adding element SoundCloud Dec 11 12:52:50 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 11 12:52:50 volumio volumio[1227]: Cannot find translation for source Bandcamp Discover Dec 11 12:52:50 volumio volumio[1227]: Cannot find translation for source SoundCloud Dec 11 12:52:50 volumio volumio[1395]: Starting albumart workers Dec 11 12:52:50 volumio volumio[1227]: info: Creating Spotify config file Dec 11 12:52:50 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:50 volumio volumio[1396]: Starting albumart workers Dec 11 12:52:51 volumio sudo[1518]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 11 12:52:51 volumio sudo[1518]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 11 12:52:51 volumio sudo[1525]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 11 12:52:51 volumio sudo[1518]: pam_unix(sudo:session): session closed for user root Dec 11 12:52:52 volumio volumio[1227]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 11 12:52:52 volumio volumio[1227]: info: [1765453972818] CoreMusicLibrary::Adding element Radio Paradise Dec 11 12:52:52 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 11 12:52:52 volumio volumio[1227]: Cannot find translation for source Bandcamp Discover Dec 11 12:52:52 volumio volumio[1227]: Cannot find translation for source SoundCloud Dec 11 12:52:52 volumio volumio[1227]: Cannot find translation for source Radio Paradise Dec 11 12:52:52 volumio volumio[1227]: info: Loading i18n strings for locale de Dec 11 12:52:52 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Dec 11 12:52:52 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 11 12:52:52 volumio volumio[1227]: info: Volumio Calling Home Dec 11 12:52:52 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 11 12:52:53 volumio sudo[1478]: pam_unix(sudo:session): session closed for user root Dec 11 12:52:54 volumio volumio[1227]: info: Discovery: this is already registered, 4f12fa0f-3f69-4775-84e3-74790cde9db8 Dec 11 12:52:54 volumio volumio[1227]: info: Discovery: Found device Volumio Dec 11 12:52:54 volumio volumio[1227]: info: CoreCommandRouter::volumioGetState Dec 11 12:52:54 volumio volumio[1227]: info: CorePlayQueue::getTrack 0 Dec 11 12:52:55 volumio volumio[1227]: info: MPD Permissions set Dec 11 12:52:55 volumio volumio[1227]: info: MPD Permissions set Dec 11 12:52:55 volumio volumio[1227]: info: Upmpdcli Daemon Started Dec 11 12:52:56 volumio volumio[1227]: info: Volumio called home Dec 11 12:52:56 volumio volumio[1227]: info: Spotify config file written Dec 11 12:52:56 volumio sudo[1582]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 11 12:52:56 volumio sudo[1582]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 11 12:52:56 volumio 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 11 12:52:56 volumio 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 11 12:52:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 11 12:52:56 volumio go-librespot[1584]: go-librespot daemon starting... Dec 11 12:52:56 volumio sudo[1582]: pam_unix(sudo:session): session closed for user root Dec 11 12:52:57 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 11 12:52:57 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 11 12:52:57 volumio systemd[1]: setdatetime-helper.service: Consumed 1.436s CPU time. Dec 11 12:52:57 volumio volumio[1227]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: No need to fix Spotify hosts Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 11 12:52:57 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 11 12:52:57 volumio go-librespot[1585]: time="2025-12-11T12:52:57+01:00" level=info msg="running go-librespot 0.4.0" Dec 11 12:52:57 volumio go-librespot[1585]: time="2025-12-11T12:52:57+01:00" level=debug msg="app state loaded" Dec 11 12:52:57 volumio go-librespot[1585]: time="2025-12-11T12:52:57+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 11 12:52:58 volumio volumio[1227]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 11 12:52:58 volumio volumio[1227]: SPOTIFY: BQCJvgQlQsEH3wwUPxRNamx67vPg8533iMG6oreNUqKIK4ktxTX_-Eakh50eeGXKhhDQrSx7f3LUWmqEkrgIwhhzFaabX_3pZL1ahIb9_ICkaOHK0KIJFiFT6-36L6RZEluRxl1X_7YPtezVkwZqaPNCtQoboLg3sVtCUZAOeC0BSHKnQjf5h0AAvIIFcQQdCGRHX-RiubeGaAdEuZ-nsxKn44vNVHGt6c8JI0KcjzE6x8HJCn6XEU7KwLp0JJH0Y9wmGen67ngS_hHYhxZ6VI_s8Ca1EvExMg Dec 11 12:52:58 volumio volumio[1227]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 11 12:52:58 volumio volumio[1227]: info: New Spotify access token = BQCJvgQlQsEH3wwUPxRNamx67vPg8533iMG6oreNUqKIK4ktxTX_-Eakh50eeGXKhhDQrSx7f3LUWmqEkrgIwhhzFaabX_3pZL1ahIb9_ICkaOHK0KIJFiFT6-36L6RZEluRxl1X_7YPtezVkwZqaPNCtQoboLg3sVtCUZAOeC0BSHKnQjf5h0AAvIIFcQQdCGRHX-RiubeGaAdEuZ-nsxKn44vNVHGt6c8JI0KcjzE6x8HJCn6XEU7KwLp0JJH0Y9wmGen67ngS_hHYhxZ6VI_s8Ca1EvExMg Dec 11 12:52:58 volumio volumio[1227]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 11 12:52:59 volumio volumio[1227]: info: CoreCommandRouter::volumioGetState Dec 11 12:52:59 volumio volumio[1227]: info: CorePlayQueue::getTrack 0 Dec 11 12:52:59 volumio volumio[1227]: SPOTIFY: User informations: {"country":"DE","display_name":"zaffford","email":"home@holz-arc.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/zaffford"},"followers":{"href":null,"total":2},"href":"https://api.spotify.com/v1/users/zaffford","id":"zaffford","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85977d7ca9d99f336be9856828","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82977d7ca9d99f336be9856828","width":64}],"product":"premium","type":"user","uri":"spotify:user:zaffford"} Dec 11 12:52:59 volumio volumio[1227]: info: Spotify Successfully logged in Dec 11 12:52:59 volumio volumio[1227]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 11 12:52:59 volumio volumio[1227]: info: [1765453979149] CoreMusicLibrary::Adding element Spotify Dec 11 12:52:59 volumio volumio[1227]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 11 12:52:59 volumio volumio[1227]: Cannot find translation for source Bandcamp Discover Dec 11 12:52:59 volumio volumio[1227]: Cannot find translation for source SoundCloud Dec 11 12:52:59 volumio volumio[1227]: Cannot find translation for source Radio Paradise Dec 11 12:52:59 volumio volumio[1227]: Cannot find translation for source Spotify Dec 11 12:52:59 volumio go-librespot[1585]: time="2025-12-11T12:52:59+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 11 12:52:59 volumio go-librespot[1585]: time="2025-12-11T12:52:59+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 11 12:52:59 volumio go-librespot[1585]: time="2025-12-11T12:52:59+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 11 12:52:59 volumio go-librespot[1585]: time="2025-12-11T12:52:59+01:00" level=info msg="zeroconf server listening on port 42725" Dec 11 12:52:59 volumio go-librespot[1585]: time="2025-12-11T12:52:59+01:00" level=debug msg="obtained new client token: AADyh/ozGWB1k5ZsZCe+29ka4f9/NxX26rkcmG9BmeMD/wttUUqPcxyziy98xfSHGKL4VZ/9YF06wrld+anvy38Eqz02HdVoka/8my/JkNIs8tRHRYmDXioBQ7/1xPza0eNQCjQN3gzoRPcdWU38rautW0mV3iHuDoJfb9kRMgKFLwJlScydHHWX2+Khg7LxiUVVaHY44ejVyp6jkDKdF0uCO0W9j5QrZpe1wjoX3ZufFBjtIC2pMaNrJ0E=" Dec 11 12:52:59 volumio go-librespot[1585]: time="2025-12-11T12:52:59+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 11 12:53:00 volumio go-librespot[1585]: time="2025-12-11T12:53:00+01: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: read tcp 192.168.1.175:37114->34.158.1.133:4070: read: connection reset by peer" Dec 11 12:53:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 11 12:53:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 11 12:53:00 volumio volumio[1227]: info: go-librespot daemon successfully initialized Dec 11 12:53:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 11 12:53:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 11 12:53:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 11 12:53:03 volumio go-librespot[1609]: go-librespot daemon starting... Dec 11 12:53:03 volumio go-librespot[1610]: time="2025-12-11T12:53:03+01:00" level=info msg="running go-librespot 0.4.0" Dec 11 12:53:03 volumio go-librespot[1610]: time="2025-12-11T12:53:03+01:00" level=debug msg="app state loaded" Dec 11 12:53:03 volumio go-librespot[1610]: time="2025-12-11T12:53:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 11 12:53:03 volumio volumio[1227]: info: Initializing connection to go-librespot Websocket Dec 11 12:53:04 volumio go-librespot[1610]: time="2025-12-11T12:53:04+01:00" level=debug msg="new websocket client" Dec 11 12:53:04 volumio go-librespot[1610]: time="2025-12-11T12:53:04+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 11 12:53:04 volumio go-librespot[1610]: time="2025-12-11T12:53:04+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 11 12:53:04 volumio go-librespot[1610]: time="2025-12-11T12:53:04+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 11 12:53:04 volumio volumio[1227]: info: Connection to go-librespot Websocket established Dec 11 12:53:04 volumio go-librespot[1610]: time="2025-12-11T12:53:04+01:00" level=info msg="zeroconf server listening on port 41897" Dec 11 12:53:04 volumio go-librespot[1610]: time="2025-12-11T12:53:04+01:00" level=debug msg="obtained new client token: AADJHjE8jtdfyd7BdevjnaOooBUBUUd8xzv66Z1tnEVCtG/cDyVOzsvwMxKtdInWPH24oCfrdWQaYWuL5BDoCvOAoNpNL5dF7TDBr5El58gXy/b4Dz9ZgCnTz4B8YgvRhibylW/UEiQWS/AwRvFaTNAUt7KaMHQMLEpYJZB82jxhDapD0n1oA1DaVV81N4c0i7dlHKXl5g5cg5zKCHv7RNUZH0PHMmivo8ZofBGu68p1uGkcrq2+8Wh2Z7M=" Dec 11 12:53:04 volumio volumio-remote-updater[679]: [2025-12-11 12:53:04] [connect] Successful connection Dec 11 12:53:04 volumio volumio-remote-updater[679]: [2025-12-11 12:53:04] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765453984 101 Dec 11 12:53:04 volumio go-librespot[1610]: time="2025-12-11T12:53:04+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 11 12:53:04 volumio go-librespot[1610]: time="2025-12-11T12:53:04+01: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 11 12:53:04 volumio volumio[1227]: 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: 2 Dec 11 12:53:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 11 12:53:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 11 12:53:04 volumio volumio[1227]: info: Connection to go-librespot Websocket closed Dec 11 12:53:07 volumio volumio[1227]: info: Getting Spotify volume Dec 11 12:53:07 volumio volumio[1227]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 11 12:53:07 volumio volumio[1227]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 11 12:53:07 volumio volumio[1227]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 11 12:53:07 volumio volumio[1227]: errno: -111, Dec 11 12:53:07 volumio volumio[1227]: code: 'ECONNREFUSED', Dec 11 12:53:07 volumio volumio[1227]: syscall: 'connect', Dec 11 12:53:07 volumio volumio[1227]: address: '127.0.0.1', Dec 11 12:53:07 volumio volumio[1227]: port: 9879, Dec 11 12:53:07 volumio volumio[1227]: response: undefined Dec 11 12:53:07 volumio volumio[1227]: } Dec 11 12:53:07 volumio volumio[1227]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 11 12:53:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 11 12:53:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 11 12:53:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 11 12:53:07 volumio go-librespot[1643]: go-librespot daemon starting... Dec 11 12:53:07 volumio go-librespot[1644]: time="2025-12-11T12:53:07+01:00" level=info msg="running go-librespot 0.4.0" Dec 11 12:53:07 volumio go-librespot[1644]: time="2025-12-11T12:53:07+01:00" level=debug msg="app state loaded" Dec 11 12:53:07 volumio go-librespot[1644]: time="2025-12-11T12:53:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 11 12:53:08 volumio go-librespot[1644]: time="2025-12-11T12:53:08+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 11 12:53:08 volumio go-librespot[1644]: time="2025-12-11T12:53:08+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 11 12:53:08 volumio go-librespot[1644]: time="2025-12-11T12:53:08+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 11 12:53:08 volumio go-librespot[1644]: time="2025-12-11T12:53:08+01:00" level=info msg="zeroconf server listening on port 33859" Dec 11 12:53:09 volumio go-librespot[1644]: time="2025-12-11T12:53:09+01:00" level=debug msg="obtained new client token: AABxL/RmlsQXd1snoY5OuIs1TKABfC6CNpnsnOw1QEp7kx92NBg9shb4xZ7ayU+kMQuMUmM4Kkk0XOitVaSgOIN6gvb1c1gr5tRi0WvVM8rwZn8niaCo0yKNNsQLhPvlmY/Mqn5DpXQCtWV231Xu311LpigclgtWbCR9ShFM/9RGm4ZSTKeeeddLbbhvDf3+zEn8XJHXeAVlU01Uk0dZ9e3nz7a/O5BqgK7JS4t8qPkBfaNHbE6jp6eL" Dec 11 12:53:09 volumio go-librespot[1644]: time="2025-12-11T12:53:09+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 11 12:53:09 volumio go-librespot[1644]: time="2025-12-11T12:53:09+01: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 11 12:53:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 11 12:53:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 11 12:53:09 volumio sudo[1608]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/usr/bin/apt update Dec 11 12:53:09 volumio sudo[1608]: pam_unix(sudo:session): session opened for user root(uid=0) by volumio(uid=1000) Dec 11 12:53:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 11 12:53:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 11 12:53:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 11 12:53:12 volumio go-librespot[1822]: go-librespot daemon starting... Dec 11 12:53:12 volumio go-librespot[1830]: time="2025-12-11T12:53:12+01:00" level=info msg="running go-librespot 0.4.0" Dec 11 12:53:12 volumio go-librespot[1830]: time="2025-12-11T12:53:12+01:00" level=debug msg="app state loaded" Dec 11 12:53:12 volumio go-librespot[1830]: time="2025-12-11T12:53:12+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 11 12:53:14 volumio go-librespot[1830]: time="2025-12-11T12:53:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 11 12:53:14 volumio go-librespot[1830]: time="2025-12-11T12:53:14+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 11 12:53:14 volumio go-librespot[1830]: time="2025-12-11T12:53:14+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 11 12:53:14 volumio sudo[1839]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-11 12:52' Dec 11 12:53:14 volumio sudo[1839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 11 12:53:14 volumio go-librespot[1830]: time="2025-12-11T12:53:14+01:00" level=info msg="zeroconf server listening on port 36669" 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"