Jan 28 13:25:09 volumio-manu systemd[1]: setdatetime-helper.service: Deactivated successfully. Jan 28 13:25:09 volumio-manu systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Jan 28 13:25:09 volumio-manu systemd[1]: setdatetime-helper.service: Consumed 1.499s CPU time. Jan 28 13:25:09 volumio-manu systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Jan 28 13:25:09 volumio-manu systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Jan 28 13:25:09 volumio-manu systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Jan 28 13:25:09 volumio-manu sudo[1139]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jan 28 13:25:09 volumio-manu sudo[1139]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 13:25:09 volumio-manu sudo[1139]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:09 volumio-manu systemd[1]: dpkg-db-backup.service: Deactivated successfully. Jan 28 13:25:09 volumio-manu systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Jan 28 13:25:09 volumio-manu sudo[1162]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jan 28 13:25:09 volumio-manu sudo[1162]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 13:25:09 volumio-manu systemd[1]: systemd-rfkill.service: Deactivated successfully. Jan 28 13:25:10 volumio-manu ntpd[850]: IO: Listen normally on 3 eth0 192.168.1.96:123 Jan 28 13:25:10 volumio-manu ntpd[850]: IO: new interface(s) found: waking up resolver Jan 28 13:25:10 volumio-manu ntpd[850]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Jan 28 13:25:10 volumio-manu sudo[1162]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:10 volumio-manu ntpd[850]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Jan 28 13:25:10 volumio-manu ntpd[850]: DNS: Pool skipping: 45.13.105.44 Jan 28 13:25:10 volumio-manu ntpd[850]: DNS: Pool skipping: 38.143.19.16 Jan 28 13:25:10 volumio-manu ntpd[850]: DNS: Pool skipping: 82.65.248.56 Jan 28 13:25:10 volumio-manu ntpd[850]: DNS: Pool skipping: 141.95.158.40 Jan 28 13:25:10 volumio-manu ntpd[850]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Jan 28 13:25:10 volumio-manu wireless.js[701]: WIRELESS.JS - INFO: Cleaning previous... Jan 28 13:25:10 volumio-manu smbd[1157]: [2026/01/28 13:25:10.053861, 0] ../../source3/smbd/server.c:1741(main) Jan 28 13:25:10 volumio-manu smbd[1157]: smbd version 4.17.8-Raspbian started. Jan 28 13:25:10 volumio-manu smbd[1157]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Jan 28 13:25:10 volumio-manu sudo[1167]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Jan 28 13:25:10 volumio-manu sudo[1167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 13:25:10 volumio-manu sudo[1167]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:10 volumio-manu kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jan 28 13:25:10 volumio-manu winbindd[1114]: [2026/01/28 13:25:10.225364, 0] ../../source3/winbindd/winbindd_idmap.c:372(wb_parent_idmap_setup_lookupname_done) Jan 28 13:25:10 volumio-manu winbindd[1114]: wb_parent_idmap_setup_lookupname_done: Lookup domain name 'VOLUMIO MANU' failed 'NT_STATUS_IO_TIMEOUT' Jan 28 13:25:10 volumio-manu wireless.js[701]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Jan 28 13:25:10 volumio-manu wireless.js[701]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 7ms Jan 28 13:25:10 volumio-manu wireless.js[701]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: b8:27:eb:29:34:a0) Jan 28 13:25:10 volumio-manu systemd[1]: Started smbd.service - Samba SMB Daemon. Jan 28 13:25:10 volumio-manu sudo[1179]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Jan 28 13:25:10 volumio-manu sudo[1179]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:10 volumio-manu sudo[1179]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:10 volumio-manu sudo[1187]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Jan 28 13:25:10 volumio-manu sudo[1187]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:10 volumio-manu ntpd[850]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Jan 28 13:25:10 volumio-manu winbindd[1127]: [2026/01/28 13:25:10.660508, 0] ../../source3/winbindd/winbindd_dual.c:162(child_write_response) Jan 28 13:25:10 volumio-manu winbindd[1127]: Could not write result Jan 28 13:25:11 volumio-manu ntpd[850]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Jan 28 13:25:11 volumio-manu ntpd[850]: DNS: Pool taking: 31.58.102.164 Jan 28 13:25:11 volumio-manu ntpd[850]: DNS: Pool taking: 51.91.83.168 Jan 28 13:25:11 volumio-manu ntpd[850]: DNS: Pool taking: 45.140.164.53 Jan 28 13:25:11 volumio-manu ntpd[850]: DNS: Pool taking: 172.232.63.219 Jan 28 13:25:11 volumio-manu ntpd[850]: DNS: Pool taking: 2a01:cb00:129e:a803::108 Jan 28 13:25:11 volumio-manu ntpd[850]: DNS: Pool taking: 2001:41d0:8:7a7d::1 Jan 28 13:25:11 volumio-manu ntpd[850]: DNS: Pool taking: 2600:3c07::f03c:94ff:fee2:c558 Jan 28 13:25:11 volumio-manu ntpd[850]: DNS: Pool taking: 2a01:e0a:431:b527::a123 Jan 28 13:25:11 volumio-manu ntpd[850]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Jan 28 13:25:11 volumio-manu ntpd[850]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Jan 28 13:25:11 volumio-manu ntpd[850]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Jan 28 13:25:11 volumio-manu ntpd[850]: DNS: Pool taking: 185.254.100.25 Jan 28 13:25:11 volumio-manu ntpd[850]: DNS: Pool skipping: 82.65.248.56 Jan 28 13:25:11 volumio-manu ntpd[850]: DNS: Pool taking: 82.64.45.50 Jan 28 13:25:11 volumio-manu ntpd[850]: DNS: Pool taking: 51.68.44.27 Jan 28 13:25:11 volumio-manu ntpd[850]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Jan 28 13:25:12 volumio-manu ntpd[850]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Jan 28 13:25:12 volumio-manu ntpd[850]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Jan 28 13:25:12 volumio-manu ntpd[850]: DNS: Pool taking: 51.210.178.126 Jan 28 13:25:12 volumio-manu ntpd[850]: DNS: Pool taking: 82.64.247.11 Jan 28 13:25:12 volumio-manu ntpd[850]: DNS: Pool taking: 37.187.150.174 Jan 28 13:25:12 volumio-manu ntpd[850]: DNS: Pool skipping: 82.64.45.50 Jan 28 13:25:12 volumio-manu ntpd[850]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Jan 28 13:25:13 volumio-manu sudo[1187]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:13 volumio-manu wireless.js[701]: WIRELESS.JS - INFO: SETTING APPROPRIATE REG DOMAIN: FR Jan 28 13:25:13 volumio-manu sudo[1198]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set FR Jan 28 13:25:13 volumio-manu sudo[1198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:13 volumio-manu sudo[1198]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:13 volumio-manu wireless.js[701]: WIRELESS.JS - INFO: SUCCESSFULLY SET NEW REGDOMAIN: FR Jan 28 13:25:13 volumio-manu wireless.js[701]: WIRELESS.JS - INFO: Single Network Mode: Ethernet active, maintaining WiFi scan capability Jan 28 13:25:13 volumio-manu wireless.js[701]: WIRELESS.JS - INFO: SNM: Maintaining wlan0 UP without IP (scan mode) Jan 28 13:25:13 volumio-manu wireless.js[701]: WIRELESS.JS - INFO: SNM: Users can configure WiFi via WebUI while ethernet is active Jan 28 13:25:13 volumio-manu sudo[1207]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Jan 28 13:25:13 volumio-manu sudo[1207]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 13:25:13 volumio-manu sudo[1207]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:13 volumio-manu sudo[1210]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jan 28 13:25:13 volumio-manu sudo[1210]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 13:25:13 volumio-manu sudo[1210]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:13 volumio-manu wpa_supplicant[1213]: Successfully initialized wpa_supplicant Jan 28 13:25:14 volumio-manu wpa_supplicant[1213]: nl80211: kernel reports: Registration to specific type not supported Jan 28 13:25:14 volumio-manu wpa_supplicant[1216]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all Jan 28 13:25:14 volumio-manu wireless.js[701]: WIRELESS.JS - INFO: SNM: Transition to scan mode completed in 229028115ms Jan 28 13:25:14 volumio-manu wireless.js[701]: WIRELESS.JS - INFO: SNM: wlan0 is UP without IP, scan capable Jan 28 13:25:14 volumio-manu wireless.js[701]: WIRELESS.JS - INFO: Notified systemd about wireless ready Jan 28 13:25:14 volumio-manu kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jan 28 13:25:14 volumio-manu systemd[1]: Started wireless.service - Wireless Services. Jan 28 13:25:14 volumio-manu systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 13:25:14 volumio-manu systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... Jan 28 13:25:14 volumio-manu systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker. Jan 28 13:25:14 volumio-manu systemd[1]: Received SIGRTMIN+21 from PID 289 (plymouthd). Jan 28 13:25:14 volumio-manu systemd[1]: Received SIGRTMIN+21 from PID 289 (plymouthd). Jan 28 13:25:14 volumio-manu systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. Jan 28 13:25:14 volumio-manu systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. Jan 28 13:25:14 volumio-manu systemd[1]: Started getty@tty1.service - Getty on tty1. Jan 28 13:25:14 volumio-manu systemd[1]: Reached target getty.target - Login Prompts. Jan 28 13:25:14 volumio-manu systemd[1]: Reached target multi-user.target - Multi-User System. Jan 28 13:25:14 volumio-manu systemd[1]: Reached target graphical.target - Graphical Interface. Jan 28 13:25:14 volumio-manu volumio-cpu-tweak[1237]: Setting RT Priority for mpd Jan 28 13:25:14 volumio-manu volumio-cpu-tweak[1252]: pid 35's current scheduling policy: SCHED_OTHER Jan 28 13:25:14 volumio-manu volumio-cpu-tweak[1252]: pid 35's current scheduling priority: 0 Jan 28 13:25:14 volumio-manu volumio-cpu-tweak[1237]: Setting MPD Affinity Jan 28 13:25:14 volumio-manu volumio-cpu-tweak[1253]: pid 3's current affinity mask: f Jan 28 13:25:14 volumio-manu systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Jan 28 13:25:14 volumio-manu volumio-cpu-tweak[1237]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Jan 28 13:25:14 volumio-manu volumio-cpu-tweak[1237]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Jan 28 13:25:14 volumio-manu systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Jan 28 13:25:14 volumio-manu systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Jan 28 13:25:14 volumio-manu systemd[1]: Startup finished in 15.282s (kernel) + 16.747s (userspace) = 32.029s. Jan 28 13:25:14 volumio-manu systemd[1]: volumio_cpu_tweak.service: Deactivated successfully. Jan 28 13:25:16 volumio-manu volumio-remote-updater[699]: [2026-01-28 13:25:16] [info] asio async_connect error: asio.system:111 (Connection refused) Jan 28 13:25:16 volumio-manu volumio-remote-updater[699]: [2026-01-28 13:25:16] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Jan 28 13:25:16 volumio-manu volumio-remote-updater[699]: [2026-01-28 13:25:16] [error] handle_connect error: Connection refused Jan 28 13:25:17 volumio-manu ntpd[850]: CLOCK: time stepped by 0.585758 Jan 28 13:25:17 volumio-manu ntpd[850]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Jan 28 13:25:19 volumio-manu volumio[1235]: info: ------------------------------------------- Jan 28 13:25:19 volumio-manu volumio[1235]: info: ----- Volumio3 ---- Jan 28 13:25:19 volumio-manu volumio[1235]: info: ------------------------------------------- Jan 28 13:25:19 volumio-manu volumio[1235]: info: ----- System startup ---- Jan 28 13:25:19 volumio-manu volumio[1235]: info: ------------------------------------------- Jan 28 13:25:19 volumio-manu systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Jan 28 13:25:19 volumio-manu systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 28 13:25:19 volumio-manu systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 28 13:25:19 volumio-manu upmpdcli[1264]: Could not open config: /tmp/upmpdcli.conf Jan 28 13:25:19 volumio-manu systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:25:19 volumio-manu systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 28 13:25:20 volumio-manu volumio[1235]: info: MYVOLUMIO Environment detected Jan 28 13:25:20 volumio-manu volumio[1235]: info: Plugin folders cleanup Jan 28 13:25:20 volumio-manu volumio[1235]: info: Scanning into folder /volumio/app/plugins/ Jan 28 13:25:20 volumio-manu volumio[1235]: info: Scanning category audio_interface Jan 28 13:25:20 volumio-manu volumio[1235]: info: Scanning category miscellanea Jan 28 13:25:20 volumio-manu volumio[1235]: info: Scanning category music_service Jan 28 13:25:20 volumio-manu volumio[1235]: info: Scanning category plugins.json Jan 28 13:25:20 volumio-manu volumio[1235]: info: Scanning category system_controller Jan 28 13:25:20 volumio-manu volumio[1235]: info: Scanning category user_interface Jan 28 13:25:20 volumio-manu volumio[1235]: info: Scanning into folder /data/plugins/ Jan 28 13:25:20 volumio-manu volumio[1235]: info: Scanning category music_service Jan 28 13:25:20 volumio-manu volumio[1235]: info: Scanning category system_controller Jan 28 13:25:20 volumio-manu volumio[1235]: info: Scanning category system_hardware Jan 28 13:25:20 volumio-manu volumio[1235]: info: Plugin folders cleanup completed Jan 28 13:25:20 volumio-manu volumio[1235]: info: ------------------------------------------- Jan 28 13:25:20 volumio-manu volumio[1235]: info: ----- Core plugins startup ---- Jan 28 13:25:20 volumio-manu volumio[1235]: info: ------------------------------------------- Jan 28 13:25:20 volumio-manu volumio[1235]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 13:25:20 volumio-manu volumio[1235]: info: Adding plugin upnp to MyMusic Plugins Jan 28 13:25:20 volumio-manu volumio[1235]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 13:25:20 volumio-manu volumio[1235]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 13:25:20 volumio-manu volumio[1235]: info: Loading plugins from folder /data/plugins/ Jan 28 13:25:20 volumio-manu volumio[1235]: info: Loading plugin "system"... Jan 28 13:25:20 volumio-manu volumio[1235]: info: Loading plugin "appearance"... Jan 28 13:25:22 volumio-manu volumio[1235]: info: Loading plugin "network"... Jan 28 13:25:22 volumio-manu volumio[1235]: info: Refreshing Cached IP Addresses Jan 28 13:25:22 volumio-manu volumio[1235]: info: Loading plugin "services"... Jan 28 13:25:22 volumio-manu volumio[1235]: info: Loading plugin "alsa_controller"... Jan 28 13:25:23 volumio-manu sudo[1274]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 13:25:23 volumio-manu sudo[1274]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:23 volumio-manu sudo[1273]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 13:25:23 volumio-manu sudo[1273]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:23 volumio-manu sudo[1274]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:23 volumio-manu sudo[1273]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:23 volumio-manu sudo[1285]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 13:25:23 volumio-manu sudo[1285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:23 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 13:25:23 volumio-manu volumio[1235]: info: Loading plugin "wizard"... Jan 28 13:25:23 volumio-manu volumio[1235]: info: Loading plugin "networkfs"... Jan 28 13:25:23 volumio-manu volumio[1235]: info: Starting Udev Watcher for removable devices Jan 28 13:25:23 volumio-manu volumio[1235]: info: Ignoring mount for partition: boot Jan 28 13:25:23 volumio-manu volumio[1235]: info: Ignoring mount for partition: volumio Jan 28 13:25:23 volumio-manu volumio[1235]: info: Ignoring mount for partition: volumio_data Jan 28 13:25:23 volumio-manu sudo[1306]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Administrateur,password=Motdepasse,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //iMac-de-Emmanuel.local/AUDIO /mnt/NAS/AUDIO Jan 28 13:25:23 volumio-manu sudo[1306]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:23 volumio-manu volumio[1235]: info: Mounting Device EFI Jan 28 13:25:23 volumio-manu sudo[1316]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/EFI -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 28 13:25:23 volumio-manu sudo[1316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:23 volumio-manu kernel: FAT-fs (sda1): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! Jan 28 13:25:23 volumio-manu kernel: FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Jan 28 13:25:23 volumio-manu sudo[1316]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:23 volumio-manu volumio[1235]: info: Mounting Device UNTITLED Jan 28 13:25:23 volumio-manu sudo[1327]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda2 /mnt/USB/UNTITLED -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 28 13:25:23 volumio-manu kernel: netfs: FS-Cache loaded Jan 28 13:25:23 volumio-manu sudo[1327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:23 volumio-manu kernel: FAT-fs (sda2): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! Jan 28 13:25:23 volumio-manu kernel: FAT-fs (sda2): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Jan 28 13:25:23 volumio-manu kernel: Key type cifs.spnego registered Jan 28 13:25:23 volumio-manu kernel: Key type cifs.idmap registered Jan 28 13:25:23 volumio-manu 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. Jan 28 13:25:23 volumio-manu kernel: CIFS: Attempting to mount //iMac-de-Emmanuel.local/AUDIO Jan 28 13:25:23 volumio-manu sudo[1327]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:23 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 13:25:23 volumio-manu volumio[1235]: info: Loading plugin "volumio_command_line_client"... Jan 28 13:25:23 volumio-manu volumio[1235]: info: Loading plugin "upnp"... Jan 28 13:25:23 volumio-manu volumio[1235]: info: [1769603123853] Starting Upmpd Daemon Jan 28 13:25:23 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 13:25:23 volumio-manu volumio[1235]: info: Loading plugin "my_music"... Jan 28 13:25:23 volumio-manu volumio[1235]: info: Loading plugin "mpd"... Jan 28 13:25:24 volumio-manu sudo[1306]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:24 volumio-manu volumio[1235]: info: Loading plugin "upnp_browser"... Jan 28 13:25:25 volumio-manu sudo[1285]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:26 volumio-manu volumio-remote-updater[699]: [2026-01-28 13:25:26] [connect] Successful connection Jan 28 13:25:26 volumio-manu volumio[1235]: info: Starting UPNP Browser Jan 28 13:25:26 volumio-manu volumio[1235]: info: Loading plugin "alarm-clock"... Jan 28 13:25:27 volumio-manu volumio[1235]: info: Loading plugin "airplay_emulation"... Jan 28 13:25:27 volumio-manu volumio[1235]: info: Starting Shairport Sync Jan 28 13:25:27 volumio-manu volumio[1235]: info: Loading plugin "last_100"... Jan 28 13:25:27 volumio-manu volumio[1235]: info: Loading plugin "webradio"... Jan 28 13:25:27 volumio-manu volumio[1235]: info: Loading plugin "i2s_dacs"... Jan 28 13:25:27 volumio-manu volumio[1235]: info: Loading plugin "volumiodiscovery"... Jan 28 13:25:27 volumio-manu volumio[1235]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 13:25:27 volumio-manu volumio[1235]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 13:25:27 volumio-manu volumio[1235]: *** WARNING *** For more information see Jan 28 13:25:27 volumio-manu volumio[1235]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 13:25:27 volumio-manu volumio[1235]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 13:25:27 volumio-manu volumio[1235]: *** WARNING *** For more information see Jan 28 13:25:27 volumio-manu node[1235]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 13:25:27 volumio-manu node[1235]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 13:25:27 volumio-manu node[1235]: *** WARNING *** For more information see Jan 28 13:25:27 volumio-manu node[1235]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 13:25:27 volumio-manu node[1235]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 13:25:27 volumio-manu node[1235]: *** WARNING *** For more information see Jan 28 13:25:27 volumio-manu volumio[1235]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 13:25:27 volumio-manu volumio[1235]: info: Discovery: Started advertising with name: Volumio Manu Jan 28 13:25:27 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 13:25:27 volumio-manu volumio[1235]: info: Loading plugin "spop"... Jan 28 13:25:30 volumio-manu volumio[1235]: info: Loading plugin "outputs"... Jan 28 13:25:30 volumio-manu volumio[1235]: info: Loading plugin "albumart"... Jan 28 13:25:30 volumio-manu volumio[1235]: info: Plugin example_plugin is not enabled Jan 28 13:25:30 volumio-manu volumio[1235]: info: Loading plugin "inputs"... Jan 28 13:25:30 volumio-manu volumio[1235]: info: Loading plugin "updater_comm"... Jan 28 13:25:31 volumio-manu volumio[1235]: info: Plugin mpdemulation is not enabled Jan 28 13:25:31 volumio-manu volumio[1235]: info: Loading plugin "rest_api"... Jan 28 13:25:31 volumio-manu volumio[1235]: info: Loading plugin "websocket"... Jan 28 13:25:31 volumio-manu volumio[1235]: info: Starting Socket.io Server version 1.7.4 Jan 28 13:25:31 volumio-manu volumio[1235]: info: Loading plugin "podcast"... Jan 28 13:25:31 volumio-manu systemd[1]: systemd-fsckd.service: Deactivated successfully. Jan 28 13:25:31 volumio-manu volumio[1235]: info: ControllerPodcast::constructor Jan 28 13:25:32 volumio-manu volumio[1362]: Forking 3 albumart workers Jan 28 13:25:32 volumio-manu volumio[1235]: info: Loading plugin "backup_restore"... Jan 28 13:25:34 volumio-manu systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Jan 28 13:25:34 volumio-manu systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 28 13:25:34 volumio-manu systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 28 13:25:34 volumio-manu upmpdcli[1416]: Could not open config: /tmp/upmpdcli.conf Jan 28 13:25:34 volumio-manu systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:25:34 volumio-manu systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 28 13:25:35 volumio-manu volumio[1235]: info: Applying required configuration parameters for plugin backup_restore Jan 28 13:25:35 volumio-manu volumio[1235]: info: Loading plugin "audiophonicsonoff"... Jan 28 13:25:36 volumio-manu systemd[1]: systemd-hostnamed.service: Deactivated successfully. Jan 28 13:25:37 volumio-manu volumio[1235]: info: Applying required configuration parameters for plugin audiophonicsonoff Jan 28 13:25:37 volumio-manu volumio[1235]: info: Audiophonics on/off initiated Jan 28 13:25:37 volumio-manu volumio[1235]: info: Loading i18n strings for locale fr Jan 28 13:25:37 volumio-manu volumio[1235]: Updating browse sources language Jan 28 13:25:37 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:25:38 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 13:25:38 volumio-manu volumio[1235]: info: CoreCommandRouter::initPlayerControls Jan 28 13:25:38 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:38 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:38 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:38 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:38 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:38 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:38 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:38 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:39 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 13:25:39 volumio-manu volumio[1235]: Express server listening on port 3000 Jan 28 13:25:39 volumio-manu volumio[1235]: [Metrics] WebUI: 20s 961.33ms Jan 28 13:25:39 volumio-manu volumio[1235]: info: CoreStateMachine::resetVolumioState Jan 28 13:25:39 volumio-manu volumio[1235]: info: CoreStateMachine::getcurrentVolume Jan 28 13:25:39 volumio-manu volumio[1235]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 13:25:39 volumio-manu sudo[1426]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 13:25:39 volumio-manu sudo[1426]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:39 volumio-manu sudo[1428]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 13:25:39 volumio-manu sudo[1428]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:39 volumio-manu sudo[1426]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:39 volumio-manu sudo[1428]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:39 volumio-manu volumio[1235]: info: Volumio Network Manager: Network status updated: 1 Jan 28 13:25:40 volumio-manu volumio[1235]: info: VolumeController:: Volume=100 Mute =false Jan 28 13:25:40 volumio-manu volumio[1235]: info: CoreStateMachine::pushState Jan 28 13:25:40 volumio-manu volumio[1235]: info: CorePlayQueue::getTrack 0 Jan 28 13:25:40 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 13:25:40 volumio-manu volumio[1235]: info: CoreCommandRouter::volumioPushState Jan 28 13:25:40 volumio-manu volumio[1235]: info: CoreStateMachine::updateTrackBlock Jan 28 13:25:40 volumio-manu volumio[1235]: info: CorePlayQueue::getTrackBlock Jan 28 13:25:40 volumio-manu volumio[1235]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 13:25:41 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:25:41 volumio-manu volumio[1235]: info: Reloading queue from file Jan 28 13:25:41 volumio-manu volumio[1235]: info: CoreStateMachine::setRepeat false single undefined Jan 28 13:25:41 volumio-manu volumio[1235]: info: CoreStateMachine::pushState Jan 28 13:25:41 volumio-manu volumio[1235]: info: CorePlayQueue::getTrack 0 Jan 28 13:25:41 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 13:25:41 volumio-manu volumio[1235]: info: CoreCommandRouter::volumioPushState Jan 28 13:25:41 volumio-manu volumio[1235]: info: CoreStateMachine::setRandom undefined Jan 28 13:25:41 volumio-manu volumio[1235]: info: CoreStateMachine::pushState Jan 28 13:25:41 volumio-manu volumio[1235]: info: CorePlayQueue::getTrack 0 Jan 28 13:25:41 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 13:25:41 volumio-manu volumio[1235]: info: CoreCommandRouter::volumioPushState Jan 28 13:25:41 volumio-manu volumio[1235]: info: Setting Device type: Raspberry PI Jan 28 13:25:41 volumio-manu volumio[1235]: info: Completed loading Core Plugins Jan 28 13:25:41 volumio-manu volumio[1373]: Starting albumart workers Jan 28 13:25:41 volumio-manu volumio[1235]: info: Preparing to generate the ALSA configuration file Jan 28 13:25:41 volumio-manu volumio[1372]: Starting albumart workers Jan 28 13:25:41 volumio-manu volumio-remote-updater[699]: [2026-01-28 13:25:41] [connect] Successful connection Jan 28 13:25:41 volumio-manu volumio[1235]: info: VolumeController:: Volume=100 Mute =false Jan 28 13:25:41 volumio-manu volumio[1235]: info: CoreStateMachine::pushState Jan 28 13:25:41 volumio-manu volumio[1235]: info: CorePlayQueue::getTrack 0 Jan 28 13:25:41 volumio-manu volumio[1235]: info: CoreCommandRouter::volumioPushState Jan 28 13:25:41 volumio-manu volumio[1374]: Starting albumart workers Jan 28 13:25:41 volumio-manu volumio-remote-updater[699]: [2026-01-28 13:25:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769603141 101 Jan 28 13:25:41 volumio-manu sudo[1445]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 13:25:41 volumio-manu sudo[1445]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:42 volumio-manu volumio[1235]: 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: 1 Jan 28 13:25:42 volumio-manu volumio[1235]: info: Discovery: adding 2d4b54dd-672c-4b28-8353-fe66b43ecafd Jan 28 13:25:42 volumio-manu volumio[1235]: info: Discovery: Found device Volumio Manu Jan 28 13:25:42 volumio-manu volumio[1235]: info: CoreCommandRouter::volumioGetState Jan 28 13:25:42 volumio-manu volumio[1235]: info: CorePlayQueue::getTrack 0 Jan 28 13:25:42 volumio-manu volumio[1235]: info: Discovery: this is already registered, 2d4b54dd-672c-4b28-8353-fe66b43ecafd Jan 28 13:25:42 volumio-manu volumio[1235]: info: Discovery: Found device Volumio Manu Jan 28 13:25:42 volumio-manu volumio[1235]: info: CoreCommandRouter::volumioGetState Jan 28 13:25:42 volumio-manu volumio[1235]: info: CorePlayQueue::getTrack 0 Jan 28 13:25:42 volumio-manu volumio[1235]: info: Asound.conf file unchanged, so no further update is needed Jan 28 13:25:42 volumio-manu volumio[1235]: info: Output device has changed, restarting MPD Jan 28 13:25:42 volumio-manu volumio[1235]: info: Output device has changed, restarting Shairport Sync Jan 28 13:25:42 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:42 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:25:42 volumio-manu sudo[1448]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 13:25:42 volumio-manu sudo[1448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:42 volumio-manu sudo[1450]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 13:25:42 volumio-manu sudo[1448]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:42 volumio-manu sudo[1450]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:42 volumio-manu volumio[1235]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 13:25:42 volumio-manu volumio[1235]: info: ___________ START PLUGINS ___________ Jan 28 13:25:42 volumio-manu volumio[1235]: info: ControllerMpd::onStart: Initializing MPD Jan 28 13:25:42 volumio-manu volumio[1235]: info: Creating MPD Configuration file Jan 28 13:25:42 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 13:25:42 volumio-manu volumio[1235]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:25:42 volumio-manu volumio[1235]: info: [1769603142788] CoreMusicLibrary::Adding element Serveurs Média Jan 28 13:25:42 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:25:42 volumio-manu sudo[1458]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 13:25:42 volumio-manu sudo[1458]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:42 volumio-manu systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 13:25:42 volumio-manu systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 13:25:42 volumio-manu sudo[1458]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:42 volumio-manu volumio[1235]: info: UPNP Browser: Client initialized successfully Jan 28 13:25:43 volumio-manu sudo[1463]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 13:25:43 volumio-manu sudo[1463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 13:25:43 volumio-manu sudo[1461]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 13:25:43 volumio-manu sudo[1461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:43 volumio-manu sudo[1464]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jan 28 13:25:43 volumio-manu sudo[1463]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:43 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:43 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:25:43 volumio-manu systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Jan 28 13:25:43 volumio-manu volumio[1235]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 13:25:43 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:43 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:25:43 volumio-manu systemd[1]: mpd.service: Deactivated successfully. Jan 28 13:25:43 volumio-manu systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 13:25:43 volumio-manu systemd[1]: mpd.socket: Deactivated successfully. Jan 28 13:25:43 volumio-manu systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 13:25:43 volumio-manu systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 13:25:43 volumio-manu systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 13:25:43 volumio-manu systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 13:25:43 volumio-manu volumio[1235]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 13:25:43 volumio-manu volumio[1235]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:25:43 volumio-manu volumio[1235]: info: [1769603143671] CoreMusicLibrary::Adding element Last_100 Jan 28 13:25:43 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:25:43 volumio-manu volumio[1235]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:25:43 volumio-manu volumio[1235]: info: [1769603143675] CoreMusicLibrary::Adding element Webradio Jan 28 13:25:43 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:25:43 volumio-manu sudo[1497]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 13:25:43 volumio-manu sudo[1497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 13:25:43 volumio-manu sudo[1506]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jan 28 13:25:43 volumio-manu sudo[1497]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:43 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 13:25:44 volumio-manu volumio[1235]: info: Initializing BBC Radios Jan 28 13:25:44 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 13:25:44 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:25:44 volumio-manu volumio[1235]: info: Creating Spotify config file Jan 28 13:25:44 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:44 volumio-manu systemd[1]: setdatetime-helper.service: Deactivated successfully. Jan 28 13:25:44 volumio-manu systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Jan 28 13:25:47 volumio-manu volumio[1235]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:25:47 volumio-manu volumio[1235]: info: [1769603147360] CoreMusicLibrary::Adding element Podcast Jan 28 13:25:47 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:25:47 volumio-manu volumio[1235]: Cannot find translation for source Podcast Jan 28 13:25:47 volumio-manu volumio[1235]: info: Configuring GPIO pins Jan 28 13:25:47 volumio-manu volumio[1235]: info: Soft shutdown GPIO 516 binding... OK Jan 28 13:25:47 volumio-manu volumio[1235]: info: Hardware button GPIO 529 binding... OK Jan 28 13:25:47 volumio-manu volumio[1235]: info: Boot OK GPIO 534 binding... OK Jan 28 13:25:47 volumio-manu volumio[1235]: info: Volumio Calling Home Jan 28 13:25:49 volumio-manu systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Jan 28 13:25:49 volumio-manu systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 28 13:25:50 volumio-manu systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 28 13:25:50 volumio-manu sudo[1445]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:50 volumio-manu volumio[1235]: info: MPD Permissions set Jan 28 13:25:50 volumio-manu volumio[1235]: info: MPD Permissions set Jan 28 13:25:50 volumio-manu volumio[1235]: info: Upmpdcli Daemon Started Jan 28 13:25:50 volumio-manu volumio[1235]: info: Spotify config file written Jan 28 13:25:50 volumio-manu sudo[1594]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 13:25:50 volumio-manu sudo[1594]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:50 volumio-manu 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. Jan 28 13:25:50 volumio-manu 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. Jan 28 13:25:50 volumio-manu systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:25:50 volumio-manu go-librespot[1596]: go-librespot daemon starting... Jan 28 13:25:50 volumio-manu sudo[1594]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:51 volumio-manu mpd[1507]: 2026-01-28T13:25:51 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 13:25:51 volumio-manu volumio[1235]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 13:25:51 volumio-manu systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 13:25:51 volumio-manu sudo[1450]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:51 volumio-manu sudo[1461]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:51 volumio-manu volumio[1235]: info: Volumio called home Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:25:51 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:51+01:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:25:51 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:51+01:00" level=debug msg="app state loaded" Jan 28 13:25:51 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:51+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:25:51 volumio-manu volumio[1235]: info: No need to fix Spotify hosts Jan 28 13:25:51 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:51+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 13:25:51 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:51+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 13:25:51 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:51+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 13:25:51 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:51+01:00" level=info msg="zeroconf server listening on port 33607" Jan 28 13:25:51 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:51+01:00" level=debug msg="obtained new client token: AAAN6OGvw06a9VlncJGD7tiyR5DOv5y1Iih2366VMITcTlXrM7IcNmc9zRYlgX+UlChUgvWUxqJW4Jcwwc2zoPCB2CF4wdy1GVC9qCA7dveKWrHAy+W0D59G2wgQHl3y8ge1Wrg/PLSkzvm2896kwlv6ruGMRrrv+5UuYjbiVVk/ZVpeI6KqMAm2X0i0vHOkdksV8xfVz0HlxZdx56f9cZHsmg10E4AOfJZR3F8zRzirplTBp9IQNrsC" Jan 28 13:25:52 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:52+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 28 13:25:52 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:52+01:00" level=debug msg="completed keyexchange" Jan 28 13:25:52 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:52+01:00" level=debug msg="completed challenge" Jan 28 13:25:52 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:52+01:00" level=info msg="authenticated AP" username="31************************my" Jan 28 13:25:52 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:52+01:00" level=info msg="authenticated Login5" username="31************************my" Jan 28 13:25:52 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:52+01:00" level=debug msg="initializing zeroconf session" username="31************************my" Jan 28 13:25:52 volumio-manu volumio[1235]: info: Completed starting Core Plugins Jan 28 13:25:52 volumio-manu volumio[1235]: info: ------------------------------------------- Jan 28 13:25:52 volumio-manu volumio[1235]: info: ----- MyVolumio plugins startup ---- Jan 28 13:25:52 volumio-manu volumio[1235]: info: ------------------------------------------- Jan 28 13:25:52 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 13:25:52 volumio-manu volumio[1235]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 13:25:52 volumio-manu volumio[1235]: SPOTIFY: BQBSyqOKg0hU_2a_98T0P8a5GwlVKtCQ4BDSq5h95OzyXRvIVkv7Lu_QZ-_c4FTIfQyaxoBATVwYs9bjYPV9XSkhZoy4aOeUdwN_TL2QVGJCzSwHqAXUH74MgCWrzLSwGIKKsA73icVSQOnvtmKaLFoEvIWZRmcSZ85hhejk6rN6lGqIqWMwKAItxMLHdETnje9dm96dBcNIiag2F0F3-IkS-TY5CBaP6VxrT3iK1g2mqDMN55eFLkzKwvnln_uHcQN1sZppxefezspqLLikB9qNTyycgPksXdan-f3fj9SkKZpYdLKHDTxi-LnC Jan 28 13:25:52 volumio-manu volumio[1235]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 13:25:52 volumio-manu volumio[1235]: info: New Spotify access token = BQBSyqOKg0hU_2a_98T0P8a5GwlVKtCQ4BDSq5h95OzyXRvIVkv7Lu_QZ-_c4FTIfQyaxoBATVwYs9bjYPV9XSkhZoy4aOeUdwN_TL2QVGJCzSwHqAXUH74MgCWrzLSwGIKKsA73icVSQOnvtmKaLFoEvIWZRmcSZ85hhejk6rN6lGqIqWMwKAItxMLHdETnje9dm96dBcNIiag2F0F3-IkS-TY5CBaP6VxrT3iK1g2mqDMN55eFLkzKwvnln_uHcQN1sZppxefezspqLLikB9qNTyycgPksXdan-f3fj9SkKZpYdLKHDTxi-LnC Jan 28 13:25:52 volumio-manu volumio[1235]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 13:25:53 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:53+01:00" level=debug msg="dealer connection opened" Jan 28 13:25:53 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:53+01:00" level=trace msg="starting accesspoint recv loop" Jan 28 13:25:53 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:53+01:00" level=trace msg="starting dealer recv loop" Jan 28 13:25:53 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:53+01:00" level=trace msg="received accesspoint ping" Jan 28 13:25:53 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:53+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 28 13:25:53 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:53+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 28 13:25:53 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:53+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 28 13:25:53 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:53+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 28 13:25:53 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:53+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 28 13:25:53 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:53+01:00" level=debug msg="received connection id: N2Q5OGFjMjgtNTVk...QTE5RkM4QkVFRA==" Jan 28 13:25:53 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:53+01:00" level=trace msg="received accesspoint pong ack" Jan 28 13:25:53 volumio-manu volumio[1235]: error: MPD error: The expression evaluated to a falsy value: Jan 28 13:25:53 volumio-manu volumio[1235]: assert.ok(self.idling) Jan 28 13:25:53 volumio-manu volumio[1235]: error: The expression evaluated to a falsy value: Jan 28 13:25:53 volumio-manu volumio[1235]: assert.ok(self.idling) Jan 28 13:25:53 volumio-manu volumio[1235]: info: MPD running with PID1507 Jan 28 13:25:53 volumio-manu volumio[1235]: ,establishing connection Jan 28 13:25:53 volumio-manu volumio[1235]: info: Starting Shairport Sync Jan 28 13:25:53 volumio-manu go-librespot[1597]: time="2026-01-28T13:25:53+01:00" level=debug msg="put connect state because NEW_DEVICE" Jan 28 13:25:53 volumio-manu volumio[1235]: info: Starting Shairport Sync Jan 28 13:25:53 volumio-manu volumio[1235]: info: Starting Shairport Sync Jan 28 13:25:53 volumio-manu volumio[1235]: error: updateQueue error: null Jan 28 13:25:53 volumio-manu sudo[1621]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 13:25:53 volumio-manu sudo[1621]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:53 volumio-manu sudo[1623]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 13:25:53 volumio-manu sudo[1623]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:53 volumio-manu sudo[1625]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 13:25:53 volumio-manu sudo[1625]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:25:53 volumio-manu systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 13:25:53 volumio-manu systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 13:25:53 volumio-manu systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 13:25:53 volumio-manu systemd[1]: shairport-sync.service: Consumed 1.921s CPU time. Jan 28 13:25:53 volumio-manu volumio[1235]: error: updateQueue error: null Jan 28 13:25:53 volumio-manu systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 13:25:53 volumio-manu sudo[1621]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:53 volumio-manu systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 13:25:53 volumio-manu systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 13:25:53 volumio-manu sudo[1623]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:53 volumio-manu systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 13:25:53 volumio-manu systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 13:25:53 volumio-manu sudo[1625]: pam_unix(sudo:session): session closed for user root Jan 28 13:25:54 volumio-manu volumio[1235]: info: Shairport-Sync Started Jan 28 13:25:54 volumio-manu volumio[1235]: Error adding Membership: Error: addMembership EINVAL Jan 28 13:25:54 volumio-manu volumio[1235]: info: Shairport-Sync Started Jan 28 13:25:54 volumio-manu volumio[1235]: info: Shairport-Sync Started Jan 28 13:25:54 volumio-manu volumio[1235]: info: CoreCommandRouter::volumioGetState Jan 28 13:25:54 volumio-manu volumio[1235]: info: CorePlayQueue::getTrack 0 Jan 28 13:25:54 volumio-manu volumio[1235]: SPOTIFY: User informations: {"country":"FR","display_name":"Théoazerty","email":"rollinmanu@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31gszsn5p2sazmn7axnxuuzuswmy"},"followers":{"href":null,"total":2},"href":"https://api.spotify.com/v1/users/31gszsn5p2sazmn7axnxuuzuswmy","id":"31gszsn5p2sazmn7axnxuuzuswmy","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85ffac796090e7264258a23179","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82ffac796090e7264258a23179","width":64}],"product":"premium","type":"user","uri":"spotify:user:31gszsn5p2sazmn7axnxuuzuswmy"} Jan 28 13:25:54 volumio-manu volumio[1235]: info: Spotify Successfully logged in Jan 28 13:25:54 volumio-manu volumio[1235]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:25:54 volumio-manu volumio[1235]: info: [1769603154918] CoreMusicLibrary::Adding element Spotify Jan 28 13:25:54 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:25:54 volumio-manu volumio[1235]: Cannot find translation for source Podcast Jan 28 13:25:54 volumio-manu volumio[1235]: Cannot find translation for source Spotify Jan 28 13:25:55 volumio-manu volumio[1235]: info: go-librespot daemon successfully initialized Jan 28 13:26:00 volumio-manu volumio[1235]: info: Initializing connection to go-librespot Websocket Jan 28 13:26:04 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:04+01:00" level=debug msg="new websocket client" Jan 28 13:26:04 volumio-manu volumio[1235]: info: Connection to go-librespot Websocket established Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 13:26:05 volumio-manu volumio[1235]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 13:26:05 volumio-manu volumio[1235]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 13:26:05 volumio-manu volumio[1235]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 13:26:05 volumio-manu volumio[1235]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 13:26:05 volumio-manu volumio[1235]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 13:26:05 volumio-manu volumio[1235]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 13:26:05 volumio-manu volumio[1235]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 13:26:05 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 13:26:14 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 13:26:14 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 13:26:14 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:26:14 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:26:14 volumio-manu volumio[1235]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 13:26:14 volumio-manu volumio[1235]: info: MyVolumio login type: Token Jan 28 13:26:14 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 13:26:14 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="handling transfer player command from 6207a6844bdc5f84ad7c2576e88dfae524bb7672" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="resolved context of track" uri="spotify:album:73CuswFpjJR0oISufRQZL2" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:album:73CuswFpjJR0oISufRQZL2" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="loading track (paused: true, position: 11110ms)" uri="spotify:track:6LChsTTDPShYFbzngKMSWK" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=trace msg="emitting websocket event: will_play" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="selected format OGG_VORBIS_320 (44554ca328d2131d2cbc0d9a4793040664fa5965)" uri="spotify:track:6LChsTTDPShYFbzngKMSWK" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="requested aes key for file 44554ca328d2131d2cbc0d9a4793040664fa5965, gid: 6LChsTTDPShYFbzngKMSWK" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1711" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:6LChsTTDPShYFbzngKMSWK" Jan 28 13:26:19 volumio-manu upmpdcli[1693]: writing RSA key Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="fetched first chunk of 16, total size is 7988575 bytes" uri="spotify:track:6LChsTTDPShYFbzngKMSWK" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=trace msg="seek to 11110ms (diff: 139ms, samples: 489951, bytes: 444507)" uri="spotify:track:6LChsTTDPShYFbzngKMSWK" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="created new output device" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=info msg="loaded track \"TU ME RENDS BÊTE\" (paused: true, position: 11110ms, duration: 165714ms, prefetched: false)" uri="spotify:track:6LChsTTDPShYFbzngKMSWK" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1302" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:6LChsTTDPShYFbzngKMSWK" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=trace msg="emitting websocket event: metadata" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=trace msg="emitting websocket event: active" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="sending successful reply for dealer request" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=trace msg="emitting websocket event: paused" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:6LChsTTDPShYFbzngKMSWK" Jan 28 13:26:19 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:19+01:00" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:6LChsTTDPShYFbzngKMSWK" Jan 28 13:26:20 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:20+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 159" Jan 28 13:26:20 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:20+01:00" level=debug msg="skipping dealer message" uri=playback-settings/content-settings-update Jan 28 13:26:20 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:20+01:00" level=debug msg="handling update_context player command from 6207a6844bdc5f84ad7c2576e88dfae524bb7672" Jan 28 13:26:21 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:21+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 28 13:26:21 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:21+01:00" level=debug msg="sending successful reply for dealer request" Jan 28 13:26:22 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 13:26:22 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 13:26:22 volumio-manu volumio[1235]: info: Streaming services startup Jan 28 13:26:22 volumio-manu volumio[1235]: info: Starting Streaming Daemon Jan 28 13:26:22 volumio-manu volumio[1235]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 13:26:22 volumio-manu sudo[1703]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 13:26:22 volumio-manu sudo[1703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:26:22 volumio-manu sudo[1703]: pam_unix(sudo:session): session closed for user root Jan 28 13:26:22 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 13:26:22 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:26:22 volumio-manu volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 28 13:26:22 volumio-manu volumio[1235]: info: Getting Spotify volume Jan 28 13:26:22 volumio-manu volumio[1235]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:album:73CuswFpjJR0oISufRQZL2","uri":"spotify:track:6LChsTTDPShYFbzngKMSWK","play_origin":"album"}} Jan 28 13:26:22 volumio-manu volumio[1235]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6LChsTTDPShYFbzngKMSWK","name":"TU ME RENDS BÊTE","artist_names":["GIMS","Damso"],"album_name":"TU ME RENDS BÊTE","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0255842bfbfe259ebedac5f193","position":11110,"duration":165714,"release_date":"year:2025 month:8 day:15","track_number":1,"disc_number":1}} Jan 28 13:26:22 volumio-manu volumio[1235]: SPOTIFY: received: {"type":"active","data":null} Jan 28 13:26:22 volumio-manu volumio[1235]: info: Aligning Spotify Volume to Volumio Volume Jan 28 13:26:22 volumio-manu volumio[1235]: info: CoreCommandRouter::volumioGetState Jan 28 13:26:22 volumio-manu volumio[1235]: info: CorePlayQueue::getTrack 0 Jan 28 13:26:22 volumio-manu volumio[1235]: info: Setting Spotify Volume from Volumio: 100 Jan 28 13:26:22 volumio-manu volumio[1235]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:album:73CuswFpjJR0oISufRQZL2","uri":"spotify:track:6LChsTTDPShYFbzngKMSWK","play_origin":"album"}} Jan 28 13:26:22 volumio-manu volumio[1235]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 13:26:23 volumio-manu volumio[1235]: TypeError: Cannot read properties of undefined (reading 'service') Jan 28 13:26:23 volumio-manu volumio[1235]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Jan 28 13:26:23 volumio-manu volumio[1235]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:280:18) Jan 28 13:26:23 volumio-manu volumio[1235]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Jan 28 13:26:23 volumio-manu volumio[1235]: at WebSocket.emit (node:events:514:28) Jan 28 13:26:23 volumio-manu volumio[1235]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Jan 28 13:26:23 volumio-manu volumio[1235]: at Receiver.emit (node:events:514:28) Jan 28 13:26:23 volumio-manu volumio[1235]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Jan 28 13:26:23 volumio-manu volumio[1235]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Jan 28 13:26:23 volumio-manu volumio[1235]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Jan 28 13:26:23 volumio-manu volumio[1235]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Jan 28 13:26:23 volumio-manu volumio[1235]: at writeOrBuffer (node:internal/streams/writable:399:12) Jan 28 13:26:23 volumio-manu volumio[1235]: at _write (node:internal/streams/writable:340:10) Jan 28 13:26:23 volumio-manu volumio[1235]: at Writable.write (node:internal/streams/writable:344:10) Jan 28 13:26:23 volumio-manu volumio[1235]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Jan 28 13:26:23 volumio-manu volumio[1235]: at Socket.emit (node:events:514:28) Jan 28 13:26:23 volumio-manu volumio[1235]: at addChunk (node:internal/streams/readable:343:12) Jan 28 13:26:23 volumio-manu volumio[1235]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 13:26:23 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:23+01:00" level=trace msg="sent dealer ping" Jan 28 13:26:23 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:23+01:00" level=trace msg="received dealer pong" Jan 28 13:26:25 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:25+01:00" level=debug msg="handling resume player command from 6207a6844bdc5f84ad7c2576e88dfae524bb7672" Jan 28 13:26:25 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:25+01:00" level=trace msg="seek to 11110ms (diff: 139ms, samples: 489951, bytes: 444507)" uri="spotify:track:6LChsTTDPShYFbzngKMSWK" Jan 28 13:26:25 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:25+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames, PCM format = FLOAT_LE" Jan 28 13:26:25 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:25+01:00" level=debug msg="resume track at 10971ms" Jan 28 13:26:25 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:25+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 28 13:26:25 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:25+01:00" level=trace msg="scheduling prefetch in 125s" Jan 28 13:26:25 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:25+01:00" level=debug msg="sending successful reply for dealer request" Jan 28 13:26:25 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:25+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 28 13:26:25 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:25+01:00" level=trace msg="emitting websocket event: playing" Jan 28 13:26:26 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:26+01:00" level=debug msg="update volume requested to 65535/65535" Jan 28 13:26:26 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:26+01:00" level=debug msg="fetched chunk 4/15, size: 524288" uri="spotify:track:6LChsTTDPShYFbzngKMSWK" Jan 28 13:26:27 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:27+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Jan 28 13:26:27 volumio-manu go-librespot[1597]: time="2026-01-28T13:26:27+01:00" level=trace msg="emitting websocket event: volume" Jan 28 13:26:28 volumio-manu sudo[1740]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 13:25' Jan 28 13:26:28 volumio-manu sudo[1740]: 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"