Oct 16 15:08:35 volumio4 systemd[1]: setdatetime-helper.service: Deactivated successfully. Oct 16 15:08:35 volumio4 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Oct 16 15:08:35 volumio4 sudo[1403]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 15:08:35 volumio4 sudo[1403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 16 15:08:35 volumio4 sudo[1403]: pam_unix(sudo:session): session closed for user root Oct 16 15:08:35 volumio4 wireless.js[795]: WIRELESS.JS - INFO: ... wlan0 IPv4 is 192.168.0.5, ipV6 is undefined Oct 16 15:08:35 volumio4 wireless.js[795]: WIRELESS.JS - INFO: Connected to SSID: Arwenator Oct 16 15:08:35 volumio4 wireless.js[795]: WIRELESS.JS - INFO: It's done! AP Oct 16 15:08:35 volumio4 wireless.js[795]: WIRELESS.JS - INFO: Restarting avahi-daemon... Oct 16 15:08:35 volumio4 sudo[1414]: root : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart avahi-daemon Oct 16 15:08:35 volumio4 sudo[1414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 16 15:08:35 volumio4 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 16 15:08:35 volumio4 systemd[1]: shairport-sync.service: Deactivated successfully. Oct 16 15:08:35 volumio4 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 15:08:35 volumio4 systemd[1]: shairport-sync.service: Consumed 1.605s CPU time. Oct 16 15:08:35 volumio4 systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Oct 16 15:08:35 volumio4 nmbd[1130]: [2026/10/16 15:08:35.142791, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Oct 16 15:08:35 volumio4 nmbd[1130]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.0.5 for name WORKGROUP<1d>. Oct 16 15:08:35 volumio4 nmbd[1130]: This response was from IP 192.168.0.109, reporting an IP address of 192.168.0.109. Oct 16 15:08:35 volumio4 avahi-daemon[776]: Got SIGTERM, quitting. Oct 16 15:08:35 volumio4 avahi-daemon[776]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.5. Oct 16 15:08:35 volumio4 avahi-daemon[776]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Oct 16 15:08:35 volumio4 avahi-daemon[776]: avahi-daemon 0.8 exiting. Oct 16 15:08:35 volumio4 systemd[1]: avahi-daemon.service: Deactivated successfully. Oct 16 15:08:35 volumio4 systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Oct 16 15:08:35 volumio4 systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Oct 16 15:08:35 volumio4 avahi-daemon[1417]: Process 776 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) Oct 16 15:08:35 volumio4 avahi-daemon[1417]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Oct 16 15:08:35 volumio4 ntpd[1064]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Oct 16 15:08:35 volumio4 ntpd[1064]: DNS: Pool taking: 193.70.94.182 Oct 16 15:08:35 volumio4 ntpd[1064]: DNS: Pool taking: 89.161.47.133 Oct 16 15:08:35 volumio4 ntpd[1064]: DNS: Pool taking: 162.159.200.123 Oct 16 15:08:35 volumio4 ntpd[1064]: DNS: Pool taking: 51.68.141.5 Oct 16 15:08:35 volumio4 ntpd[1064]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Oct 16 15:08:35 volumio4 avahi-daemon[1417]: Successfully dropped root privileges. Oct 16 15:08:35 volumio4 avahi-daemon[1417]: avahi-daemon 0.8 starting up. Oct 16 15:08:35 volumio4 avahi-daemon[1417]: Successfully called chroot(). Oct 16 15:08:35 volumio4 avahi-daemon[1417]: Successfully dropped remaining capabilities. Oct 16 15:08:35 volumio4 systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Oct 16 15:08:35 volumio4 avahi-daemon[1417]: Loading service file /services/volumio.service. Oct 16 15:08:35 volumio4 avahi-daemon[1417]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.5. Oct 16 15:08:35 volumio4 avahi-daemon[1417]: New relevant interface wlan0.IPv4 for mDNS. Oct 16 15:08:35 volumio4 avahi-daemon[1417]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Oct 16 15:08:35 volumio4 avahi-daemon[1417]: New relevant interface lo.IPv4 for mDNS. Oct 16 15:08:35 volumio4 avahi-daemon[1417]: Network interface enumeration completed. Oct 16 15:08:35 volumio4 avahi-daemon[1417]: Registering new address record for 192.168.0.5 on wlan0.IPv4. Oct 16 15:08:35 volumio4 avahi-daemon[1417]: Registering new address record for 127.0.0.1 on lo.IPv4. Oct 16 15:08:35 volumio4 sudo[1414]: pam_unix(sudo:session): session closed for user root Oct 16 15:08:35 volumio4 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 15:08:35 volumio4 wireless.js[795]: WIRELESS.JS - INFO: Notified systemd about wireless ready Oct 16 15:08:35 volumio4 winbindd[1389]: [2026/10/16 15:08:35.524362, 0] ../../source3/winbindd/winbindd.c:1440(main) Oct 16 15:08:35 volumio4 winbindd[1389]: winbindd version 4.17.8-Raspbian started. Oct 16 15:08:35 volumio4 winbindd[1389]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Oct 16 15:08:35 volumio4 python[1002]: System status: Temp 45°c, Disk space remaining 91%, IP address uid Oct 16 15:08:35 volumio4 winbindd[1389]: [2026/10/16 15:08:35.760523, 0] ../../source3/winbindd/winbindd_cache.c:3116(initialize_winbindd_cache) Oct 16 15:08:35 volumio4 winbindd[1389]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Oct 16 15:08:35 volumio4 systemd[1]: Started winbind.service - Samba Winbind Daemon. Oct 16 15:08:35 volumio4 systemd[1]: Starting smbd.service - Samba SMB Daemon... Oct 16 15:08:35 volumio4 ntpd[1064]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 16 15:08:36 volumio4 avahi-daemon[1417]: Server startup complete. Host name is volumio4.local. Local service cookie is 3210023232. Oct 16 15:08:36 volumio4 ntpd[1064]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Oct 16 15:08:36 volumio4 ntpd[1064]: DNS: Pool taking: 194.146.251.100 Oct 16 15:08:36 volumio4 ntpd[1064]: DNS: Pool skipping: 51.68.141.5 Oct 16 15:08:36 volumio4 ntpd[1064]: DNS: Pool taking: 77.252.226.67 Oct 16 15:08:36 volumio4 ntpd[1064]: DNS: Pool skipping: 162.159.200.123 Oct 16 15:08:36 volumio4 ntpd[1064]: DNS: Pool taking: 2a0d:5440::24 Oct 16 15:08:36 volumio4 ntpd[1064]: DNS: Pool taking: 2001:6a0:0:31::2 Oct 16 15:08:36 volumio4 ntpd[1064]: DNS: Pool taking: 2001:41d0:601:1100::649c Oct 16 15:08:36 volumio4 ntpd[1064]: DNS: Pool taking: 2001:41d0:601:1100::45d2 Oct 16 15:08:36 volumio4 ntpd[1064]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Oct 16 15:08:36 volumio4 smbd[1451]: [2026/10/16 15:08:36.666698, 0] ../../source3/smbd/server.c:1741(main) Oct 16 15:08:36 volumio4 smbd[1451]: smbd version 4.17.8-Raspbian started. Oct 16 15:08:36 volumio4 smbd[1451]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Oct 16 15:08:36 volumio4 systemd[1]: systemd-hostnamed.service: Deactivated successfully. Oct 16 15:08:36 volumio4 ntpd[1064]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 16 15:08:37 volumio4 avahi-daemon[1417]: Service "Volumio4" (/services/volumio.service) successfully established. Oct 16 15:08:37 volumio4 ntpd[1064]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Oct 16 15:08:37 volumio4 ntpd[1064]: DNS: Pool skipping: 193.70.94.182 Oct 16 15:08:37 volumio4 ntpd[1064]: DNS: Pool taking: 89.161.47.132 Oct 16 15:08:37 volumio4 ntpd[1064]: DNS: Pool taking: 156.17.245.123 Oct 16 15:08:37 volumio4 ntpd[1064]: DNS: Pool taking: 109.206.205.233 Oct 16 15:08:37 volumio4 ntpd[1064]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Oct 16 15:08:37 volumio4 volumio[1249]: info: MYVOLUMIO Environment detected Oct 16 15:08:37 volumio4 ntpd[1064]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 16 15:08:38 volumio4 ntpd[1064]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Oct 16 15:08:38 volumio4 ntpd[1064]: DNS: Pool taking: 195.46.37.22 Oct 16 15:08:38 volumio4 ntpd[1064]: DNS: Pool skipping: 89.161.47.132 Oct 16 15:08:38 volumio4 ntpd[1064]: DNS: Pool taking: 94.240.10.55 Oct 16 15:08:38 volumio4 ntpd[1064]: DNS: Pool taking: 83.168.69.149 Oct 16 15:08:38 volumio4 ntpd[1064]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Oct 16 15:08:38 volumio4 systemd[1]: Started smbd.service - Samba SMB Daemon. Oct 16 15:08:39 volumio4 volumio[1249]: info: Plugin folders cleanup Oct 16 15:08:39 volumio4 volumio[1249]: info: Scanning into folder /volumio/app/plugins/ Oct 16 15:08:39 volumio4 volumio[1249]: info: Scanning category audio_interface Oct 16 15:08:39 volumio4 volumio[1249]: info: Scanning category miscellanea Oct 16 15:08:39 volumio4 volumio[1249]: info: Scanning category music_service Oct 16 15:08:39 volumio4 volumio[1249]: info: Scanning category plugins.json Oct 16 15:08:39 volumio4 volumio[1249]: info: Scanning category system_controller Oct 16 15:08:39 volumio4 volumio[1249]: info: Scanning category user_interface Oct 16 15:08:39 volumio4 volumio[1249]: info: Scanning into folder /data/plugins/ Oct 16 15:08:39 volumio4 volumio[1249]: info: Scanning category music_service Oct 16 15:08:39 volumio4 volumio[1249]: info: Scanning category system_hardware Oct 16 15:08:39 volumio4 volumio[1249]: info: Plugin folders cleanup completed Oct 16 15:08:39 volumio4 volumio[1249]: info: ------------------------------------------- Oct 16 15:08:39 volumio4 volumio[1249]: info: ----- Core plugins startup ---- Oct 16 15:08:39 volumio4 volumio[1249]: info: ------------------------------------------- Oct 16 15:08:39 volumio4 volumio[1249]: info: Loading plugins from folder /volumio/app/plugins/ Oct 16 15:08:39 volumio4 volumio[1249]: info: Adding plugin upnp to MyMusic Plugins Oct 16 15:08:39 volumio4 volumio[1249]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 16 15:08:39 volumio4 volumio[1249]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 16 15:08:39 volumio4 volumio[1249]: info: Loading plugins from folder /data/plugins/ Oct 16 15:08:39 volumio4 volumio[1249]: info: Loading plugin "system"... Oct 16 15:08:39 volumio4 volumio[1249]: info: Loading plugin "appearance"... Oct 16 15:08:41 volumio4 ntpd[1064]: CLOCK: time stepped by 0.257974 Oct 16 15:08:41 volumio4 ntpd[1064]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Oct 16 15:08:42 volumio4 volumio[1249]: info: Loading plugin "network"... Oct 16 15:08:42 volumio4 volumio[1249]: info: Refreshing Cached IP Addresses Oct 16 15:08:42 volumio4 sudo[1486]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 15:08:42 volumio4 sudo[1486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:08:42 volumio4 sudo[1486]: pam_unix(sudo:session): session closed for user root Oct 16 15:08:42 volumio4 sudo[1487]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 15:08:42 volumio4 sudo[1487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:08:42 volumio4 volumio[1249]: info: Loading plugin "services"... Oct 16 15:08:42 volumio4 volumio[1249]: info: Loading plugin "volumio5onboarding"... Oct 16 15:08:42 volumio4 sudo[1487]: pam_unix(sudo:session): session closed for user root Oct 16 15:08:42 volumio4 volumio[1249]: info: Loading plugin "alsa_controller"... Oct 16 15:08:42 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 15:08:42 volumio4 volumio[1249]: info: Loading plugin "wizard"... Oct 16 15:08:42 volumio4 volumio[1249]: info: Loading plugin "networkfs"... Oct 16 15:08:42 volumio4 sudo[1500]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 16 15:08:42 volumio4 sudo[1500]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:08:42 volumio4 volumio[1249]: info: Starting Udev Watcher for removable devices Oct 16 15:08:42 volumio4 volumio[1249]: info: Ignoring mount for partition: boot Oct 16 15:08:42 volumio4 volumio[1249]: info: Ignoring mount for partition: volumio Oct 16 15:08:42 volumio4 volumio[1249]: info: Ignoring mount for partition: volumio_data Oct 16 15:08:42 volumio4 sudo[1516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,vers=2.1 //192.168.0.109/music\\muza /mnt/NAS/music Oct 16 15:08:42 volumio4 sudo[1516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:08:42 volumio4 kernel: netfs: FS-Cache loaded Oct 16 15:08:42 volumio4 volumio[1249]: info: Ignoring mount for partition: INTERNAL Oct 16 15:08:42 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 15:08:42 volumio4 volumio[1249]: info: Loading plugin "volumio_command_line_client"... Oct 16 15:08:42 volumio4 volumio[1249]: info: Loading plugin "upnp"... Oct 16 15:08:42 volumio4 volumio[1249]: info: [1792156122774] Starting Upmpd Daemon Oct 16 15:08:42 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 15:08:42 volumio4 volumio[1249]: info: Loading plugin "my_music"... Oct 16 15:08:42 volumio4 volumio[1249]: info: Loading plugin "mpd"... Oct 16 15:08:42 volumio4 kernel: Key type cifs.spnego registered Oct 16 15:08:42 volumio4 kernel: Key type cifs.idmap registered Oct 16 15:08:42 volumio4 kernel: CIFS: Attempting to mount //192.168.0.109/music/muza Oct 16 15:08:43 volumio4 volumio[1249]: info: Loading plugin "upnp_browser"... Oct 16 15:08:43 volumio4 sudo[1516]: pam_unix(sudo:session): session closed for user root Oct 16 15:08:44 volumio4 volumio[1249]: info: Starting UPNP Browser Oct 16 15:08:44 volumio4 volumio[1249]: info: Loading plugin "alarm-clock"... Oct 16 15:08:44 volumio4 volumio[1249]: info: Loading plugin "airplay_emulation"... Oct 16 15:08:44 volumio4 volumio[1249]: info: Starting Shairport Sync Oct 16 15:08:44 volumio4 volumio[1249]: info: Loading plugin "last_100"... Oct 16 15:08:44 volumio4 volumio[1249]: info: Loading plugin "webradio"... Oct 16 15:08:44 volumio4 volumio[1249]: info: Loading plugin "i2s_dacs"... Oct 16 15:08:44 volumio4 volumio[1249]: info: I2S DAC not set, start Auto-detection Oct 16 15:08:44 volumio4 volumio[1249]: info: Loading plugin "volumiodiscovery"... Oct 16 15:08:44 volumio4 volumio[1249]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 16 15:08:44 volumio4 volumio[1249]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 15:08:44 volumio4 volumio[1249]: *** WARNING *** For more information see Oct 16 15:08:44 volumio4 volumio[1249]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 16 15:08:44 volumio4 volumio[1249]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 15:08:44 volumio4 volumio[1249]: *** WARNING *** For more information see Oct 16 15:08:44 volumio4 node[1249]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 16 15:08:44 volumio4 node[1249]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 15:08:44 volumio4 node[1249]: *** WARNING *** For more information see Oct 16 15:08:44 volumio4 node[1249]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 16 15:08:44 volumio4 node[1249]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 15:08:44 volumio4 node[1249]: *** WARNING *** For more information see Oct 16 15:08:44 volumio4 volumio[1249]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 16 15:08:44 volumio4 volumio[1249]: info: Discovery: Started advertising with name: Volumio4 Oct 16 15:08:44 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 15:08:44 volumio4 volumio[1249]: info: Loading plugin "spop"... Oct 16 15:08:45 volumio4 volumio[1249]: info: Loading plugin "gpio-buttons"... Oct 16 15:08:46 volumio4 volumio[1249]: gpiox_arm32 V2.2.1 Oct 16 15:08:46 volumio4 sudo[1500]: pam_unix(sudo:session): session closed for user root Oct 16 15:08:46 volumio4 volumio[1249]: info: gpio-buttons - GPIO-Buttons initialized Oct 16 15:08:46 volumio4 volumio[1249]: info: Loading plugin "outputs"... Oct 16 15:08:46 volumio4 volumio[1249]: info: Loading plugin "albumart"... Oct 16 15:08:46 volumio4 volumio[1249]: info: Plugin example_plugin is not enabled Oct 16 15:08:46 volumio4 volumio[1249]: info: Loading plugin "inputs"... Oct 16 15:08:46 volumio4 volumio[1249]: info: Loading plugin "updater_comm"... Oct 16 15:08:46 volumio4 volumio[1249]: info: Plugin mpdemulation is not enabled Oct 16 15:08:46 volumio4 volumio[1249]: info: Loading plugin "rest_api"... Oct 16 15:08:46 volumio4 volumio[1249]: info: Loading plugin "websocket"... Oct 16 15:08:46 volumio4 volumio[1249]: info: Starting Socket.io Server version 1.7.4 Oct 16 15:08:46 volumio4 volumio[1249]: info: Loading plugin "gpio_control"... Oct 16 15:08:47 volumio4 volumio[1249]: gpiox_arm32 V2.2.1 Oct 16 15:08:47 volumio4 volumio[1550]: Forking 3 albumart workers Oct 16 15:08:48 volumio4 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Oct 16 15:08:48 volumio4 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Oct 16 15:08:48 volumio4 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Oct 16 15:08:49 volumio4 upmpdcli[1590]: Could not open config: /tmp/upmpdcli.conf Oct 16 15:08:49 volumio4 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Oct 16 15:08:49 volumio4 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Oct 16 15:08:49 volumio4 volumio[1249]: info: Applying required configuration parameters for plugin gpio_control Oct 16 15:08:49 volumio4 volumio[1249]: info: Loading plugin "rotaryencoder2"... Oct 16 15:08:50 volumio4 volumio-remote-updater[794]: [2026-10-16 15:08:50] [connect] Successful connection Oct 16 15:08:51 volumio4 volumio[1249]: info: Loading i18n strings for locale pl Oct 16 15:08:51 volumio4 volumio[1249]: Updating browse sources language Oct 16 15:08:51 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 15:08:51 volumio4 volumio[1560]: Starting albumart workers Oct 16 15:08:52 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 15:08:52 volumio4 volumio[1249]: info: CoreCommandRouter::initPlayerControls Oct 16 15:08:52 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:08:52 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:08:52 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:08:52 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:08:52 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:08:52 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:08:52 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:08:52 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:08:52 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 15:08:52 volumio4 volumio[1249]: Express server listening on port 3000 Oct 16 15:08:52 volumio4 volumio[1249]: [Metrics] WebUI: 19s 625.74ms Oct 16 15:08:52 volumio4 volumio[1562]: Starting albumart workers Oct 16 15:08:52 volumio4 volumio[1249]: info: CoreStateMachine::resetVolumioState Oct 16 15:08:52 volumio4 volumio[1249]: info: CoreStateMachine::getcurrentVolume Oct 16 15:08:52 volumio4 volumio[1249]: info: CoreCommandRouter::volumioRetrievevolume Oct 16 15:08:52 volumio4 volumio[1249]: info: CoreStateMachine::pushState Oct 16 15:08:52 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:08:52 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 15:08:52 volumio4 volumio[1249]: info: CoreCommandRouter::volumioPushState Oct 16 15:08:52 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 15:08:53 volumio4 sudo[1609]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 15:08:53 volumio4 sudo[1609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:08:53 volumio4 sudo[1611]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 15:08:53 volumio4 sudo[1611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:08:53 volumio4 sudo[1609]: pam_unix(sudo:session): session closed for user root Oct 16 15:08:53 volumio4 sudo[1611]: pam_unix(sudo:session): session closed for user root Oct 16 15:08:53 volumio4 volumio[1249]: info: Volumio Network Manager: Network status updated: 2 Oct 16 15:08:53 volumio4 volumio[1561]: Starting albumart workers Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 15:08:54 volumio4 volumio[1249]: info: Discovery: Getting this device information Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:54 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 15:08:54 volumio4 volumio[1249]: info: Reloading queue from file Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreStateMachine::setRepeat false single undefined Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreStateMachine::pushState Oct 16 15:08:54 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::volumioPushState Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreStateMachine::setRandom false Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreStateMachine::pushState Oct 16 15:08:54 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::volumioPushState Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 15:08:54 volumio4 volumio[1249]: info: Discovery: Getting this device information Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:54 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 15:08:54 volumio4 volumio[1249]: info: Setting Device type: Raspberry PI Oct 16 15:08:54 volumio4 volumio[1249]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 16 15:08:54 volumio4 volumio[1249]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03114 Oct 16 15:08:54 volumio4 volumio[1249]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:54 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 15:08:54 volumio4 volumio[1249]: info: Discovery: Getting this device information Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:54 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 15:08:54 volumio4 volumio[1249]: info: Discovery: Getting this device information Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:54 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 15:08:54 volumio4 volumio-remote-updater[794]: [2026-10-16 15:08:54] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1792156130 101 Oct 16 15:08:54 volumio4 volumio[1249]: 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 Oct 16 15:08:54 volumio4 sudo[1632]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 16 15:08:54 volumio4 sudo[1632]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:54 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:54 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:54 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 15:08:54 volumio4 volumio[1249]: info: Discovery: Getting this device information Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:54 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:08:54 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 15:08:54 volumio4 volumio[1249]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Oct 16 15:08:54 volumio4 volumio[1249]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Oct 16 15:08:55 volumio4 volumio[1249]: info: Completed loading Core Plugins Oct 16 15:08:55 volumio4 volumio[1249]: info: Preparing to generate the ALSA configuration file Oct 16 15:08:55 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:55 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:08:55 volumio4 volumio[1249]: info: Asound.conf file written Oct 16 15:08:55 volumio4 sudo[1641]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 16 15:08:55 volumio4 sudo[1641]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:08:55 volumio4 sudo[1641]: pam_unix(sudo:session): session closed for user root Oct 16 15:08:55 volumio4 volumio[1249]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Oct 16 15:08:55 volumio4 volumio[1249]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Oct 16 15:08:55 volumio4 volumio[1249]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Oct 16 15:08:55 volumio4 volumio[1249]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2 Oct 16 15:08:55 volumio4 volumio[1249]: info: Output device has changed, restarting MPD Oct 16 15:08:55 volumio4 volumio[1249]: info: Output device has changed, restarting Shairport Sync Oct 16 15:08:55 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:08:55 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 15:08:55 volumio4 sudo[1648]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 16 15:08:55 volumio4 sudo[1651]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 16 15:08:55 volumio4 sudo[1648]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:08:55 volumio4 volumio[1249]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 15:08:55 volumio4 volumio[1249]: info: ___________ START PLUGINS ___________ Oct 16 15:08:55 volumio4 sudo[1651]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:08:55 volumio4 sudo[1648]: pam_unix(sudo:session): session closed for user root Oct 16 15:08:55 volumio4 volumio[1249]: info: ControllerMpd::onStart: Initializing MPD Oct 16 15:08:55 volumio4 volumio[1249]: info: Creating MPD Configuration file Oct 16 15:08:55 volumio4 sudo[1660]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 16 15:08:55 volumio4 sudo[1657]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Oct 16 15:08:55 volumio4 sudo[1657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:08:55 volumio4 sudo[1660]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:08:56 volumio4 sudo[1660]: pam_unix(sudo:session): session closed for user root Oct 16 15:08:56 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 15:08:56 volumio4 volumio[1249]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 15:08:56 volumio4 volumio[1249]: info: [1792156136032] CoreMusicLibrary::Adding element Serwery Mediów Oct 16 15:08:56 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 15:08:56 volumio4 volumio[1249]: info: UPNP Browser: Client initialized successfully Oct 16 15:08:56 volumio4 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 16 15:08:56 volumio4 systemd[1]: Starting mpd.service - Music Player Daemon... Oct 16 15:08:56 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:08:56 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 15:08:56 volumio4 systemd[1]: Stopping pydpiper.service - LCD server for Volumio (pydPiper)... Oct 16 15:08:56 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 16 15:08:56 volumio4 sudo[1666]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 16 15:08:56 volumio4 sudo[1666]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 16 15:08:56 volumio4 sudo[1657]: pam_unix(sudo:session): session closed for user root Oct 16 15:08:56 volumio4 sudo[1670]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 16 15:08:56 volumio4 sudo[1666]: pam_unix(sudo:session): session closed for user root Oct 16 15:08:56 volumio4 sudo[1665]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 16 15:08:56 volumio4 sudo[1665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:08:56 volumio4 systemd[1]: mpd.service: Deactivated successfully. Oct 16 15:08:56 volumio4 systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 16 15:08:56 volumio4 systemd[1]: mpd.socket: Deactivated successfully. Oct 16 15:08:56 volumio4 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 16 15:08:56 volumio4 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 16 15:08:56 volumio4 volumio[1249]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 15:08:56 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:08:56 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 15:08:56 volumio4 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 16 15:08:56 volumio4 systemd[1]: Starting mpd.service - Music Player Daemon... Oct 16 15:08:56 volumio4 sudo[1689]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 16 15:08:56 volumio4 sudo[1689]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 16 15:08:56 volumio4 sudo[1692]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 16 15:08:56 volumio4 sudo[1689]: pam_unix(sudo:session): session closed for user root Oct 16 15:08:56 volumio4 volumio[1249]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 15:08:56 volumio4 volumio[1249]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 15:08:56 volumio4 volumio[1249]: info: [1792156136588] CoreMusicLibrary::Adding element Last_100 Oct 16 15:08:56 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 15:08:56 volumio4 volumio[1249]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 15:08:56 volumio4 volumio[1249]: info: [1792156136592] CoreMusicLibrary::Adding element Webradio Oct 16 15:08:56 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 15:08:56 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 15:08:56 volumio4 volumio[1249]: info: Initializing BBC Radios Oct 16 15:08:56 volumio4 volumio5-onboarding[1668]: time=2026-10-16T15:08:56.605+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 16 15:08:56 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 15:08:56 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 15:08:56 volumio4 volumio[1249]: info: Creating Spotify config file Oct 16 15:08:56 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:08:57 volumio4 volumio[1249]: info: gpio-buttons - Initializing GPIO triggers... Oct 16 15:08:57 volumio4 volumio[1249]: info: gpio-buttons - ✅ GPIO17 configured for playPause Oct 16 15:08:57 volumio4 volumio[1249]: info: gpio-buttons - ✅ GPIO7 configured for previous Oct 16 15:08:57 volumio4 volumio[1249]: info: gpio-buttons - ✅ GPIO8 configured for next Oct 16 15:08:58 volumio4 volumio[1249]: info: Volumio Calling Home Oct 16 15:08:58 volumio4 sudo[1715]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 16 15:08:58 volumio4 sudo[1715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:08:58 volumio4 volumio[1249]: info: gpio-buttons - GPIO-Buttons started Oct 16 15:08:58 volumio4 sudo[1715]: pam_unix(sudo:session): session closed for user root Oct 16 15:08:59 volumio4 python[1002]: Exiting... Oct 16 15:08:59 volumio4 python[1002]: Loading font from /home/volumio/pydPiper_test/pydPiper/app/displays/fonts/latin1_5x8_fixed.fnt Oct 16 15:08:59 volumio4 python[1002]: Connected to Volumio Web Service Oct 16 15:08:59 volumio4 python[1002]: Loading font from /home/volumio/pydPiper_test/pydPiper/app/displays/fonts/latin1_5x8_lcd.fnt Oct 16 15:08:59 volumio4 python[1002]: Loading font from /home/volumio/pydPiper_test/pydPiper/app/displays/fonts/BigFont_10x16_fixed.fnt Oct 16 15:08:59 volumio4 python[1002]: Loading font from /home/volumio/pydPiper_test/pydPiper/app/displays/fonts/upperasciiwide_3x5_fixed.fnt Oct 16 15:08:59 volumio4 python[1002]: Shutting down threads Oct 16 15:08:59 volumio4 systemd[1]: pydpiper.service: Deactivated successfully. Oct 16 15:08:59 volumio4 systemd[1]: Stopped pydpiper.service - LCD server for Volumio (pydPiper). Oct 16 15:08:59 volumio4 systemd[1]: pydpiper.service: Consumed 4.288s CPU time. Oct 16 15:08:59 volumio4 systemd[1]: Started pydpiper.service - LCD server for Volumio (pydPiper). Oct 16 15:09:00 volumio4 volumio[1249]: info: Discovery: adding b1384ca2-a9a4-4b11-af6f-04cd5c3872a6 Oct 16 15:09:00 volumio4 volumio[1249]: info: Discovery: Found device Volumio4 Oct 16 15:09:00 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:00 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:00 volumio4 volumio[1249]: info: Discovery: this is already registered, b1384ca2-a9a4-4b11-af6f-04cd5c3872a6 Oct 16 15:09:00 volumio4 volumio[1249]: info: Discovery: Found device Volumio4 Oct 16 15:09:00 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:00 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:00 volumio4 volumio[1249]: info: MPD Permissions set Oct 16 15:09:00 volumio4 volumio[1249]: info: MPD Permissions set Oct 16 15:09:00 volumio4 sudo[1721]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay rotary-encoder pin_a=12 pin_b=13 relative_axis=true steps-per-period=1 Oct 16 15:09:00 volumio4 sudo[1721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:09:00 volumio4 mpd[1693]: 2026-10-16T15:09:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 16 15:09:00 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 15:09:00 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 15:09:00 volumio4 volumio[1249]: info: Discovery: Getting this device information Oct 16 15:09:00 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:00 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:00 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 15:09:00 volumio4 python[1718]: pydPiper starting Oct 16 15:09:00 volumio4 python[1718]: Loading display controller Oct 16 15:09:00 volumio4 python[1718]: Loading music controller Oct 16 15:09:00 volumio4 sudo[1721]: pam_unix(sudo:session): session closed for user root Oct 16 15:09:00 volumio4 systemd[1]: Started mpd.service - Music Player Daemon. Oct 16 15:09:00 volumio4 sudo[1665]: pam_unix(sudo:session): session closed for user root Oct 16 15:09:00 volumio4 kernel: rotary-encoder rotary@c: gray Oct 16 15:09:00 volumio4 python[1718]: Starting new HTTP connection (1): localhost:3000 Oct 16 15:09:00 volumio4 sudo[1651]: pam_unix(sudo:session): session closed for user root Oct 16 15:09:00 volumio4 kernel: input: rotary@c as /devices/platform/rotary@c/input/input4 Oct 16 15:09:01 volumio4 volumio[1249]: 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: 4 Oct 16 15:09:01 volumio4 volumio[1249]: info: Volumio called home Oct 16 15:09:01 volumio4 volumio[1249]: info: Spotify config file written Oct 16 15:09:01 volumio4 sudo[1736]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 16 15:09:01 volumio4 sudo[1736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:09:01 volumio4 volumio[1249]: 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: 4 Oct 16 15:09:01 volumio4 volumio[1249]: info: Received Get System Info Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 15:09:01 volumio4 volumio[1249]: info: Discovery: Getting this device information Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:01 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 15:09:01 volumio4 volumio5-onboarding[1668]: time=2026-10-16T15:09:01.237+02:00 level=INFO msg="system info for 88eab4ded9b862c4feedca6c2b4018f0" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.119 Oct 16 15:09:01 volumio4 volumio5-onboarding[1668]: time=2026-10-16T15:09:01.270+02:00 level=INFO msg="bootstrapping state" hasInternet=true Oct 16 15:09:01 volumio4 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. Oct 16 15:09:01 volumio4 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. Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:01 volumio4 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 15:09:01 volumio4 go-librespot[1740]: go-librespot daemon starting... Oct 16 15:09:01 volumio4 sudo[1736]: pam_unix(sudo:session): session closed for user root Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:01 volumio4 volumio[1249]: info: No need to fix Spotify hosts Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:01 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:01 volumio4 volumio[1249]: info: Received Get System Info Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 15:09:01 volumio4 volumio[1249]: info: Discovery: Getting this device information Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:01 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:01 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 15:09:01 volumio4 go-librespot[1746]: time="2026-10-16T15:09:01+02:00" level=info msg="running go-librespot 0.7.1" Oct 16 15:09:01 volumio4 go-librespot[1746]: time="2026-10-16T15:09:01+02:00" level=debug msg="app state loaded" Oct 16 15:09:01 volumio4 go-librespot[1746]: time="2026-10-16T15:09:01+02:00" level=debug msg="stored credentials not found" Oct 16 15:09:01 volumio4 go-librespot[1746]: time="2026-10-16T15:09:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 15:09:02 volumio4 go-librespot[1746]: time="2026-10-16T15:09:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 15:09:02 volumio4 go-librespot[1746]: time="2026-10-16T15:09:02+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 16 15:09:02 volumio4 go-librespot[1746]: time="2026-10-16T15:09:02+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 16 15:09:02 volumio4 go-librespot[1746]: time="2026-10-16T15:09:02+02:00" level=info msg="zeroconf server listening on port 33021" Oct 16 15:09:02 volumio4 go-librespot[1746]: time="2026-10-16T15:09:02+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 16 15:09:02 volumio4 sudo[1762]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay gpio-key gpio=5 active_low=true gpio_pull=up keycode=20 Oct 16 15:09:02 volumio4 sudo[1762]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:09:02 volumio4 volumio-remote-updater[794]: Test mode disabled Oct 16 15:09:02 volumio4 volumio-remote-updater[794]: Alpha mode disabled Oct 16 15:09:02 volumio4 volumio-remote-updater[794]: Alpha legacy test mode disabled Oct 16 15:09:02 volumio4 kernel: input: button@5 as /devices/platform/button@5/input/input5 Oct 16 15:09:02 volumio4 sudo[1762]: pam_unix(sudo:session): session closed for user root Oct 16 15:09:02 volumio4 python[1718]: Music Controller Starting Oct 16 15:09:02 volumio4 python[1718]: Loading app/pages/pages_lcd_16x2.py as page file Oct 16 15:09:02 volumio4 python[1718]: Initializing current system status update process. System status will update every five minutes Oct 16 15:09:02 volumio4 python[1718]: Weather service not enabled Oct 16 15:09:02 volumio4 python[1718]: Weather service not enabled Oct 16 15:09:03 volumio4 python[1718]: System status: Temp 51°c, Disk space remaining 91%, IP address uid Oct 16 15:09:03 volumio4 python[1718]: Loading image progbar Oct 16 15:09:03 volumio4 python[1718]: v out of range with value -1. Should have been between 0 and 100 Oct 16 15:09:03 volumio4 python[1718]: Trying to add widget playartist to sequence seqPlay but widget was not found Oct 16 15:09:03 volumio4 python[1718]: Trying to add widget playalbum to sequence seqPlay but widget was not found Oct 16 15:09:03 volumio4 python[1718]: Trying to add widget playartist_radio to sequence seqPlay but widget was not found Oct 16 15:09:03 volumio4 python[1718]: Trying to add widget playalbum_radio to sequence seqPlay but widget was not found Oct 16 15:09:03 volumio4 python[1718]: Trying to add widget playtitle_radio to sequence seqPlay but widget was not found Oct 16 15:09:03 volumio4 volumio[1249]: error: MPD error: The expression evaluated to a falsy value: Oct 16 15:09:03 volumio4 volumio[1249]: assert.ok(self.idling) Oct 16 15:09:03 volumio4 volumio[1249]: error: The expression evaluated to a falsy value: Oct 16 15:09:03 volumio4 volumio[1249]: assert.ok(self.idling) Oct 16 15:09:03 volumio4 volumio[1249]: info: MPD running with PID1693 Oct 16 15:09:03 volumio4 volumio[1249]: ,establishing connection Oct 16 15:09:03 volumio4 volumio[1249]: error: updateQueue error: null Oct 16 15:09:03 volumio4 volumio[1249]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 16 15:09:03 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 16 15:09:03 volumio4 volumio[1249]: info: Starting Shairport Sync Oct 16 15:09:03 volumio4 volumio[1249]: info: Starting Shairport Sync Oct 16 15:09:03 volumio4 volumio[1249]: info: Starting Shairport Sync Oct 16 15:09:03 volumio4 volumio[1249]: info: New Spotify access tokenBQCIAAmyt2... Oct 16 15:09:03 volumio4 sudo[1803]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 15:09:03 volumio4 sudo[1803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:09:03 volumio4 volumio[1249]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 16 15:09:03 volumio4 sudo[1806]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 15:09:03 volumio4 sudo[1805]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 15:09:03 volumio4 sudo[1805]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:09:03 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 15:09:03 volumio4 sudo[1806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:09:03 volumio4 volumio[1249]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 16 15:09:03 volumio4 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 16 15:09:03 volumio4 systemd[1]: shairport-sync.service: Deactivated successfully. Oct 16 15:09:03 volumio4 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 15:09:03 volumio4 systemd[1]: shairport-sync.service: Consumed 1.251s CPU time. Oct 16 15:09:03 volumio4 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 15:09:03 volumio4 sudo[1803]: pam_unix(sudo:session): session closed for user root Oct 16 15:09:04 volumio4 sudo[1805]: pam_unix(sudo:session): session closed for user root Oct 16 15:09:04 volumio4 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 16 15:09:04 volumio4 systemd[1]: shairport-sync.service: Deactivated successfully. Oct 16 15:09:04 volumio4 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 15:09:04 volumio4 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 15:09:04 volumio4 sudo[1806]: pam_unix(sudo:session): session closed for user root Oct 16 15:09:04 volumio4 volumio[1249]: error: updateQueue error: null Oct 16 15:09:04 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 15:09:04 volumio4 sudo[1829]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay rotary-encoder pin_a=14 pin_b=15 relative_axis=true steps-per-period=1 Oct 16 15:09:04 volumio4 sudo[1829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:09:04 volumio4 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 4. Oct 16 15:09:04 volumio4 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Oct 16 15:09:04 volumio4 volumio[1249]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 16 15:09:04 volumio4 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Oct 16 15:09:04 volumio4 kernel: rotary-encoder rotary@e: gray Oct 16 15:09:04 volumio4 sudo[1632]: pam_unix(sudo:session): session closed for user root Oct 16 15:09:04 volumio4 kernel: input: rotary@e as /devices/platform/rotary@e/input/input6 Oct 16 15:09:04 volumio4 volumio[1249]: info: Shairport-Sync Started Oct 16 15:09:04 volumio4 sudo[1829]: pam_unix(sudo:session): session closed for user root Oct 16 15:09:04 volumio4 volumio[1249]: Error adding Membership: Error: addMembership EINVAL Oct 16 15:09:04 volumio4 volumio[1249]: info: Shairport-Sync Started Oct 16 15:09:04 volumio4 volumio[1249]: info: Shairport-Sync Started Oct 16 15:09:04 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 15:09:04 volumio4 python[1718]: http://localhost:3000 "GET /socket.io/?transport=polling&EIO=3&t=1792156140.9628842 HTTP/1.1" 200 101 Oct 16 15:09:04 volumio4 volumio[1249]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.32.5 Engine version: 3 Transport: polling Total Clients: 7 Oct 16 15:09:04 volumio4 volumio[1249]: info: Upmpdcli Daemon Started Oct 16 15:09:04 volumio4 volumio[1249]: info: Received Get System Info Oct 16 15:09:04 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 15:09:04 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 15:09:04 volumio4 volumio[1249]: info: Discovery: Getting this device information Oct 16 15:09:04 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:04 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:04 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 15:09:04 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 16 15:09:04 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 16 15:09:04 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 15:09:04 volumio4 volumio5-onboarding[1668]: time=2026-10-16T15:09:04.918+02:00 level=INFO msg="enabling local network discovery" Oct 16 15:09:04 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 15:09:04 volumio4 volumio[1249]: info: Discovery: Getting this device information Oct 16 15:09:04 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:04 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:04 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 15:09:04 volumio4 volumio5-onboarding[1668]: time=2026-10-16T15:09:04.946+02:00 level=INFO msg="enabling BLE discovery" Oct 16 15:09:05 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:05 volumio4 sudo[1853]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay gpio-key gpio=6 active_low=true gpio_pull=up keycode=20 Oct 16 15:09:05 volumio4 sudo[1853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:09:05 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:05 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:05 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:05 volumio4 kernel: input: button@6 as /devices/platform/button@6/input/input7 Oct 16 15:09:05 volumio4 sudo[1853]: pam_unix(sudo:session): session closed for user root Oct 16 15:09:05 volumio4 volumio[1249]: info: Spotify Successfully logged in Oct 16 15:09:05 volumio4 volumio[1249]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 15:09:05 volumio4 volumio[1249]: info: [1792156145834] CoreMusicLibrary::Adding element Spotify Oct 16 15:09:05 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 15:09:05 volumio4 volumio[1249]: Cannot find translation for source Spotify Oct 16 15:09:05 volumio4 volumio5-onboarding[1668]: time=2026-10-16T15:09:05.902+02:00 level=INFO msg="service successfully established" component=discovery/localnet Oct 16 15:09:05 volumio4 python[1718]: Connected to Volumio3 Oct 16 15:09:06 volumio4 python[1718]: Connected to Volumio Web Service Oct 16 15:09:06 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetQueue Oct 16 15:09:06 volumio4 volumio[1249]: info: CoreStateMachine::getQueue Oct 16 15:09:06 volumio4 volumio[1249]: info: CorePlayQueue::getQueue Oct 16 15:09:06 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:06 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:06 volumio4 sudo[1870]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 16 15:09:06 volumio4 sudo[1870]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:09:06 volumio4 sudo[1870]: pam_unix(sudo:session): session closed for user root Oct 16 15:09:06 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:06 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:06 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 15:09:06 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 15:09:06 volumio4 volumio[1249]: info: Discovery: Getting this device information Oct 16 15:09:06 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:06 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:06 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 15:09:06 volumio4 volumio[1249]: info: Completed starting Core Plugins Oct 16 15:09:06 volumio4 volumio[1249]: info: ------------------------------------------- Oct 16 15:09:06 volumio4 volumio[1249]: info: ----- MyVolumio plugins startup ---- Oct 16 15:09:06 volumio4 volumio[1249]: info: ------------------------------------------- Oct 16 15:09:06 volumio4 volumio[1249]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 16 15:09:06 volumio4 volumio[1249]: info: go-librespot daemon successfully initialized Oct 16 15:09:06 volumio4 sudo[1880]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 16 15:09:06 volumio4 sudo[1880]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:09:06 volumio4 sudo[1880]: pam_unix(sudo:session): session closed for user root Oct 16 15:09:07 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetQueue Oct 16 15:09:07 volumio4 volumio[1249]: info: CoreStateMachine::getQueue Oct 16 15:09:07 volumio4 volumio[1249]: info: CorePlayQueue::getQueue Oct 16 15:09:07 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:07 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:07 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:07 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:07 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:07 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:07 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetQueue Oct 16 15:09:07 volumio4 volumio[1249]: info: CoreStateMachine::getQueue Oct 16 15:09:07 volumio4 volumio[1249]: info: CorePlayQueue::getQueue Oct 16 15:09:07 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:07 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:08 volumio4 volumio[1249]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 16 15:09:10 volumio4 volumio[1249]: info: Initializing connection to go-librespot Websocket Oct 16 15:09:10 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetQueue Oct 16 15:09:10 volumio4 volumio[1249]: info: CoreStateMachine::getQueue Oct 16 15:09:10 volumio4 volumio[1249]: info: CorePlayQueue::getQueue Oct 16 15:09:10 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:10 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:10 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetQueue Oct 16 15:09:10 volumio4 volumio[1249]: info: CoreStateMachine::getQueue Oct 16 15:09:10 volumio4 volumio[1249]: info: CorePlayQueue::getQueue Oct 16 15:09:10 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:10 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:14 volumio4 go-librespot[1746]: time="2026-10-16T15:09:14+02:00" level=debug msg="new websocket client" Oct 16 15:09:17 volumio4 volumio[1249]: info: Connection to go-librespot Websocket established Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreStateMachine::getQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CorePlayQueue::getQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:17 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreStateMachine::getQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CorePlayQueue::getQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:17 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreStateMachine::getQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CorePlayQueue::getQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:17 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreStateMachine::getQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CorePlayQueue::getQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:17 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreStateMachine::getQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CorePlayQueue::getQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:17 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreStateMachine::getQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CorePlayQueue::getQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:17 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreStateMachine::getQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CorePlayQueue::getQueue Oct 16 15:09:17 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:17 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:19 volumio4 upmpdcli[1930]: writing RSA key Oct 16 15:09:19 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetQueue Oct 16 15:09:19 volumio4 volumio[1249]: info: CoreStateMachine::getQueue Oct 16 15:09:19 volumio4 volumio[1249]: info: CorePlayQueue::getQueue Oct 16 15:09:19 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:19 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:19 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetQueue Oct 16 15:09:19 volumio4 volumio[1249]: info: CoreStateMachine::getQueue Oct 16 15:09:19 volumio4 volumio[1249]: info: CorePlayQueue::getQueue Oct 16 15:09:19 volumio4 volumio[1249]: info: CoreCommandRouter::volumioGetState Oct 16 15:09:19 volumio4 volumio[1249]: info: CorePlayQueue::getTrack 0 Oct 16 15:09:24 volumio4 systemd[1]: Stopping pydpiper.service - LCD server for Volumio (pydPiper)... Oct 16 15:09:27 volumio4 volumio[1249]: info: Getting Spotify volume Oct 16 15:09:27 volumio4 volumio[1249]: error: MyVolumio Plugin failed to start in a timely fashion Oct 16 15:09:27 volumio4 volumio[1249]: [Metrics] CommandRouter: 52s 605.94ms Oct 16 15:09:27 volumio4 volumio[1249]: info: CoreCommandRouter::volumiosetStartupVolume Oct 16 15:09:27 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:09:27 volumio4 volumio[1249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 15:09:27 volumio4 volumio[1249]: info: CoreCommandRouter::Close All Modals sent Oct 16 15:09:27 volumio4 volumio[1249]: info: CoreCommandRouter::Close All Modals sent Oct 16 15:09:27 volumio4 volumio[1249]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 15:09:27 volumio4 volumio[1249]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals. Oct 16 15:09:27 volumio4 volumio[1249]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues Oct 16 15:09:27 volumio4 volumio[1249]: at new NodeError (node:internal/errors:405:5) Oct 16 15:09:27 volumio4 volumio[1249]: at assert (node:internal/assert:14:11) Oct 16 15:09:27 volumio4 volumio[1249]: at internalConnectMultiple (node:net:1118:3) Oct 16 15:09:27 volumio4 volumio[1249]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3) Oct 16 15:09:27 volumio4 volumio[1249]: at listOnTimeout (node:internal/timers:575:11) Oct 16 15:09:27 volumio4 volumio[1249]: at process.processTimers (node:internal/timers:514:7) { Oct 16 15:09:27 volumio4 volumio[1249]: code: 'ERR_INTERNAL_ASSERTION' Oct 16 15:09:27 volumio4 volumio[1249]: } Oct 16 15:09:27 volumio4 volumio[1249]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 15:09:27 volumio4 python[1718]: Exiting... Oct 16 15:09:27 volumio4 python[1718]: Loading font from /home/volumio/pydPiper_test/pydPiper/app/displays/fonts/latin1_5x8_fixed.fnt Oct 16 15:09:27 volumio4 python[1718]: Connected to Volumio Web Service Oct 16 15:09:27 volumio4 python[1718]: Loading font from /home/volumio/pydPiper_test/pydPiper/app/displays/fonts/latin1_5x8_lcd.fnt Oct 16 15:09:27 volumio4 python[1718]: Loading font from /home/volumio/pydPiper_test/pydPiper/app/displays/fonts/BigFont_10x16_fixed.fnt Oct 16 15:09:27 volumio4 python[1718]: Loading font from /home/volumio/pydPiper_test/pydPiper/app/displays/fonts/upperasciiwide_3x5_fixed.fnt Oct 16 15:09:27 volumio4 python[1718]: Shutting down threads Oct 16 15:09:27 volumio4 systemd[1]: pydpiper.service: Deactivated successfully. Oct 16 15:09:27 volumio4 systemd[1]: Stopped pydpiper.service - LCD server for Volumio (pydPiper). Oct 16 15:09:27 volumio4 systemd[1]: pydpiper.service: Consumed 3.178s CPU time. Oct 16 15:09:27 volumio4 systemd[1]: Started pydpiper.service - LCD server for Volumio (pydPiper). Oct 16 15:09:27 volumio4 systemd[1]: pydpiper-kick.service: Deactivated successfully. Oct 16 15:09:27 volumio4 systemd[1]: Finished pydpiper-kick.service - Kick pydPiper after boot (2x restart). Oct 16 15:09:27 volumio4 systemd[1]: Reached target multi-user.target - Multi-User System. Oct 16 15:09:27 volumio4 systemd[1]: Reached target graphical.target - Graphical Interface. Oct 16 15:09:27 volumio4 systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Oct 16 15:09:28 volumio4 systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Oct 16 15:09:28 volumio4 systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Oct 16 15:09:28 volumio4 systemd[1]: Startup finished in 20.073s (kernel) + 1min 39.912s (userspace) = 1min 59.986s. Oct 16 15:09:28 volumio4 python[1972]: pydPiper starting Oct 16 15:09:28 volumio4 python[1972]: Loading display controller Oct 16 15:09:28 volumio4 python[1972]: Loading music controller Oct 16 15:09:28 volumio4 python[1972]: Starting new HTTP connection (1): localhost:3000 Oct 16 15:09:30 volumio4 python[1972]: Music Controller Starting Oct 16 15:09:30 volumio4 python[1972]: Loading app/pages/pages_lcd_16x2.py as page file Oct 16 15:09:30 volumio4 python[1972]: Initializing current system status update process. System status will update every five minutes Oct 16 15:09:31 volumio4 python[1972]: Weather service not enabled Oct 16 15:09:31 volumio4 python[1972]: Weather service not enabled Oct 16 15:09:31 volumio4 python[1972]: System status: Temp 55°c, Disk space remaining 91%, IP address uid Oct 16 15:09:31 volumio4 python[1972]: Loading image progbar Oct 16 15:09:31 volumio4 python[1972]: v out of range with value -1. Should have been between 0 and 100 Oct 16 15:09:31 volumio4 python[1972]: Trying to add widget playartist to sequence seqPlay but widget was not found Oct 16 15:09:31 volumio4 python[1972]: Trying to add widget playalbum to sequence seqPlay but widget was not found Oct 16 15:09:31 volumio4 python[1972]: Trying to add widget playartist_radio to sequence seqPlay but widget was not found Oct 16 15:09:31 volumio4 python[1972]: Trying to add widget playalbum_radio to sequence seqPlay but widget was not found Oct 16 15:09:31 volumio4 python[1972]: Trying to add widget playtitle_radio to sequence seqPlay but widget was not found Oct 16 15:09:31 volumio4 sudo[1978]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-16 15:08' Oct 16 15:09:31 volumio4 sudo[1978]: 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"