Jul 18 06:39:42 volumio ntpd[807]: CLOCK: time stepped by 128384.385016 Jul 18 06:39:42 volumio ntpd[807]: CLOCK: time changed from 2025-07-16 to 2025-07-18 Jul 18 06:39:42 volumio ntpd[807]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Jul 18 06:39:42 volumio sudo[1155]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jul 18 06:39:42 volumio sudo[1155]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:39:42 volumio sudo[1155]: pam_unix(sudo:session): session closed for user root Jul 18 06:39:43 volumio sudo[1159]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jul 18 06:39:43 volumio sudo[1159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:39:43 volumio sudo[1159]: pam_unix(sudo:session): session closed for user root Jul 18 06:39:44 volumio sudo[1163]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jul 18 06:39:44 volumio sudo[1163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:39:44 volumio sudo[1163]: pam_unix(sudo:session): session closed for user root Jul 18 06:39:44 volumio dhcpcd[716]: wlan0: leased 192.168.1.88 for 21600 seconds Jul 18 06:39:44 volumio avahi-daemon[594]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.88. Jul 18 06:39:44 volumio avahi-daemon[594]: New relevant interface wlan0.IPv4 for mDNS. Jul 18 06:39:44 volumio avahi-daemon[594]: Registering new address record for 192.168.1.88 on wlan0.IPv4. Jul 18 06:39:44 volumio dhcpcd[716]: wlan0: adding route to 192.168.1.0/24 Jul 18 06:39:44 volumio dhcpcd[716]: wlan0: adding default route via 192.168.1.1 Jul 18 06:39:45 volumio systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Jul 18 06:39:45 volumio systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Jul 18 06:39:45 volumio systemd[1]: welcome.service: Deactivated successfully. Jul 18 06:39:45 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Jul 18 06:39:45 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Jul 18 06:39:45 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Jul 18 06:39:45 volumio systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Jul 18 06:39:45 volumio welcome[1192]: Resolved ip:[2] 192.168.1.245 192.168.1.88 Jul 18 06:39:45 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Jul 18 06:39:45 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Jul 18 06:39:45 volumio systemd[1]: dpkg-db-backup.service: Deactivated successfully. Jul 18 06:39:45 volumio systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Jul 18 06:39:45 volumio sudo[1203]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jul 18 06:39:45 volumio sudo[1203]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:39:45 volumio sudo[1203]: pam_unix(sudo:session): session closed for user root Jul 18 06:39:45 volumio sudo[1206]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 18 06:39:45 volumio sudo[1206]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jul 18 06:39:45 volumio sudo[1206]: pam_unix(sudo:session): session closed for user root Jul 18 06:39:45 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jul 18 06:39:45 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jul 18 06:39:45 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jul 18 06:39:45 volumio systemd[1]: shairport-sync.service: Consumed 1.725s CPU time. Jul 18 06:39:45 volumio avahi-daemon[594]: Got SIGTERM, quitting. Jul 18 06:39:45 volumio systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Jul 18 06:39:45 volumio avahi-daemon[594]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.88. Jul 18 06:39:45 volumio avahi-daemon[594]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.1.245. Jul 18 06:39:45 volumio avahi-daemon[594]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Jul 18 06:39:45 volumio avahi-daemon[594]: avahi-daemon 0.8 exiting. Jul 18 06:39:45 volumio systemd[1]: avahi-daemon.service: Deactivated successfully. Jul 18 06:39:45 volumio systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Jul 18 06:39:45 volumio systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Jul 18 06:39:45 volumio avahi-daemon[1211]: Process 594 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) Jul 18 06:39:45 volumio avahi-daemon[1211]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Jul 18 06:39:45 volumio avahi-daemon[1211]: Successfully dropped root privileges. Jul 18 06:39:46 volumio avahi-daemon[1211]: avahi-daemon 0.8 starting up. Jul 18 06:39:46 volumio systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Jul 18 06:39:46 volumio avahi-daemon[1211]: Successfully called chroot(). Jul 18 06:39:46 volumio avahi-daemon[1211]: Successfully dropped remaining capabilities. Jul 18 06:39:46 volumio avahi-daemon[1211]: No service file found in /etc/avahi/services. Jul 18 06:39:46 volumio avahi-daemon[1211]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.88. Jul 18 06:39:46 volumio avahi-daemon[1211]: New relevant interface wlan0.IPv4 for mDNS. Jul 18 06:39:46 volumio avahi-daemon[1211]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.245. Jul 18 06:39:46 volumio avahi-daemon[1211]: New relevant interface eth0.IPv4 for mDNS. Jul 18 06:39:46 volumio avahi-daemon[1211]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Jul 18 06:39:46 volumio avahi-daemon[1211]: New relevant interface lo.IPv4 for mDNS. Jul 18 06:39:46 volumio avahi-daemon[1211]: Network interface enumeration completed. Jul 18 06:39:46 volumio avahi-daemon[1211]: Registering new address record for 192.168.1.88 on wlan0.IPv4. Jul 18 06:39:46 volumio avahi-daemon[1211]: Registering new address record for 192.168.1.245 on eth0.IPv4. Jul 18 06:39:46 volumio avahi-daemon[1211]: Registering new address record for 127.0.0.1 on lo.IPv4. Jul 18 06:39:46 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jul 18 06:39:46 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jul 18 06:39:46 volumio systemd[1]: Started wireless.service - Wireless Services. Jul 18 06:39:46 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jul 18 06:39:46 volumio systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... Jul 18 06:39:46 volumio systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker. Jul 18 06:39:46 volumio systemd[1]: Received SIGRTMIN+21 from PID 207 (plymouthd). Jul 18 06:39:46 volumio systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. Jul 18 06:39:46 volumio systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. Jul 18 06:39:46 volumio systemd[1]: Received SIGRTMIN+21 from PID 207 (n/a). Jul 18 06:39:46 volumio systemd[1]: Started getty@tty1.service - Getty on tty1. Jul 18 06:39:46 volumio systemd[1]: Reached target getty.target - Login Prompts. Jul 18 06:39:46 volumio systemd[1]: Reached target multi-user.target - Multi-User System. Jul 18 06:39:46 volumio systemd[1]: Reached target graphical.target - Graphical Interface. Jul 18 06:39:46 volumio systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Jul 18 06:39:46 volumio volumio-cpu-tweak[1231]: Setting RT Priority for mpd Jul 18 06:39:46 volumio volumio-cpu-tweak[1231]: Setting MPD Affinity Jul 18 06:39:46 volumio volumio-cpu-tweak[1249]: pid 893's current affinity mask: f Jul 18 06:39:46 volumio volumio-cpu-tweak[1249]: pid 893's new affinity mask: 3 Jul 18 06:39:46 volumio volumio-cpu-tweak[1231]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Jul 18 06:39:46 volumio volumio-cpu-tweak[1231]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Jul 18 06:39:46 volumio systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Jul 18 06:39:46 volumio systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Jul 18 06:39:46 volumio systemd[1]: Startup finished in 16.124s (kernel) + 27.637s (userspace) = 43.761s. Jul 18 06:39:46 volumio systemd[1]: volumio_cpu_tweak.service: Deactivated successfully. Jul 18 06:39:46 volumio ntpd[807]: IO: Listen normally on 4 wlan0 192.168.1.88:123 Jul 18 06:39:46 volumio ntpd[807]: IO: new interface(s) found: waking up resolver Jul 18 06:39:46 volumio ntpd[807]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Jul 18 06:39:46 volumio ntpd[807]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Jul 18 06:39:46 volumio ntpd[807]: DNS: Pool skipping: 93.94.88.51 Jul 18 06:39:46 volumio ntpd[807]: DNS: Pool skipping: 129.152.16.145 Jul 18 06:39:46 volumio ntpd[807]: DNS: Pool skipping: 37.247.53.178 Jul 18 06:39:46 volumio ntpd[807]: DNS: Pool skipping: 162.159.200.123 Jul 18 06:39:46 volumio ntpd[807]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Jul 18 06:39:46 volumio avahi-daemon[1211]: Server startup complete. Host name is volumio.local. Local service cookie is 150710912. Jul 18 06:39:47 volumio volumio-remote-updater[618]: [2025-07-18 06:39:47] [info] asio async_connect error: asio.system:111 (Connection refused) Jul 18 06:39:47 volumio volumio-remote-updater[618]: [2025-07-18 06:39:47] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Jul 18 06:39:47 volumio volumio-remote-updater[618]: [2025-07-18 06:39:47] [error] handle_connect error: Connection refused Jul 18 06:39:47 volumio ntpd[807]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Jul 18 06:39:47 volumio ntpd[807]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Jul 18 06:39:47 volumio ntpd[807]: DNS: Pool skipping: 89.46.74.148 Jul 18 06:39:47 volumio ntpd[807]: DNS: Pool skipping: 81.56.230.156 Jul 18 06:39:47 volumio ntpd[807]: DNS: Pool skipping: 212.6.50.243 Jul 18 06:39:47 volumio ntpd[807]: DNS: Pool skipping: 151.22.209.90 Jul 18 06:39:47 volumio ntpd[807]: DNS: Pool skipping: 2a00:6d41:10:1194::5 Jul 18 06:39:47 volumio ntpd[807]: DNS: Pool skipping: 2a00:6d41:10:1194::4 Jul 18 06:39:47 volumio ntpd[807]: DNS: Pool skipping: 2a07:7e81:7140:0:7a9a:18ff:fec7:9d36 Jul 18 06:39:47 volumio ntpd[807]: DNS: Pool skipping: 2a00:6d41:200:2::14 Jul 18 06:39:47 volumio ntpd[807]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Jul 18 06:39:48 volumio ntpd[807]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Jul 18 06:39:48 volumio ntpd[807]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Jul 18 06:39:48 volumio ntpd[807]: DNS: Pool skipping: 195.32.70.195 Jul 18 06:39:48 volumio ntpd[807]: DNS: Pool skipping: 217.61.62.224 Jul 18 06:39:48 volumio ntpd[807]: DNS: Pool skipping: 129.152.16.145 Jul 18 06:39:48 volumio ntpd[807]: DNS: Pool skipping: 89.46.74.148 Jul 18 06:39:48 volumio ntpd[807]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Jul 18 06:39:49 volumio ntpd[807]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Jul 18 06:39:49 volumio ntpd[807]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Jul 18 06:39:49 volumio ntpd[807]: DNS: Pool skipping: 195.32.70.195 Jul 18 06:39:49 volumio ntpd[807]: DNS: Pool skipping: 85.199.214.99 Jul 18 06:39:49 volumio ntpd[807]: DNS: Pool skipping: 93.94.88.50 Jul 18 06:39:49 volumio ntpd[807]: DNS: Pool skipping: 95.110.135.141 Jul 18 06:39:49 volumio ntpd[807]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Jul 18 06:39:49 volumio volumio[1216]: info: ------------------------------------------- Jul 18 06:39:49 volumio volumio[1216]: info: ----- Volumio3 ---- Jul 18 06:39:49 volumio volumio[1216]: info: ------------------------------------------- Jul 18 06:39:49 volumio volumio[1216]: info: ----- System startup ---- Jul 18 06:39:49 volumio volumio[1216]: info: ------------------------------------------- Jul 18 06:39:50 volumio volumio[1216]: info: MYVOLUMIO Environment detected Jul 18 06:39:51 volumio volumio[1216]: info: Plugin folders cleanup Jul 18 06:39:51 volumio volumio[1216]: info: Scanning into folder /volumio/app/plugins/ Jul 18 06:39:51 volumio volumio[1216]: info: Scanning category audio_interface Jul 18 06:39:51 volumio volumio[1216]: info: Scanning category miscellanea Jul 18 06:39:51 volumio volumio[1216]: info: Scanning category music_service Jul 18 06:39:51 volumio volumio[1216]: info: Scanning category plugins.json Jul 18 06:39:51 volumio volumio[1216]: info: Scanning category system_controller Jul 18 06:39:51 volumio volumio[1216]: info: Scanning category user_interface Jul 18 06:39:51 volumio volumio[1216]: info: Scanning into folder /data/plugins/ Jul 18 06:39:51 volumio volumio[1216]: info: Scanning category music_service Jul 18 06:39:51 volumio volumio[1216]: info: Scanning category user_interface Jul 18 06:39:51 volumio volumio[1216]: info: Plugin folders cleanup completed Jul 18 06:39:51 volumio volumio[1216]: info: ------------------------------------------- Jul 18 06:39:51 volumio volumio[1216]: info: ----- Core plugins startup ---- Jul 18 06:39:51 volumio volumio[1216]: info: ------------------------------------------- Jul 18 06:39:51 volumio volumio[1216]: info: Loading plugins from folder /volumio/app/plugins/ Jul 18 06:39:51 volumio volumio[1216]: info: Adding plugin upnp to MyMusic Plugins Jul 18 06:39:51 volumio volumio[1216]: info: Adding plugin airplay_emulation to MyMusic Plugins Jul 18 06:39:51 volumio volumio[1216]: info: Adding plugin upnp_browser to MyMusic Plugins Jul 18 06:39:51 volumio volumio[1216]: info: Loading plugins from folder /data/plugins/ Jul 18 06:39:51 volumio volumio[1216]: info: Loading plugin "system"... Jul 18 06:39:51 volumio volumio[1216]: info: Loading plugin "appearance"... Jul 18 06:39:52 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully. Jul 18 06:39:53 volumio volumio[1216]: info: Loading plugin "network"... Jul 18 06:39:53 volumio volumio[1216]: info: Refreshing Cached IP Addresses Jul 18 06:39:53 volumio sudo[1271]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 18 06:39:53 volumio sudo[1271]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:39:53 volumio sudo[1271]: pam_unix(sudo:session): session closed for user root Jul 18 06:39:53 volumio volumio[1216]: info: Loading plugin "services"... Jul 18 06:39:53 volumio sudo[1273]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 18 06:39:53 volumio sudo[1273]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:39:53 volumio volumio[1216]: info: Loading plugin "alsa_controller"... Jul 18 06:39:53 volumio sudo[1273]: pam_unix(sudo:session): session closed for user root Jul 18 06:39:53 volumio sudo[1279]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jul 18 06:39:53 volumio sudo[1279]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:39:53 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 18 06:39:53 volumio volumio[1216]: info: Loading plugin "wizard"... Jul 18 06:39:53 volumio volumio[1216]: info: Loading plugin "networkfs"... Jul 18 06:39:53 volumio volumio[1216]: info: Starting Udev Watcher for removable devices Jul 18 06:39:53 volumio sudo[1307]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Volumio,password=69volumio69,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.125/Music /mnt/NAS/Volumio Jul 18 06:39:53 volumio sudo[1307]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:39:53 volumio volumio[1216]: info: Ignoring mount for partition: boot Jul 18 06:39:53 volumio volumio[1216]: info: Ignoring mount for partition: volumio Jul 18 06:39:53 volumio volumio[1216]: info: Ignoring mount for partition: volumio_data Jul 18 06:39:53 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 18 06:39:53 volumio volumio[1216]: info: Loading plugin "volumio_command_line_client"... Jul 18 06:39:53 volumio volumio[1216]: info: Loading plugin "upnp"... Jul 18 06:39:53 volumio volumio[1216]: info: [1752813593357] Starting Upmpd Daemon Jul 18 06:39:53 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 18 06:39:53 volumio volumio[1216]: info: Loading plugin "my_music"... Jul 18 06:39:53 volumio volumio[1216]: info: Loading plugin "mpd"... Jul 18 06:39:53 volumio kernel: netfs: FS-Cache loaded Jul 18 06:39:53 volumio kernel: Key type cifs.spnego registered Jul 18 06:39:53 volumio kernel: Key type cifs.idmap registered Jul 18 06:39:53 volumio kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Jul 18 06:39:53 volumio kernel: CIFS: Attempting to mount //192.168.1.125/Music Jul 18 06:39:54 volumio sudo[1307]: pam_unix(sudo:session): session closed for user root Jul 18 06:39:54 volumio sudo[1279]: pam_unix(sudo:session): session closed for user root Jul 18 06:39:54 volumio volumio[1216]: info: Loading plugin "upnp_browser"... Jul 18 06:39:55 volumio volumio[1216]: info: Loading plugin "alarm-clock"... Jul 18 06:39:56 volumio volumio[1216]: info: Loading plugin "airplay_emulation"... Jul 18 06:39:56 volumio volumio[1216]: info: Starting Shairport Sync Jul 18 06:39:56 volumio volumio[1216]: info: Loading plugin "last_100"... Jul 18 06:39:56 volumio volumio[1216]: info: Loading plugin "webradio"... Jul 18 06:39:56 volumio volumio[1216]: info: Loading plugin "i2s_dacs"... Jul 18 06:39:56 volumio volumio[1216]: info: Loading plugin "volumiodiscovery"... Jul 18 06:39:56 volumio volumio[1216]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 18 06:39:56 volumio volumio[1216]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 18 06:39:56 volumio volumio[1216]: *** WARNING *** For more information see Jul 18 06:39:56 volumio volumio[1216]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 18 06:39:56 volumio volumio[1216]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 18 06:39:56 volumio volumio[1216]: *** WARNING *** For more information see Jul 18 06:39:56 volumio node[1216]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 18 06:39:56 volumio node[1216]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 18 06:39:56 volumio node[1216]: *** WARNING *** For more information see Jul 18 06:39:56 volumio node[1216]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 18 06:39:56 volumio node[1216]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 18 06:39:56 volumio node[1216]: *** WARNING *** For more information see Jul 18 06:39:56 volumio volumio[1216]: info: Applying required configuration parameters for plugin volumiodiscovery Jul 18 06:39:56 volumio volumio[1216]: info: Discovery: Started advertising with name: Volumio Jul 18 06:39:56 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 18 06:39:56 volumio volumio[1216]: info: Loading plugin "youtube2"... Jul 18 06:39:57 volumio volumio-remote-updater[618]: [2025-07-18 06:39:57] [connect] Successful connection Jul 18 06:39:58 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully. Jul 18 06:40:00 volumio volumio[1216]: info: Loading plugin "ytmusic"... Jul 18 06:40:03 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. Jul 18 06:40:04 volumio volumio[1216]: info: Loading plugin "now_playing"... Jul 18 06:40:07 volumio volumio[1216]: info: Loading plugin "outputs"... Jul 18 06:40:07 volumio volumio[1216]: info: Loading plugin "albumart"... Jul 18 06:40:07 volumio volumio[1216]: info: Plugin example_plugin is not enabled Jul 18 06:40:07 volumio volumio[1216]: info: Loading plugin "inputs"... Jul 18 06:40:07 volumio volumio[1216]: info: Loading plugin "updater_comm"... Jul 18 06:40:07 volumio volumio[1216]: info: Plugin mpdemulation is not enabled Jul 18 06:40:07 volumio volumio[1216]: info: Loading plugin "rest_api"... Jul 18 06:40:07 volumio volumio[1216]: info: Loading plugin "websocket"... Jul 18 06:40:07 volumio volumio[1216]: info: Starting Socket.io Server version 1.7.4 Jul 18 06:40:07 volumio volumio[1216]: info: Loading plugin "Systeminfo"... Jul 18 06:40:08 volumio volumio[1367]: Forking 3 albumart workers Jul 18 06:40:08 volumio volumio[1216]: info: Loading i18n strings for locale it Jul 18 06:40:08 volumio volumio[1216]: Updating browse sources language Jul 18 06:40:08 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 06:40:09 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 18 06:40:09 volumio volumio[1216]: info: CoreCommandRouter::initPlayerControls Jul 18 06:40:09 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:09 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:09 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:09 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:09 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:09 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:09 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:09 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:09 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 18 06:40:09 volumio volumio[1216]: Express server listening on port 3000 Jul 18 06:40:09 volumio volumio[1216]: [Metrics] WebUI: 21s 154.37ms Jul 18 06:40:10 volumio volumio[1216]: info: CoreStateMachine::resetVolumioState Jul 18 06:40:10 volumio volumio[1216]: info: CoreStateMachine::getcurrentVolume Jul 18 06:40:10 volumio volumio[1216]: info: CoreCommandRouter::volumioRetrievevolume Jul 18 06:40:10 volumio sudo[1412]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 18 06:40:10 volumio sudo[1412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:40:10 volumio sudo[1412]: pam_unix(sudo:session): session closed for user root Jul 18 06:40:10 volumio sudo[1414]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 18 06:40:10 volumio sudo[1414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:40:10 volumio sudo[1414]: pam_unix(sudo:session): session closed for user root Jul 18 06:40:10 volumio volumio[1216]: info: Volumio Network Manager: Network status updated: 3 Jul 18 06:40:10 volumio volumio[1216]: info: VolumeController:: Volume=91 Mute =false Jul 18 06:40:10 volumio volumio[1216]: info: CoreStateMachine::pushState Jul 18 06:40:10 volumio volumio[1216]: info: CorePlayQueue::getTrack 0 Jul 18 06:40:10 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 06:40:10 volumio volumio[1216]: info: CoreCommandRouter::volumioPushState Jul 18 06:40:10 volumio volumio[1216]: info: CoreStateMachine::updateTrackBlock Jul 18 06:40:10 volumio volumio[1216]: info: CorePlayQueue::getTrackBlock Jul 18 06:40:10 volumio volumio[1216]: info: CoreCommandRouter::volumioRetrievevolume Jul 18 06:40:11 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 06:40:11 volumio volumio[1216]: info: Reloading queue from file Jul 18 06:40:11 volumio volumio[1216]: info: CoreStateMachine::setRepeat null single undefined Jul 18 06:40:11 volumio volumio[1216]: info: CoreStateMachine::pushState Jul 18 06:40:11 volumio volumio[1216]: info: CorePlayQueue::getTrack 0 Jul 18 06:40:11 volumio volumio[1216]: info: CoreCommandRouter::volumioPushState Jul 18 06:40:11 volumio volumio[1216]: info: CoreStateMachine::setRandom null Jul 18 06:40:11 volumio volumio[1216]: info: CoreStateMachine::pushState Jul 18 06:40:11 volumio volumio[1216]: info: CorePlayQueue::getTrack 0 Jul 18 06:40:11 volumio volumio[1216]: info: CoreCommandRouter::volumioPushState Jul 18 06:40:11 volumio volumio[1216]: info: Setting Device type: Raspberry PI Jul 18 06:40:11 volumio volumio[1216]: info: Completed loading Core Plugins Jul 18 06:40:11 volumio volumio[1216]: info: Preparing to generate the ALSA configuration file Jul 18 06:40:11 volumio volumio[1216]: info: VolumeController:: Volume=91 Mute =false Jul 18 06:40:11 volumio volumio[1216]: info: CoreStateMachine::pushState Jul 18 06:40:11 volumio volumio[1216]: info: CorePlayQueue::getTrack 0 Jul 18 06:40:11 volumio volumio[1216]: info: CoreCommandRouter::volumioPushState Jul 18 06:40:11 volumio volumio[1216]: info: Discovery: adding 5721fb05-0f51-4225-a7c5-39fd8d05dda5 Jul 18 06:40:11 volumio sudo[1431]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jul 18 06:40:11 volumio sudo[1431]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:40:11 volumio volumio[1216]: info: Discovery: Found device Volumio Jul 18 06:40:11 volumio volumio[1216]: info: CoreCommandRouter::volumioGetState Jul 18 06:40:11 volumio volumio[1216]: info: CorePlayQueue::getTrack 0 Jul 18 06:40:11 volumio volumio[1216]: info: Asound.conf file unchanged, so no further update is needed Jul 18 06:40:11 volumio volumio[1216]: info: Output device has changed, restarting MPD Jul 18 06:40:11 volumio volumio[1216]: info: Output device has changed, restarting Shairport Sync Jul 18 06:40:11 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:11 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 06:40:11 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jul 18 06:40:11 volumio sudo[1431]: pam_unix(sudo:session): session closed for user root Jul 18 06:40:11 volumio sudo[1434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 18 06:40:11 volumio sudo[1434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:40:11 volumio sudo[1434]: pam_unix(sudo:session): session closed for user root Jul 18 06:40:12 volumio sudo[1437]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 18 06:40:12 volumio volumio[1216]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 18 06:40:12 volumio sudo[1437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:40:12 volumio volumio[1216]: info: ___________ START PLUGINS ___________ Jul 18 06:40:12 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jul 18 06:40:12 volumio volumio[1216]: info: ControllerMpd::onStart: Initializing MPD Jul 18 06:40:12 volumio volumio[1216]: info: Creating MPD Configuration file Jul 18 06:40:12 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 18 06:40:12 volumio volumio[1216]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 18 06:40:12 volumio volumio[1216]: info: [1752813612280] CoreMusicLibrary::Adding element Server multimediali Jul 18 06:40:12 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 06:40:12 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:12 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 06:40:12 volumio sudo[1455]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 18 06:40:12 volumio sudo[1455]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:40:12 volumio sudo[1455]: pam_unix(sudo:session): session closed for user root Jul 18 06:40:12 volumio volumio[1216]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 18 06:40:12 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:12 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 06:40:12 volumio sudo[1457]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 18 06:40:12 volumio sudo[1457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:40:12 volumio volumio-remote-updater[618]: [2025-07-18 06:40:12] [connect] Successful connection Jul 18 06:40:12 volumio volumio[1216]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 18 06:40:12 volumio volumio[1216]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 18 06:40:12 volumio volumio[1216]: info: [1752813612470] CoreMusicLibrary::Adding element Last_100 Jul 18 06:40:12 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 06:40:12 volumio volumio[1216]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 18 06:40:12 volumio volumio[1216]: info: [1752813612491] CoreMusicLibrary::Adding element Webradio Jul 18 06:40:12 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 06:40:12 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 18 06:40:12 volumio volumio[1216]: info: Initializing BBC Radios Jul 18 06:40:12 volumio systemd[1]: mpd.service: Deactivated successfully. Jul 18 06:40:12 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jul 18 06:40:12 volumio systemd[1]: mpd.service: Consumed 6.453s CPU time. Jul 18 06:40:12 volumio systemd[1]: mpd.socket: Deactivated successfully. Jul 18 06:40:12 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jul 18 06:40:12 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jul 18 06:40:12 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jul 18 06:40:12 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jul 18 06:40:12 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 18 06:40:12 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 06:40:12 volumio volumio[1216]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 18 06:40:12 volumio sudo[1477]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 18 06:40:12 volumio sudo[1477]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jul 18 06:40:12 volumio volumio[1216]: info: [1752813612873] CoreMusicLibrary::Adding element YouTube2 Jul 18 06:40:12 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 06:40:12 volumio volumio[1216]: Cannot find translation for source YouTube2 Jul 18 06:40:12 volumio sudo[1477]: pam_unix(sudo:session): session closed for user root Jul 18 06:40:12 volumio volumio[1377]: Starting albumart workers Jul 18 06:40:12 volumio volumio[1216]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 18 06:40:12 volumio volumio[1216]: info: [1752813612921] CoreMusicLibrary::Adding element YouTube Music Jul 18 06:40:12 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 06:40:12 volumio volumio[1216]: Cannot find translation for source YouTube2 Jul 18 06:40:12 volumio volumio[1216]: Cannot find translation for source YouTube Music Jul 18 06:40:12 volumio volumio[1379]: Starting albumart workers Jul 18 06:40:13 volumio volumio[1216]: info: [now-playing] ConfigUpdater: config is up to date. Jul 18 06:40:13 volumio volumio[1216]: info: Volumio Calling Home Jul 18 06:40:14 volumio volumio[1378]: Starting albumart workers Jul 18 06:40:16 volumio mpd[1484]: 2025-07-18T06:40:16 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 18 06:40:16 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jul 18 06:40:16 volumio volumio[1216]: info: [now-playing] App is listening on port 4004. Jul 18 06:40:16 volumio sudo[1437]: pam_unix(sudo:session): session closed for user root Jul 18 06:40:16 volumio sudo[1457]: pam_unix(sudo:session): session closed for user root Jul 18 06:40:16 volumio volumio[1216]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Jul 18 06:40:16 volumio volumio[1216]: info: Discovery: this is already registered, 5721fb05-0f51-4225-a7c5-39fd8d05dda5 Jul 18 06:40:16 volumio volumio[1216]: info: Discovery: Found device Volumio Jul 18 06:40:16 volumio volumio[1216]: info: CoreCommandRouter::volumioGetState Jul 18 06:40:16 volumio volumio[1216]: info: CorePlayQueue::getTrack 0 Jul 18 06:40:16 volumio volumio[1216]: info: Discovery: this is already registered, 5721fb05-0f51-4225-a7c5-39fd8d05dda5 Jul 18 06:40:16 volumio volumio[1216]: info: Discovery: Found device Volumio Jul 18 06:40:16 volumio volumio[1216]: info: CoreCommandRouter::volumioGetState Jul 18 06:40:16 volumio volumio[1216]: info: CorePlayQueue::getTrack 0 Jul 18 06:40:16 volumio volumio[1216]: info: Completed starting Core Plugins Jul 18 06:40:16 volumio volumio[1216]: info: ------------------------------------------- Jul 18 06:40:16 volumio volumio[1216]: info: ----- MyVolumio plugins startup ---- Jul 18 06:40:16 volumio volumio[1216]: info: ------------------------------------------- Jul 18 06:40:16 volumio volumio[1216]: info: [MyVolumio PluginManager] Fetching plans data.... Jul 18 06:40:16 volumio volumio[1216]: info: MPD Permissions set Jul 18 06:40:16 volumio volumio[1216]: info: MPD Permissions set Jul 18 06:40:16 volumio volumio[1216]: info: Upmpdcli Daemon Started Jul 18 06:40:16 volumio volumio-remote-updater[618]: [2025-07-18 06:40:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1752813612 101 Jul 18 06:40:16 volumio volumio[1216]: 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 Jul 18 06:40:16 volumio volumio[1216]: info: Volumio called home Jul 18 06:40:17 volumio volumio[1216]: error: MPD error: The expression evaluated to a falsy value: Jul 18 06:40:17 volumio volumio[1216]: assert.ok(self.idling) Jul 18 06:40:17 volumio volumio[1216]: error: The expression evaluated to a falsy value: Jul 18 06:40:17 volumio volumio[1216]: assert.ok(self.idling) Jul 18 06:40:17 volumio volumio[1216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jul 18 06:40:17 volumio volumio[1216]: info: MPD running with PID1484 Jul 18 06:40:17 volumio volumio[1216]: ,establishing connection Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:17 volumio volumio[1216]: error: updateQueue error: null Jul 18 06:40:18 volumio volumio[1216]: error: updateQueue error: null Jul 18 06:40:18 volumio volumio[1216]: info: Starting Shairport Sync Jul 18 06:40:18 volumio volumio[1216]: info: Starting Shairport Sync Jul 18 06:40:18 volumio sudo[1541]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 18 06:40:18 volumio sudo[1541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:40:18 volumio volumio[1216]: info: Starting Shairport Sync Jul 18 06:40:18 volumio sudo[1543]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 18 06:40:18 volumio sudo[1543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:40:18 volumio sudo[1546]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 18 06:40:18 volumio sudo[1546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:40:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jul 18 06:40:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jul 18 06:40:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jul 18 06:40:18 volumio systemd[1]: shairport-sync.service: Consumed 1.829s CPU time. Jul 18 06:40:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jul 18 06:40:18 volumio sudo[1541]: pam_unix(sudo:session): session closed for user root Jul 18 06:40:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jul 18 06:40:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jul 18 06:40:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jul 18 06:40:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jul 18 06:40:18 volumio sudo[1546]: pam_unix(sudo:session): session closed for user root Jul 18 06:40:18 volumio sudo[1543]: pam_unix(sudo:session): session closed for user root Jul 18 06:40:18 volumio volumio[1216]: info: Shairport-Sync Started Jul 18 06:40:18 volumio volumio[1216]: Error adding Membership: Error: addMembership EINVAL Jul 18 06:40:18 volumio volumio[1216]: info: Shairport-Sync Started Jul 18 06:40:18 volumio volumio[1216]: info: Shairport-Sync Started Jul 18 06:40:18 volumio volumio[1216]: info: CoreCommandRouter::volumioGetState Jul 18 06:40:18 volumio volumio[1216]: info: CorePlayQueue::getTrack 0 Jul 18 06:40:21 volumio volumio[1216]: error: error Jul 18 06:40:21 volumio volumio[1216]: error: error Jul 18 06:40:22 volumio volumio[1216]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jul 18 06:40:35 volumio volumio[1216]: Cannot compose Albumart path Jul 18 06:40:36 volumio volumio[1216]: error: MyVolumio Plugin failed to start in a timely fashion Jul 18 06:40:36 volumio volumio[1216]: [Metrics] CommandRouter: 47s 201.90ms Jul 18 06:40:36 volumio volumio[1216]: info: CoreCommandRouter::volumiosetStartupVolume Jul 18 06:40:36 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 06:40:36 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 06:40:36 volumio volumio[1216]: info: CoreCommandRouter::Close All Modals sent Jul 18 06:40:37 volumio volumio[1216]: info: CoreCommandRouter::Close All Modals sent Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jul 18 06:40:37 volumio volumio[1216]: info: Adding plugin bluetooth to MyMusic Plugins Jul 18 06:40:37 volumio volumio[1216]: info: Adding plugin multiroom to MyMusic Plugins Jul 18 06:40:37 volumio volumio[1216]: info: Adding plugin metavolumio to MyMusic Plugins Jul 18 06:40:37 volumio volumio[1216]: info: Adding plugin cd_controller to MyMusic Plugins Jul 18 06:40:37 volumio volumio[1216]: info: Adding plugin qobuzconnect to MyMusic Plugins Jul 18 06:40:37 volumio volumio[1216]: info: Adding plugin smart_inputs to MyMusic Plugins Jul 18 06:40:37 volumio volumio[1216]: info: Adding plugin tidalconnect to MyMusic Plugins Jul 18 06:40:37 volumio volumio[1216]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jul 18 06:40:42 volumio volumio[1216]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jul 18 06:40:42 volumio volumio[1216]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jul 18 06:40:42 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 06:40:42 volumio volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 06:40:42 volumio volumio[1216]: info: Starting MyVolumio Remote Streaming Endpoints Jul 18 06:40:42 volumio volumio[1216]: info: MyVolumio login type: Token Jul 18 06:40:42 volumio volumio[1216]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jul 18 06:40:42 volumio volumio[1216]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jul 18 06:40:43 volumio volumio[1216]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jul 18 06:40:43 volumio volumio[1216]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jul 18 06:40:43 volumio volumio[1216]: info: Streaming services startup Jul 18 06:40:43 volumio volumio[1216]: info: Starting Streaming Daemon Jul 18 06:40:44 volumio volumio[1216]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jul 18 06:40:44 volumio sudo[1612]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jul 18 06:40:44 volumio sudo[1612]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 18 06:40:44 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jul 18 06:40:44 volumio sudo[1612]: pam_unix(sudo:session): session closed for user root Jul 18 06:40:44 volumio volumio[1216]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 18 06:40:44 volumio dbus-daemon[599]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.22' (uid=0 pid=1626 comm="timedatectl show --property=NTPSynchronized --valu") Jul 18 06:40:44 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jul 18 06:40:44 volumio volumio[1216]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals. Jul 18 06:40:44 volumio volumio[1216]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues Jul 18 06:40:44 volumio volumio[1216]: at new NodeError (node:internal/errors:405:5) Jul 18 06:40:44 volumio volumio[1216]: at assert (node:internal/assert:14:11) Jul 18 06:40:44 volumio volumio[1216]: at internalConnectMultiple (node:net:1118:3) Jul 18 06:40:44 volumio volumio[1216]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3) Jul 18 06:40:44 volumio volumio[1216]: at listOnTimeout (node:internal/timers:575:11) Jul 18 06:40:44 volumio volumio[1216]: at process.processTimers (node:internal/timers:514:7) { Jul 18 06:40:44 volumio volumio[1216]: code: 'ERR_INTERNAL_ASSERTION' Jul 18 06:40:44 volumio volumio[1216]: } Jul 18 06:40:44 volumio volumio[1216]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 18 06:40:44 volumio dbus-daemon[599]: [system] Successfully activated service 'org.freedesktop.timedate1' Jul 18 06:40:44 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. Jul 18 06:40:44 volumio setdatetime-helper.sh[1625]: Time is already synchronized. Jul 18 06:40:44 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jul 18 06:40:44 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jul 18 06:40:48 volumio sudo[1643]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-07-18 06:39' Jul 18 06:40:48 volumio sudo[1643]: 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="30967a3eaa5e867c9c73ed66f5e07b238b646dd7" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="c82d2341a3a7e284141656a9703a39c694911dfd" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Jul 12 07:39:31 UTC 2025" VOLUMIO_VERSION="4.016" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5b26578fd35198fc4430a2f6138ca1e3"