May 28 17:42:16 volumio-manu systemd[1]: setdatetime-helper.service: Deactivated successfully. May 28 17:42:16 volumio-manu systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. May 28 17:42:16 volumio-manu systemd[1]: setdatetime-helper.service: Consumed 1.514s CPU time. May 28 17:42:16 volumio-manu systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... May 28 17:42:16 volumio-manu systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. May 28 17:42:16 volumio-manu systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. May 28 17:42:16 volumio-manu sudo[1139]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 May 28 17:42:16 volumio-manu sudo[1139]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 28 17:42:16 volumio-manu sudo[1139]: pam_unix(sudo:session): session closed for user root May 28 17:42:16 volumio-manu sudo[1167]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down May 28 17:42:16 volumio-manu sudo[1167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 28 17:42:16 volumio-manu systemd[1]: dpkg-db-backup.service: Deactivated successfully. May 28 17:42:16 volumio-manu systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. May 28 17:42:16 volumio-manu systemd[1]: systemd-rfkill.service: Deactivated successfully. May 28 17:42:16 volumio-manu sudo[1167]: pam_unix(sudo:session): session closed for user root May 28 17:42:16 volumio-manu ntpd[894]: IO: Listen normally on 3 eth0 192.168.1.96:123 May 28 17:42:16 volumio-manu ntpd[894]: IO: new interface(s) found: waking up resolver May 28 17:42:16 volumio-manu ntpd[894]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 May 28 17:42:16 volumio-manu ntpd[894]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 May 28 17:42:16 volumio-manu wireless.js[700]: WIRELESS.JS - INFO: Cleaning previous... May 28 17:42:16 volumio-manu ntpd[894]: DNS: Pool skipping: 109.190.177.205 May 28 17:42:16 volumio-manu ntpd[894]: DNS: Pool skipping: 82.64.230.205 May 28 17:42:16 volumio-manu ntpd[894]: DNS: Pool skipping: 162.159.200.123 May 28 17:42:16 volumio-manu ntpd[894]: DNS: Pool skipping: 5.196.76.84 May 28 17:42:16 volumio-manu ntpd[894]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 May 28 17:42:16 volumio-manu smbd[1158]: [2026/05/28 17:42:16.920519, 0] ../../source3/smbd/server.c:1741(main) May 28 17:42:16 volumio-manu smbd[1158]: smbd version 4.17.8-Raspbian started. May 28 17:42:16 volumio-manu smbd[1158]: Copyright Andrew Tridgell and the Samba Team 1992-2022 May 28 17:42:17 volumio-manu winbindd[1094]: [2026/05/28 17:42:17.016464, 0] ../../source3/winbindd/winbindd_idmap.c:372(wb_parent_idmap_setup_lookupname_done) May 28 17:42:17 volumio-manu winbindd[1094]: wb_parent_idmap_setup_lookupname_done: Lookup domain name 'VOLUMIO MANU' failed 'NT_STATUS_IO_TIMEOUT' May 28 17:42:17 volumio-manu sudo[1173]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 28 17:42:17 volumio-manu sudo[1173]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 28 17:42:17 volumio-manu systemd[1]: Started smbd.service - Samba SMB Daemon. May 28 17:42:17 volumio-manu kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled May 28 17:42:17 volumio-manu sudo[1173]: pam_unix(sudo:session): session closed for user root May 28 17:42:17 volumio-manu wireless.js[700]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations May 28 17:42:17 volumio-manu wireless.js[700]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 4ms May 28 17:42:17 volumio-manu wireless.js[700]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: b8:27:eb:29:34:a0) May 28 17:42:17 volumio-manu sudo[1185]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get May 28 17:42:17 volumio-manu sudo[1185]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:17 volumio-manu sudo[1185]: pam_unix(sudo:session): session closed for user root May 28 17:42:17 volumio-manu sudo[1193]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan May 28 17:42:17 volumio-manu sudo[1193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:17 volumio-manu winbindd[1132]: [2026/05/28 17:42:17.499003, 0] ../../source3/winbindd/winbindd_dual.c:162(child_write_response) May 28 17:42:17 volumio-manu winbindd[1132]: Could not write result May 28 17:42:17 volumio-manu ntpd[894]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 May 28 17:42:17 volumio-manu ntpd[894]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 May 28 17:42:17 volumio-manu ntpd[894]: DNS: Pool skipping: 82.64.42.185 May 28 17:42:17 volumio-manu ntpd[894]: DNS: Pool skipping: 23.161.104.133 May 28 17:42:17 volumio-manu ntpd[894]: DNS: Pool skipping: 172.232.44.156 May 28 17:42:17 volumio-manu ntpd[894]: DNS: Pool skipping: 82.65.248.56 May 28 17:42:17 volumio-manu ntpd[894]: DNS: Pool skipping: 2a12:8ac1:a0::123:1 May 28 17:42:17 volumio-manu ntpd[894]: DNS: Pool skipping: 2a12:bec4:1821:5f1::123 May 28 17:42:17 volumio-manu ntpd[894]: DNS: Pool skipping: 2001:41d0:ab05::4:0:31 May 28 17:42:17 volumio-manu ntpd[894]: DNS: Pool skipping: 2001:bc8:711:46a0::123 May 28 17:42:17 volumio-manu ntpd[894]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 May 28 17:42:18 volumio-manu ntpd[894]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 May 28 17:42:18 volumio-manu ntpd[894]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 May 28 17:42:18 volumio-manu ntpd[894]: DNS: Pool taking: 51.75.18.118 May 28 17:42:18 volumio-manu ntpd[894]: DNS: Pool taking: 79.143.250.33 May 28 17:42:18 volumio-manu ntpd[894]: DNS: Pool taking: 109.190.177.200 May 28 17:42:18 volumio-manu ntpd[894]: DNS: Pool skipping: 162.159.200.123 May 28 17:42:18 volumio-manu ntpd[894]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 May 28 17:42:19 volumio-manu ntpd[894]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 May 28 17:42:19 volumio-manu ntpd[894]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 May 28 17:42:19 volumio-manu ntpd[894]: DNS: Pool taking: 193.42.63.23 May 28 17:42:19 volumio-manu ntpd[894]: DNS: Pool taking: 82.64.81.218 May 28 17:42:19 volumio-manu ntpd[894]: DNS: Pool taking: 146.59.88.209 May 28 17:42:19 volumio-manu ntpd[894]: DNS: Pool taking: 82.64.84.116 May 28 17:42:19 volumio-manu ntpd[894]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 May 28 17:42:20 volumio-manu sudo[1193]: pam_unix(sudo:session): session closed for user root May 28 17:42:20 volumio-manu wireless.js[700]: WIRELESS.JS - INFO: SETTING APPROPRIATE REG DOMAIN: FR May 28 17:42:20 volumio-manu sudo[1204]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set FR May 28 17:42:20 volumio-manu sudo[1204]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:20 volumio-manu sudo[1204]: pam_unix(sudo:session): session closed for user root May 28 17:42:20 volumio-manu wireless.js[700]: WIRELESS.JS - INFO: SUCCESSFULLY SET NEW REGDOMAIN: FR May 28 17:42:20 volumio-manu wireless.js[700]: WIRELESS.JS - INFO: Single Network Mode: Ethernet active, maintaining WiFi scan capability May 28 17:42:20 volumio-manu wireless.js[700]: WIRELESS.JS - INFO: SNM: Maintaining wlan0 UP without IP (scan mode) May 28 17:42:20 volumio-manu wireless.js[700]: WIRELESS.JS - INFO: SNM: Users can configure WiFi via WebUI while ethernet is active May 28 17:42:20 volumio-manu sudo[1215]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 28 17:42:20 volumio-manu sudo[1215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 28 17:42:20 volumio-manu sudo[1215]: pam_unix(sudo:session): session closed for user root May 28 17:42:20 volumio-manu sudo[1218]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 May 28 17:42:20 volumio-manu sudo[1218]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 28 17:42:20 volumio-manu sudo[1218]: pam_unix(sudo:session): session closed for user root May 28 17:42:20 volumio-manu wpa_supplicant[1221]: Successfully initialized wpa_supplicant May 28 17:42:20 volumio-manu wpa_supplicant[1221]: nl80211: kernel reports: Registration to specific type not supported May 28 17:42:20 volumio-manu wpa_supplicant[1224]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all May 28 17:42:20 volumio-manu wireless.js[700]: WIRELESS.JS - INFO: SNM: Transition to scan mode completed in 154945033ms May 28 17:42:20 volumio-manu wireless.js[700]: WIRELESS.JS - INFO: SNM: wlan0 is UP without IP, scan capable May 28 17:42:21 volumio-manu wireless.js[700]: WIRELESS.JS - INFO: Notified systemd about wireless ready May 28 17:42:21 volumio-manu kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled May 28 17:42:21 volumio-manu systemd[1]: Started wireless.service - Wireless Services. May 28 17:42:21 volumio-manu systemd[1]: Started volumio.service - Volumio Backend Module. May 28 17:42:21 volumio-manu systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... May 28 17:42:21 volumio-manu systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker. May 28 17:42:21 volumio-manu systemd[1]: Received SIGRTMIN+21 from PID 293 (plymouthd). May 28 17:42:21 volumio-manu systemd[1]: Received SIGRTMIN+21 from PID 293 (plymouthd). May 28 17:42:21 volumio-manu systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. May 28 17:42:21 volumio-manu systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. May 28 17:42:21 volumio-manu systemd[1]: Started getty@tty1.service - Getty on tty1. May 28 17:42:21 volumio-manu systemd[1]: Reached target getty.target - Login Prompts. May 28 17:42:21 volumio-manu systemd[1]: Reached target multi-user.target - Multi-User System. May 28 17:42:21 volumio-manu systemd[1]: Reached target graphical.target - Graphical Interface. May 28 17:42:21 volumio-manu systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... May 28 17:42:21 volumio-manu volumio-cpu-tweak[1243]: Setting RT Priority for mpd May 28 17:42:21 volumio-manu volumio-cpu-tweak[1259]: pid 35's current scheduling policy: SCHED_OTHER May 28 17:42:21 volumio-manu volumio-cpu-tweak[1259]: pid 35's current scheduling priority: 0 May 28 17:42:21 volumio-manu volumio-cpu-tweak[1243]: Setting MPD Affinity May 28 17:42:21 volumio-manu volumio-cpu-tweak[1260]: pid 3's current affinity mask: f May 28 17:42:21 volumio-manu volumio-cpu-tweak[1243]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input May 28 17:42:21 volumio-manu volumio-cpu-tweak[1243]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance May 28 17:42:21 volumio-manu systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. May 28 17:42:21 volumio-manu systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. May 28 17:42:21 volumio-manu systemd[1]: Startup finished in 15.089s (kernel) + 16.011s (userspace) = 31.100s. May 28 17:42:21 volumio-manu systemd[1]: volumio_cpu_tweak.service: Deactivated successfully. May 28 17:42:23 volumio-manu volumio-remote-updater[698]: [2026-05-28 17:42:23] [info] asio async_connect error: asio.system:111 (Connection refused) May 28 17:42:23 volumio-manu volumio-remote-updater[698]: [2026-05-28 17:42:23] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) May 28 17:42:23 volumio-manu volumio-remote-updater[698]: [2026-05-28 17:42:23] [error] handle_connect error: Connection refused May 28 17:42:24 volumio-manu ntpd[894]: CLOCK: time stepped by 0.133491 May 28 17:42:24 volumio-manu ntpd[894]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes May 28 17:42:25 volumio-manu volumio[1241]: info: ------------------------------------------- May 28 17:42:25 volumio-manu volumio[1241]: info: ----- Volumio3 ---- May 28 17:42:25 volumio-manu volumio[1241]: info: ------------------------------------------- May 28 17:42:25 volumio-manu volumio[1241]: info: ----- System startup ---- May 28 17:42:25 volumio-manu volumio[1241]: info: ------------------------------------------- May 28 17:42:26 volumio-manu systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. May 28 17:42:26 volumio-manu systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. May 28 17:42:26 volumio-manu systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. May 28 17:42:26 volumio-manu upmpdcli[1270]: Could not open config: /tmp/upmpdcli.conf May 28 17:42:26 volumio-manu systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE May 28 17:42:26 volumio-manu systemd[1]: upmpdcli.service: Failed with result 'exit-code'. May 28 17:42:26 volumio-manu volumio[1241]: info: MYVOLUMIO Environment detected May 28 17:42:27 volumio-manu volumio[1241]: info: Plugin folders cleanup May 28 17:42:27 volumio-manu volumio[1241]: info: Scanning into folder /volumio/app/plugins/ May 28 17:42:27 volumio-manu volumio[1241]: info: Scanning category audio_interface May 28 17:42:27 volumio-manu volumio[1241]: info: Scanning category miscellanea May 28 17:42:27 volumio-manu volumio[1241]: info: Scanning category music_service May 28 17:42:27 volumio-manu volumio[1241]: info: Scanning category plugins.json May 28 17:42:27 volumio-manu volumio[1241]: info: Scanning category system_controller May 28 17:42:27 volumio-manu volumio[1241]: info: Scanning category user_interface May 28 17:42:27 volumio-manu volumio[1241]: info: Scanning into folder /data/plugins/ May 28 17:42:27 volumio-manu volumio[1241]: info: Scanning category music_service May 28 17:42:27 volumio-manu volumio[1241]: info: Scanning category system_controller May 28 17:42:27 volumio-manu volumio[1241]: info: Scanning category system_hardware May 28 17:42:27 volumio-manu volumio[1241]: info: Plugin folders cleanup completed May 28 17:42:27 volumio-manu volumio[1241]: info: ------------------------------------------- May 28 17:42:27 volumio-manu volumio[1241]: info: ----- Core plugins startup ---- May 28 17:42:27 volumio-manu volumio[1241]: info: ------------------------------------------- May 28 17:42:27 volumio-manu volumio[1241]: info: Loading plugins from folder /volumio/app/plugins/ May 28 17:42:27 volumio-manu volumio[1241]: info: Adding plugin upnp to MyMusic Plugins May 28 17:42:27 volumio-manu volumio[1241]: info: Adding plugin airplay_emulation to MyMusic Plugins May 28 17:42:27 volumio-manu volumio[1241]: info: Adding plugin upnp_browser to MyMusic Plugins May 28 17:42:27 volumio-manu volumio[1241]: info: Loading plugins from folder /data/plugins/ May 28 17:42:27 volumio-manu volumio[1241]: info: Loading plugin "system"... May 28 17:42:27 volumio-manu volumio[1241]: info: Loading plugin "appearance"... May 28 17:42:29 volumio-manu volumio[1241]: info: Loading plugin "network"... May 28 17:42:29 volumio-manu volumio[1241]: info: Refreshing Cached IP Addresses May 28 17:42:29 volumio-manu sudo[1279]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 28 17:42:29 volumio-manu sudo[1279]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:29 volumio-manu volumio[1241]: info: Loading plugin "services"... May 28 17:42:29 volumio-manu volumio[1241]: info: Loading plugin "volumio5onboarding"... May 28 17:42:29 volumio-manu sudo[1279]: pam_unix(sudo:session): session closed for user root May 28 17:42:29 volumio-manu sudo[1280]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 28 17:42:29 volumio-manu sudo[1280]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:29 volumio-manu volumio[1241]: info: Loading plugin "alsa_controller"... May 28 17:42:29 volumio-manu sudo[1280]: pam_unix(sudo:session): session closed for user root May 28 17:42:29 volumio-manu sudo[1288]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 28 17:42:29 volumio-manu sudo[1288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:29 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 28 17:42:29 volumio-manu volumio[1241]: info: Loading plugin "wizard"... May 28 17:42:29 volumio-manu volumio[1241]: info: Loading plugin "networkfs"... May 28 17:42:29 volumio-manu volumio[1241]: info: Starting Udev Watcher for removable devices May 28 17:42:29 volumio-manu volumio[1241]: info: Ignoring mount for partition: boot May 28 17:42:29 volumio-manu volumio[1241]: info: Ignoring mount for partition: volumio May 28 17:42:29 volumio-manu volumio[1241]: info: Ignoring mount for partition: volumio_data May 28 17:42:29 volumio-manu sudo[1309]: 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 May 28 17:42:29 volumio-manu sudo[1309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:29 volumio-manu volumio[1241]: info: Mounting Device EFI May 28 17:42:29 volumio-manu sudo[1319]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/EFI -o noatime,dmask=0000,fmask=0000,iocharset=utf8 May 28 17:42:29 volumio-manu sudo[1319]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:29 volumio-manu kernel: FAT-fs (sda1): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! May 28 17:42:29 volumio-manu kernel: FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. May 28 17:42:29 volumio-manu sudo[1319]: pam_unix(sudo:session): session closed for user root May 28 17:42:29 volumio-manu volumio[1241]: info: Mounting Device UNTITLED May 28 17:42:29 volumio-manu sudo[1329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda2 /mnt/USB/UNTITLED -o noatime,dmask=0000,fmask=0000,iocharset=utf8 May 28 17:42:29 volumio-manu sudo[1329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:30 volumio-manu kernel: netfs: FS-Cache loaded May 28 17:42:30 volumio-manu kernel: FAT-fs (sda2): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! May 28 17:42:30 volumio-manu sudo[1329]: pam_unix(sudo:session): session closed for user root May 28 17:42:30 volumio-manu kernel: FAT-fs (sda2): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. May 28 17:42:30 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 28 17:42:30 volumio-manu volumio[1241]: info: Loading plugin "volumio_command_line_client"... May 28 17:42:30 volumio-manu volumio[1241]: info: Loading plugin "upnp"... May 28 17:42:30 volumio-manu volumio[1241]: info: [1779982950085] Starting Upmpd Daemon May 28 17:42:30 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 28 17:42:30 volumio-manu volumio[1241]: info: Loading plugin "my_music"... May 28 17:42:30 volumio-manu volumio[1241]: info: Loading plugin "mpd"... May 28 17:42:30 volumio-manu kernel: Key type cifs.spnego registered May 28 17:42:30 volumio-manu kernel: Key type cifs.idmap registered May 28 17:42:30 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. May 28 17:42:30 volumio-manu kernel: CIFS: Attempting to mount //iMac-de-Emmanuel.local/AUDIO May 28 17:42:30 volumio-manu volumio[1241]: info: Loading plugin "upnp_browser"... May 28 17:42:30 volumio-manu sudo[1309]: pam_unix(sudo:session): session closed for user root May 28 17:42:31 volumio-manu sudo[1288]: pam_unix(sudo:session): session closed for user root May 28 17:42:32 volumio-manu volumio[1241]: info: Starting UPNP Browser May 28 17:42:32 volumio-manu volumio[1241]: info: Loading plugin "alarm-clock"... May 28 17:42:33 volumio-manu volumio[1241]: info: Loading plugin "airplay_emulation"... May 28 17:42:33 volumio-manu volumio[1241]: info: Starting Shairport Sync May 28 17:42:33 volumio-manu volumio[1241]: info: Loading plugin "last_100"... May 28 17:42:33 volumio-manu volumio-remote-updater[698]: [2026-05-28 17:42:33] [connect] Successful connection May 28 17:42:33 volumio-manu volumio[1241]: info: Loading plugin "webradio"... May 28 17:42:33 volumio-manu volumio[1241]: info: Loading plugin "i2s_dacs"... May 28 17:42:33 volumio-manu volumio[1241]: info: Loading plugin "volumiodiscovery"... May 28 17:42:33 volumio-manu volumio[1241]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 28 17:42:33 volumio-manu node[1241]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 28 17:42:33 volumio-manu volumio[1241]: *** WARNING *** Please fix your application to use the native API of Avahi! May 28 17:42:33 volumio-manu node[1241]: *** WARNING *** Please fix your application to use the native API of Avahi! May 28 17:42:33 volumio-manu volumio[1241]: *** WARNING *** For more information see May 28 17:42:33 volumio-manu node[1241]: *** WARNING *** For more information see May 28 17:42:33 volumio-manu volumio[1241]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 28 17:42:33 volumio-manu node[1241]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 28 17:42:33 volumio-manu volumio[1241]: *** WARNING *** Please fix your application to use the native API of Avahi! May 28 17:42:33 volumio-manu node[1241]: *** WARNING *** Please fix your application to use the native API of Avahi! May 28 17:42:33 volumio-manu volumio[1241]: *** WARNING *** For more information see May 28 17:42:33 volumio-manu node[1241]: *** WARNING *** For more information see May 28 17:42:33 volumio-manu volumio[1241]: info: Applying required configuration parameters for plugin volumiodiscovery May 28 17:42:33 volumio-manu volumio[1241]: info: Discovery: Started advertising with name: Volumio Manu May 28 17:42:33 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 28 17:42:33 volumio-manu volumio[1241]: info: Loading plugin "spop"... May 28 17:42:36 volumio-manu volumio[1241]: info: Loading plugin "outputs"... May 28 17:42:36 volumio-manu volumio[1241]: info: Loading plugin "albumart"... May 28 17:42:36 volumio-manu volumio[1241]: info: Plugin example_plugin is not enabled May 28 17:42:36 volumio-manu volumio[1241]: info: Loading plugin "inputs"... May 28 17:42:36 volumio-manu volumio[1241]: info: Loading plugin "updater_comm"... May 28 17:42:36 volumio-manu volumio[1241]: info: Plugin mpdemulation is not enabled May 28 17:42:36 volumio-manu volumio[1241]: info: Loading plugin "rest_api"... May 28 17:42:36 volumio-manu volumio[1241]: info: Loading plugin "websocket"... May 28 17:42:36 volumio-manu volumio[1241]: info: Starting Socket.io Server version 1.7.4 May 28 17:42:36 volumio-manu volumio[1241]: info: Loading plugin "podcast"... May 28 17:42:37 volumio-manu volumio[1241]: info: ControllerPodcast::constructor May 28 17:42:37 volumio-manu volumio[1367]: Forking 3 albumart workers May 28 17:42:38 volumio-manu volumio[1241]: info: Loading plugin "backup_restore"... May 28 17:42:38 volumio-manu systemd[1]: systemd-fsckd.service: Deactivated successfully. May 28 17:42:41 volumio-manu systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. May 28 17:42:41 volumio-manu systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. May 28 17:42:41 volumio-manu systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. May 28 17:42:41 volumio-manu upmpdcli[1421]: Could not open config: /tmp/upmpdcli.conf May 28 17:42:41 volumio-manu systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE May 28 17:42:41 volumio-manu systemd[1]: upmpdcli.service: Failed with result 'exit-code'. May 28 17:42:41 volumio-manu volumio[1241]: info: Applying required configuration parameters for plugin backup_restore May 28 17:42:41 volumio-manu volumio[1241]: info: Loading plugin "audiophonicsonoff"... May 28 17:42:43 volumio-manu systemd[1]: systemd-hostnamed.service: Deactivated successfully. May 28 17:42:45 volumio-manu volumio[1241]: info: Applying required configuration parameters for plugin audiophonicsonoff May 28 17:42:45 volumio-manu volumio[1241]: info: Audiophonics on/off initiated May 28 17:42:45 volumio-manu volumio[1241]: info: Loading i18n strings for locale fr May 28 17:42:45 volumio-manu volumio[1241]: Updating browse sources language May 28 17:42:45 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 28 17:42:45 volumio-manu volumio[1377]: Starting albumart workers May 28 17:42:46 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 28 17:42:46 volumio-manu volumio[1241]: info: CoreCommandRouter::initPlayerControls May 28 17:42:46 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:46 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:46 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:46 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:46 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:46 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:46 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:46 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:46 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 28 17:42:46 volumio-manu volumio[1241]: Express server listening on port 3000 May 28 17:42:46 volumio-manu volumio[1241]: [Metrics] WebUI: 21s 955.87ms May 28 17:42:46 volumio-manu volumio[1241]: info: CoreStateMachine::resetVolumioState May 28 17:42:46 volumio-manu volumio[1241]: info: CoreStateMachine::getcurrentVolume May 28 17:42:46 volumio-manu volumio[1241]: info: CoreCommandRouter::volumioRetrievevolume May 28 17:42:46 volumio-manu volumio[1379]: Starting albumart workers May 28 17:42:46 volumio-manu sudo[1436]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 28 17:42:46 volumio-manu sudo[1438]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 28 17:42:46 volumio-manu sudo[1438]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:46 volumio-manu sudo[1438]: pam_unix(sudo:session): session closed for user root May 28 17:42:46 volumio-manu sudo[1436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:46 volumio-manu sudo[1436]: pam_unix(sudo:session): session closed for user root May 28 17:42:46 volumio-manu volumio[1241]: info: Volumio Network Manager: Network status updated: 1 May 28 17:42:46 volumio-manu volumio[1378]: Starting albumart workers May 28 17:42:46 volumio-manu volumio[1241]: info: CoreStateMachine::pushState May 28 17:42:46 volumio-manu volumio[1241]: info: CorePlayQueue::getTrack 0 May 28 17:42:46 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 28 17:42:46 volumio-manu volumio[1241]: info: CoreCommandRouter::volumioPushState May 28 17:42:46 volumio-manu volumio[1241]: info: CoreStateMachine::updateTrackBlock May 28 17:42:46 volumio-manu volumio[1241]: info: CorePlayQueue::getTrackBlock May 28 17:42:46 volumio-manu volumio[1241]: info: CoreCommandRouter::volumioRetrievevolume May 28 17:42:47 volumio-manu volumio[1241]: info: CoreStateMachine::pushState May 28 17:42:47 volumio-manu volumio[1241]: info: CorePlayQueue::getTrack 0 May 28 17:42:47 volumio-manu volumio[1241]: info: CoreCommandRouter::volumioPushState May 28 17:42:47 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 28 17:42:47 volumio-manu volumio[1241]: info: Reloading queue from file May 28 17:42:48 volumio-manu volumio[1241]: info: CoreStateMachine::setRepeat false single undefined May 28 17:42:48 volumio-manu volumio[1241]: info: CoreStateMachine::pushState May 28 17:42:48 volumio-manu volumio[1241]: info: CorePlayQueue::getTrack 0 May 28 17:42:48 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 28 17:42:48 volumio-manu volumio[1241]: info: CoreCommandRouter::volumioPushState May 28 17:42:48 volumio-manu volumio[1241]: info: CoreStateMachine::setRandom undefined May 28 17:42:48 volumio-manu volumio[1241]: info: CoreStateMachine::pushState May 28 17:42:48 volumio-manu volumio[1241]: info: CorePlayQueue::getTrack 0 May 28 17:42:48 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 28 17:42:48 volumio-manu volumio[1241]: info: CoreCommandRouter::volumioPushState May 28 17:42:48 volumio-manu volumio-remote-updater[698]: [2026-05-28 17:42:48] [connect] Successful connection May 28 17:42:48 volumio-manu volumio[1241]: info: Setting Device type: Raspberry PI May 28 17:42:48 volumio-manu volumio[1241]: info: Completed loading Core Plugins May 28 17:42:48 volumio-manu volumio[1241]: info: Preparing to generate the ALSA configuration file May 28 17:42:48 volumio-manu volumio[1241]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf May 28 17:42:48 volumio-manu volumio[1241]: info: Reading ALSA contributions from plugins. May 28 17:42:48 volumio-manu volumio-remote-updater[698]: [2026-05-28 17:42:48] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1779982968 101 May 28 17:42:48 volumio-manu volumio[1241]: 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 May 28 17:42:48 volumio-manu volumio[1241]: info: Discovery: adding 2d4b54dd-672c-4b28-8353-fe66b43ecafd May 28 17:42:48 volumio-manu volumio[1241]: info: Discovery: Found device Volumio Manu May 28 17:42:48 volumio-manu volumio[1241]: info: CoreCommandRouter::volumioGetState May 28 17:42:48 volumio-manu volumio[1241]: info: CorePlayQueue::getTrack 0 May 28 17:42:48 volumio-manu sudo[1462]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 28 17:42:48 volumio-manu sudo[1462]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:48 volumio-manu volumio[1241]: info: Discovery: this is already registered, 2d4b54dd-672c-4b28-8353-fe66b43ecafd May 28 17:42:48 volumio-manu volumio[1241]: info: Discovery: Found device Volumio Manu May 28 17:42:49 volumio-manu volumio[1241]: info: CoreCommandRouter::volumioGetState May 28 17:42:49 volumio-manu volumio[1241]: info: CorePlayQueue::getTrack 0 May 28 17:42:49 volumio-manu volumio[1241]: info: Asound.conf file unchanged, so no further update is needed May 28 17:42:49 volumio-manu volumio[1241]: info: Output device has changed, restarting MPD May 28 17:42:49 volumio-manu volumio[1241]: info: Output device has changed, restarting Shairport Sync May 28 17:42:49 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:49 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 28 17:42:49 volumio-manu sudo[1465]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 28 17:42:49 volumio-manu sudo[1465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:49 volumio-manu sudo[1465]: pam_unix(sudo:session): session closed for user root May 28 17:42:49 volumio-manu sudo[1467]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 28 17:42:49 volumio-manu sudo[1467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:49 volumio-manu volumio[1241]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 28 17:42:49 volumio-manu volumio[1241]: info: ___________ START PLUGINS ___________ May 28 17:42:49 volumio-manu volumio[1241]: info: ControllerMpd::onStart: Initializing MPD May 28 17:42:49 volumio-manu volumio[1241]: info: Creating MPD Configuration file May 28 17:42:49 volumio-manu systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 28 17:42:49 volumio-manu systemd[1]: Starting mpd.service - Music Player Daemon... May 28 17:42:50 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 28 17:42:50 volumio-manu volumio[1241]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 28 17:42:50 volumio-manu volumio[1241]: info: [1779982970121] CoreMusicLibrary::Adding element Serveurs Média May 28 17:42:50 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 28 17:42:50 volumio-manu sudo[1484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 28 17:42:50 volumio-manu sudo[1484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:50 volumio-manu sudo[1485]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 28 17:42:50 volumio-manu sudo[1485]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 28 17:42:50 volumio-manu sudo[1498]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory May 28 17:42:50 volumio-manu sudo[1485]: pam_unix(sudo:session): session closed for user root May 28 17:42:50 volumio-manu volumio[1241]: info: UPNP Browser: Client initialized successfully May 28 17:42:50 volumio-manu sudo[1491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 28 17:42:50 volumio-manu systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... May 28 17:42:50 volumio-manu sudo[1484]: pam_unix(sudo:session): session closed for user root May 28 17:42:50 volumio-manu sudo[1491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:50 volumio-manu sudo[1482]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service May 28 17:42:50 volumio-manu sudo[1482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:50 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:50 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 28 17:42:50 volumio-manu systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. May 28 17:42:50 volumio-manu systemd[1]: mpd.service: Deactivated successfully. May 28 17:42:50 volumio-manu systemd[1]: Stopped mpd.service - Music Player Daemon. May 28 17:42:50 volumio-manu sudo[1482]: pam_unix(sudo:session): session closed for user root May 28 17:42:50 volumio-manu systemd[1]: mpd.socket: Deactivated successfully. May 28 17:42:50 volumio-manu systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 28 17:42:50 volumio-manu systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 28 17:42:50 volumio-manu systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 28 17:42:50 volumio-manu systemd[1]: Starting mpd.service - Music Player Daemon... May 28 17:42:50 volumio-manu volumio[1241]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 28 17:42:50 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:50 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 28 17:42:51 volumio-manu volumio[1241]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 28 17:42:51 volumio-manu volumio[1241]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 28 17:42:51 volumio-manu sudo[1523]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 28 17:42:51 volumio-manu volumio[1241]: info: [1779982971021] CoreMusicLibrary::Adding element Last_100 May 28 17:42:51 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 28 17:42:51 volumio-manu sudo[1523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 28 17:42:51 volumio-manu sudo[1539]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory May 28 17:42:51 volumio-manu sudo[1523]: pam_unix(sudo:session): session closed for user root May 28 17:42:51 volumio-manu volumio[1241]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 28 17:42:51 volumio-manu volumio[1241]: info: [1779982971080] CoreMusicLibrary::Adding element Webradio May 28 17:42:51 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 28 17:42:51 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 28 17:42:51 volumio-manu volumio[1241]: info: Initializing BBC Radios May 28 17:42:51 volumio-manu volumio5-onboarding[1521]: time=2026-05-28T17:42:51.258+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z May 28 17:42:51 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 28 17:42:51 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 28 17:42:51 volumio-manu volumio[1241]: info: Creating Spotify config file May 28 17:42:51 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:52 volumio-manu systemd[1]: setdatetime-helper.service: Deactivated successfully. May 28 17:42:52 volumio-manu systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. May 28 17:42:52 volumio-manu systemd[1]: setdatetime-helper.service: Consumed 1.014s CPU time. May 28 17:42:54 volumio-manu volumio[1241]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 28 17:42:54 volumio-manu volumio[1241]: info: [1779982974031] CoreMusicLibrary::Adding element Podcast May 28 17:42:54 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 28 17:42:54 volumio-manu volumio[1241]: Cannot find translation for source Podcast May 28 17:42:54 volumio-manu volumio[1241]: info: Configuring GPIO pins May 28 17:42:54 volumio-manu volumio[1241]: info: Soft shutdown GPIO 516 binding... OK May 28 17:42:54 volumio-manu volumio[1241]: info: Hardware button GPIO 529 binding... OK May 28 17:42:54 volumio-manu volumio[1241]: info: Boot OK GPIO 534 binding... OK May 28 17:42:54 volumio-manu volumio[1241]: info: Volumio Calling Home May 28 17:42:56 volumio-manu volumio[1241]: info: MPD Permissions set May 28 17:42:56 volumio-manu volumio[1241]: info: MPD Permissions set May 28 17:42:56 volumio-manu volumio[1241]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 May 28 17:42:56 volumio-manu systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. May 28 17:42:56 volumio-manu systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. May 28 17:42:56 volumio-manu volumio[1241]: info: Volumio called home May 28 17:42:56 volumio-manu volumio[1241]: info: Spotify config file written May 28 17:42:56 volumio-manu systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. May 28 17:42:56 volumio-manu sudo[1462]: pam_unix(sudo:session): session closed for user root May 28 17:42:57 volumio-manu sudo[1612]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 28 17:42:57 volumio-manu sudo[1612]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:57 volumio-manu volumio[1241]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 May 28 17:42:57 volumio-manu volumio[1241]: info: Received Get System Info May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 28 17:42:57 volumio-manu volumio[1241]: info: Discovery: Getting this device information May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::volumioGetState May 28 17:42:57 volumio-manu volumio[1241]: info: CorePlayQueue::getTrack 0 May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 28 17:42:57 volumio-manu volumio5-onboarding[1521]: time=2026-05-28T17:42:57.134+02:00 level=INFO msg="system info for d95a87b07c7f2b9e5c2ede7bad160b54" deviceName="Volumio Manu" deviceVariant=volumio deviceModel= softwareVersion=4.119 May 28 17:42:57 volumio-manu volumio5-onboarding[1521]: time=2026-05-28T17:42:57.162+02:00 level=INFO msg="bootstrapping state" hasInternet=true May 28 17:42:57 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. May 28 17:42:57 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. May 28 17:42:57 volumio-manu systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 28 17:42:57 volumio-manu go-librespot[1624]: go-librespot daemon starting... May 28 17:42:57 volumio-manu sudo[1612]: pam_unix(sudo:session): session closed for user root May 28 17:42:57 volumio-manu volumio[1241]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: No need to fix Spotify hosts May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 17:42:57 volumio-manu volumio[1241]: info: Received Get System Info May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 28 17:42:57 volumio-manu volumio[1241]: info: Discovery: Getting this device information May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::volumioGetState May 28 17:42:57 volumio-manu volumio[1241]: info: CorePlayQueue::getTrack 0 May 28 17:42:57 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 28 17:42:58 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:58+02:00" level=info msg="running go-librespot 0.7.1" May 28 17:42:58 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:58+02:00" level=debug msg="app state loaded" May 28 17:42:58 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:58+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 28 17:42:58 volumio-manu mpd[1540]: decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 28 17:42:58 volumio-manu mpd[1540]: output: No 'audio_output' defined in config file May 28 17:42:58 volumio-manu mpd[1540]: output: Successfully detected a sndio audio device May 28 17:42:58 volumio-manu volumio[1241]: info: Upmpdcli Daemon Started May 28 17:42:58 volumio-manu mpd[1540]: zeroconf: No global port, disabling zeroconf May 28 17:42:58 volumio-manu systemd[1]: Started mpd.service - Music Player Daemon. May 28 17:42:58 volumio-manu sudo[1491]: pam_unix(sudo:session): session closed for user root May 28 17:42:58 volumio-manu sudo[1467]: pam_unix(sudo:session): session closed for user root May 28 17:42:58 volumio-manu volumio-remote-updater[698]: Test mode disabled May 28 17:42:58 volumio-manu volumio-remote-updater[698]: Alpha mode disabled May 28 17:42:58 volumio-manu volumio-remote-updater[698]: Alpha legacy test mode disabled May 28 17:42:59 volumio-manu volumio[1241]: info: New Spotify access tokenBQCp121ZfO... May 28 17:42:59 volumio-manu volumio[1241]: info: Spotify credentials grant success - running version from March 24, 2019 May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=info msg="zeroconf server listening on port 34819" May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" May 28 17:42:59 volumio-manu volumio[1241]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 28 17:42:59 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 28 17:42:59 volumio-manu volumio[1241]: info: Completed starting Core Plugins May 28 17:42:59 volumio-manu volumio[1241]: info: ------------------------------------------- May 28 17:42:59 volumio-manu volumio[1241]: info: ----- MyVolumio plugins startup ---- May 28 17:42:59 volumio-manu volumio[1241]: info: ------------------------------------------- May 28 17:42:59 volumio-manu volumio[1241]: info: [MyVolumio PluginManager] Fetching plans data.... May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=debug msg="obtained new client token: AAD3F7k3ogN7ImFn3VbKTiBtjY3NaBgCuUYjE4l5O5yGneTCTZIkszc7XVqe/0dWbejQ+AyMTHwBLBBesaOv/r4Cu1N5R6cMnf6M9j2lV2XhjR3jjhAFroJ4SB5MXKsfFPSxlcEBFyurvvOQ0Mo9FFlrPgnTnFoWyDBjwCWbVTM8pL6GAqjmoloI50bue/ycyida53nuAMynEa8RREb6F2FnxLAkuYmZJ0dJ3YG1NRqWKSYZQuN/" May 28 17:42:59 volumio-manu volumio[1241]: info: Starting Shairport Sync May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=debug msg="completed keyexchange" May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=debug msg="completed challenge" May 28 17:42:59 volumio-manu volumio[1241]: info: Starting Shairport Sync May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=info msg="authenticated AP" username="31************************my" May 28 17:42:59 volumio-manu volumio[1241]: info: Starting Shairport Sync May 28 17:42:59 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 28 17:42:59 volumio-manu sudo[1654]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 28 17:42:59 volumio-manu sudo[1654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:59 volumio-manu sudo[1656]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 28 17:42:59 volumio-manu sudo[1656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=info msg="authenticated Login5" username="31************************my" May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=debug msg="initializing zeroconf session" username="31************************my" May 28 17:42:59 volumio-manu sudo[1653]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 28 17:42:59 volumio-manu sudo[1653]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=debug msg="dealer connection opened" May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=trace msg="starting accesspoint recv loop" May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=trace msg="starting dealer recv loop" May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=trace msg="received accesspoint ping" May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=debug msg="received connection id: MDUzYzM2OTEtNGU2...NzMzOTUxMTY0Qg==" May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=trace msg="received accesspoint pong ack" May 28 17:42:59 volumio-manu systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 28 17:42:59 volumio-manu systemd[1]: shairport-sync.service: Deactivated successfully. May 28 17:42:59 volumio-manu systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 28 17:42:59 volumio-manu systemd[1]: shairport-sync.service: Consumed 1.901s CPU time. May 28 17:42:59 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 28 17:42:59 volumio-manu systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 28 17:42:59 volumio-manu systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 28 17:42:59 volumio-manu sudo[1654]: pam_unix(sudo:session): session closed for user root May 28 17:42:59 volumio-manu systemd[1]: shairport-sync.service: Deactivated successfully. May 28 17:42:59 volumio-manu go-librespot[1625]: time="2026-05-28T17:42:59+02:00" level=debug msg="put connect state because NEW_DEVICE" May 28 17:42:59 volumio-manu systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 28 17:42:59 volumio-manu systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 28 17:42:59 volumio-manu sudo[1656]: pam_unix(sudo:session): session closed for user root May 28 17:42:59 volumio-manu systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 28 17:42:59 volumio-manu systemd[1]: shairport-sync.service: Deactivated successfully. May 28 17:42:59 volumio-manu systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 28 17:42:59 volumio-manu systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 28 17:42:59 volumio-manu sudo[1653]: pam_unix(sudo:session): session closed for user root May 28 17:43:00 volumio-manu volumio[1241]: error: MPD error: The expression evaluated to a falsy value: May 28 17:43:00 volumio-manu volumio[1241]: assert.ok(self.idling) May 28 17:43:00 volumio-manu volumio[1241]: error: The expression evaluated to a falsy value: May 28 17:43:00 volumio-manu volumio[1241]: assert.ok(self.idling) May 28 17:43:00 volumio-manu volumio[1241]: info: MPD running with PID1540 May 28 17:43:00 volumio-manu volumio[1241]: ,establishing connection May 28 17:43:00 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 28 17:43:00 volumio-manu volumio[1241]: error: updateQueue error: null May 28 17:43:00 volumio-manu volumio[1241]: info: Shairport-Sync Started May 28 17:43:00 volumio-manu volumio[1241]: Error adding Membership: Error: addMembership EINVAL May 28 17:43:00 volumio-manu volumio[1241]: info: Shairport-Sync Started May 28 17:43:00 volumio-manu volumio[1241]: info: Shairport-Sync Started May 28 17:43:00 volumio-manu volumio[1241]: info: Received Get System Info May 28 17:43:00 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 28 17:43:00 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 28 17:43:00 volumio-manu volumio[1241]: info: Discovery: Getting this device information May 28 17:43:00 volumio-manu volumio[1241]: info: CoreCommandRouter::volumioGetState May 28 17:43:00 volumio-manu volumio[1241]: info: CorePlayQueue::getTrack 0 May 28 17:43:00 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 28 17:43:01 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 28 17:43:01 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 28 17:43:01 volumio-manu volumio[1241]: error: updateQueue error: null May 28 17:43:01 volumio-manu volumio5-onboarding[1521]: time=2026-05-28T17:43:01.132+02:00 level=INFO msg="enabling local network discovery" May 28 17:43:01 volumio-manu volumio5-onboarding[1521]: time=2026-05-28T17:43:01.170+02:00 level=INFO msg="enabling BLE discovery" May 28 17:43:01 volumio-manu volumio[1241]: info: CoreCommandRouter::volumioGetState May 28 17:43:01 volumio-manu volumio[1241]: info: CorePlayQueue::getTrack 0 May 28 17:43:01 volumio-manu volumio[1241]: SPOTIFY: User informations: {"account_id":"UZdUCfnVGs","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"} May 28 17:43:01 volumio-manu volumio[1241]: info: Spotify Successfully logged in May 28 17:43:01 volumio-manu volumio[1241]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 28 17:43:01 volumio-manu volumio[1241]: info: [1779982981640] CoreMusicLibrary::Adding element Spotify May 28 17:43:01 volumio-manu volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 28 17:43:01 volumio-manu volumio[1241]: Cannot find translation for source Podcast May 28 17:43:01 volumio-manu volumio[1241]: Cannot find translation for source Spotify May 28 17:43:01 volumio-manu volumio[1241]: info: go-librespot daemon successfully initialized May 28 17:43:02 volumio-manu volumio5-onboarding[1521]: time=2026-05-28T17:43:02.240+02:00 level=INFO msg="service successfully established" component=discovery/localnet May 28 17:43:04 volumio-manu mpd[1540]: exception: No database May 28 17:43:04 volumio-manu mpd[1540]: exception: No database May 28 17:43:04 volumio-manu mpd[1540]: exception: No database May 28 17:43:04 volumio-manu volumio[1241]: error: Failed LSINFO: Error: [50@0] {lsinfo} No database May 28 17:43:04 volumio-manu volumio[1241]: info: Initializing connection to go-librespot Websocket May 28 17:43:04 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:04+02:00" level=debug msg="new websocket client" May 28 17:43:04 volumio-manu volumio[1241]: info: Connection to go-librespot Websocket established May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="handling transfer player command from d479c00d70ebab4b6efe26c330c6bc55acd399da" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="resolved context of track" uri="spotify:album:4Vk4vV6FLeDiJE0uupd7Bt" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:album:4Vk4vV6FLeDiJE0uupd7Bt" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="loading track (paused: false, position: 2830ms)" uri="spotify:track:2MFm3yQgt7hNkjP1ZYsI2u" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=trace msg="emitting websocket event: will_play" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" May 28 17:43:05 volumio-manu volumio[1241]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:album:4Vk4vV6FLeDiJE0uupd7Bt","uri":"spotify:track:2MFm3yQgt7hNkjP1ZYsI2u","play_origin":"whats_new_panel"}} May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="selected format OGG_VORBIS_320 (bdd259e98812f150c39f65266babc0d26f837c10)" uri="spotify:track:2MFm3yQgt7hNkjP1ZYsI2u" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="requested aes key for file bdd259e98812f150c39f65266babc0d26f837c10, gid: 2MFm3yQgt7hNkjP1ZYsI2u" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:2MFm3yQgt7hNkjP1ZYsI2u" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="fetched first chunk of 16, total size is 7928706 bytes" uri="spotify:track:2MFm3yQgt7hNkjP1ZYsI2u" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=trace msg="seek to 2830ms (diff: 95ms, samples: 124803, bytes: 89939)" uri="spotify:track:2MFm3yQgt7hNkjP1ZYsI2u" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="created new output device" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1827" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02: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" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=info msg="loaded track \"MÉDICAMENT\" (paused: false, position: 2830ms, duration: 186880ms, prefetched: false)" uri="spotify:track:2MFm3yQgt7hNkjP1ZYsI2u" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=trace msg="scheduling prefetch in 154s" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=trace msg="emitting websocket event: metadata" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=trace msg="emitting websocket event: active" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="sending successful reply for dealer request" May 28 17:43:05 volumio-manu volumio[1241]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2MFm3yQgt7hNkjP1ZYsI2u","name":"MÉDICAMENT","artist_names":["HOUDI","Anyme023"],"album_name":"MÉDICAMENT","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02524954f7ece093e92a7ef525","position":2830,"duration":186880,"release_date":"year:2026 month:5 day:22","track_number":1,"disc_number":1}} May 28 17:43:05 volumio-manu volumio[1241]: SPOTIFY: received: {"type":"active","data":null} May 28 17:43:05 volumio-manu volumio[1241]: info: Aligning Spotify Volume to Volumio Volume May 28 17:43:05 volumio-manu volumio[1241]: info: CoreCommandRouter::volumioGetState May 28 17:43:05 volumio-manu volumio[1241]: info: CorePlayQueue::getTrack 0 May 28 17:43:05 volumio-manu volumio[1241]: info: Setting Spotify Volume from Volumio: 100 May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:2MFm3yQgt7hNkjP1ZYsI2u" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:2MFm3yQgt7hNkjP1ZYsI2u" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1418" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=trace msg="emitting websocket event: playing" May 28 17:43:05 volumio-manu go-librespot[1625]: time="2026-05-28T17:43:05+02:00" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:2MFm3yQgt7hNkjP1ZYsI2u" May 28 17:43:05 volumio-manu volumio[1241]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:4Vk4vV6FLeDiJE0uupd7Bt","uri":"spotify:track:2MFm3yQgt7hNkjP1ZYsI2u","resume":false,"play_origin":"whats_new_panel"}} May 28 17:43:05 volumio-manu volumio[1241]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 28 17:43:05 volumio-manu volumio[1241]: TypeError: Cannot read properties of undefined (reading 'service') May 28 17:43:05 volumio-manu volumio[1241]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) May 28 17:43:05 volumio-manu volumio[1241]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:272:18) May 28 17:43:05 volumio-manu volumio[1241]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) May 28 17:43:05 volumio-manu volumio[1241]: at WebSocket.emit (node:events:514:28) May 28 17:43:05 volumio-manu volumio[1241]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) May 28 17:43:05 volumio-manu volumio[1241]: at Receiver.emit (node:events:514:28) May 28 17:43:05 volumio-manu volumio[1241]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) May 28 17:43:05 volumio-manu volumio[1241]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) May 28 17:43:05 volumio-manu volumio[1241]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) May 28 17:43:05 volumio-manu volumio[1241]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) May 28 17:43:05 volumio-manu volumio[1241]: at writeOrBuffer (node:internal/streams/writable:399:12) May 28 17:43:05 volumio-manu volumio[1241]: at _write (node:internal/streams/writable:340:10) May 28 17:43:05 volumio-manu volumio[1241]: at Writable.write (node:internal/streams/writable:344:10) May 28 17:43:05 volumio-manu volumio[1241]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) May 28 17:43:05 volumio-manu volumio[1241]: at Socket.emit (node:events:514:28) May 28 17:43:05 volumio-manu volumio[1241]: at addChunk (node:internal/streams/readable:343:12) May 28 17:43:05 volumio-manu volumio[1241]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 28 17:43:13 volumio-manu upmpdcli[1726]: writing RSA key May 28 17:43:13 volumio-manu sudo[1730]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-28 17:42' May 28 17:43:13 volumio-manu sudo[1730]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"