Aug 28 09:23:21 bst systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 28 09:23:21 bst systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 28 09:23:21 bst systemd[1]: setdatetime-helper.service: Consumed 1.089s CPU time. Aug 28 09:23:21 bst systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Aug 28 09:23:21 bst systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Aug 28 09:23:21 bst systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Aug 28 09:23:21 bst winbindd[1335]: [2026/08/28 09:23:21.199056, 0] ../../source3/winbindd/winbindd_idmap.c:372(wb_parent_idmap_setup_lookupname_done) Aug 28 09:23:21 bst winbindd[1335]: wb_parent_idmap_setup_lookupname_done: Lookup domain name 'BST' failed 'NT_STATUS_IO_TIMEOUT' Aug 28 09:23:21 bst systemd[1]: Started smbd.service - Samba SMB Daemon. Aug 28 09:23:21 bst systemd[1]: Reached target multi-user.target - Multi-User System. Aug 28 09:23:21 bst systemd[1]: Reached target graphical.target - Graphical Interface. Aug 28 09:23:21 bst ntpd[1107]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 28 09:23:21 bst ntpd[1107]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Aug 28 09:23:21 bst ntpd[1107]: DNS: Pool taking: 178.215.228.24 Aug 28 09:23:21 bst ntpd[1107]: DNS: Pool taking: 45.87.76.3 Aug 28 09:23:21 bst ntpd[1107]: DNS: Pool skipping: 45.138.55.60 Aug 28 09:23:21 bst ntpd[1107]: DNS: Pool taking: 91.177.126.188 Aug 28 09:23:21 bst ntpd[1107]: DNS: Pool taking: 2a12:bec4:1821:25c::123 Aug 28 09:23:21 bst ntpd[1107]: DNS: Pool taking: 2a10:3781:2d18::31 Aug 28 09:23:21 bst ntpd[1107]: DNS: Pool taking: 2a05:5502:12:11::123 Aug 28 09:23:21 bst ntpd[1107]: DNS: Pool taking: 2a01:b2e0:2::63 Aug 28 09:23:21 bst ntpd[1107]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Aug 28 09:23:21 bst systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Aug 28 09:23:21 bst systemd[1]: dpkg-db-backup.service: Deactivated successfully. Aug 28 09:23:21 bst systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Aug 28 09:23:21 bst systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Aug 28 09:23:21 bst systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Aug 28 09:23:21 bst systemd[1]: Startup finished in 14.192s (kernel) + 14.897s (userspace) = 29.090s. Aug 28 09:23:21 bst dhcpcd[775]: eth0: leased 192.168.0.245 for 86400 seconds Aug 28 09:23:21 bst sh[752]: eth0: leased 192.168.0.245 for 86400 seconds Aug 28 09:23:21 bst dhcpcd[775]: eth0: adding route to 192.168.0.0/24 Aug 28 09:23:21 bst sh[752]: eth0: adding route to 192.168.0.0/24 Aug 28 09:23:21 bst sh[752]: eth0: adding default route via 192.168.0.1 Aug 28 09:23:21 bst dhcpcd[775]: eth0: adding default route via 192.168.0.1 Aug 28 09:23:21 bst systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Aug 28 09:23:21 bst systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Aug 28 09:23:21 bst systemd[1]: welcome.service: Deactivated successfully. Aug 28 09:23:21 bst systemd[1]: Stopped welcome.service - Show a welcome message on console. Aug 28 09:23:21 bst systemd[1]: Stopping welcome.service - Show a welcome message on console... Aug 28 09:23:21 bst sh[752]: forked to background, child pid 774 Aug 28 09:23:21 bst systemd[1]: Starting welcome.service - Show a welcome message on console... Aug 28 09:23:21 bst welcome[1428]: Resolved ip:[1] 192.168.0.245 Aug 28 09:23:21 bst systemd[1]: Finished welcome.service - Show a welcome message on console. Aug 28 09:23:21 bst systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Aug 28 09:23:21 bst ifplugd(eth0)[1118]: client: ifup: interface eth0 already configured Aug 28 09:23:21 bst sh[1467]: eth0=eth0 Aug 28 09:23:21 bst ifplugd(eth0)[1118]: Program executed successfully. Aug 28 09:23:22 bst ntpd[1107]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 28 09:23:22 bst ntpd[1107]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Aug 28 09:23:22 bst ntpd[1107]: DNS: Pool taking: 162.159.200.1 Aug 28 09:23:22 bst ntpd[1107]: DNS: Pool taking: 94.142.246.192 Aug 28 09:23:22 bst ntpd[1107]: DNS: Pool taking: 185.51.192.63 Aug 28 09:23:22 bst ntpd[1107]: DNS: Pool taking: 81.82.227.219 Aug 28 09:23:22 bst ntpd[1107]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Aug 28 09:23:23 bst volumio[1349]: info: ------------------------------------------- Aug 28 09:23:23 bst volumio[1349]: info: ----- Volumio3 ---- Aug 28 09:23:23 bst volumio[1349]: info: ------------------------------------------- Aug 28 09:23:23 bst volumio[1349]: info: ----- System startup ---- Aug 28 09:23:23 bst volumio[1349]: info: ------------------------------------------- Aug 28 09:23:23 bst ntpd[1107]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 28 09:23:23 bst ntpd[1107]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Aug 28 09:23:23 bst ntpd[1107]: DNS: Pool taking: 85.163.168.227 Aug 28 09:23:23 bst ntpd[1107]: DNS: Pool taking: 45.87.78.35 Aug 28 09:23:23 bst ntpd[1107]: DNS: Pool skipping: 162.159.200.1 Aug 28 09:23:23 bst ntpd[1107]: DNS: Pool taking: 156.106.214.52 Aug 28 09:23:23 bst ntpd[1107]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Aug 28 09:23:23 bst volumio-remote-updater[857]: [2026-08-28 09:23:23] [connect] Successful connection Aug 28 09:23:23 bst volumio[1349]: info: MYVOLUMIO Environment detected Aug 28 09:23:24 bst volumio[1349]: info: Plugin folders cleanup Aug 28 09:23:24 bst volumio[1349]: info: Scanning into folder /volumio/app/plugins/ Aug 28 09:23:24 bst volumio[1349]: info: Scanning category audio_interface Aug 28 09:23:24 bst volumio[1349]: info: Scanning category miscellanea Aug 28 09:23:24 bst volumio[1349]: info: Scanning category music_service Aug 28 09:23:24 bst volumio[1349]: info: Scanning category plugins.json Aug 28 09:23:24 bst volumio[1349]: info: Scanning category system_controller Aug 28 09:23:24 bst volumio[1349]: info: Scanning category user_interface Aug 28 09:23:24 bst volumio[1349]: info: Scanning into folder /data/plugins/ Aug 28 09:23:24 bst volumio[1349]: info: Scanning category music_service Aug 28 09:23:24 bst volumio[1349]: info: Scanning category user_interface Aug 28 09:23:24 bst volumio[1349]: info: Plugin folders cleanup completed Aug 28 09:23:24 bst volumio[1349]: info: ------------------------------------------- Aug 28 09:23:24 bst volumio[1349]: info: ----- Core plugins startup ---- Aug 28 09:23:24 bst volumio[1349]: info: ------------------------------------------- Aug 28 09:23:24 bst volumio[1349]: info: Loading plugins from folder /volumio/app/plugins/ Aug 28 09:23:24 bst volumio[1349]: info: Adding plugin upnp to MyMusic Plugins Aug 28 09:23:24 bst volumio[1349]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 28 09:23:24 bst volumio[1349]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 28 09:23:24 bst volumio[1349]: info: Loading plugins from folder /data/plugins/ Aug 28 09:23:24 bst volumio[1349]: info: Loading plugin "system"... Aug 28 09:23:24 bst volumio[1349]: info: Loading plugin "appearance"... Aug 28 09:23:25 bst volumio[1349]: info: Loading plugin "network"... Aug 28 09:23:25 bst volumio[1349]: info: Refreshing Cached IP Addresses Aug 28 09:23:25 bst volumio[1349]: info: Loading plugin "services"... Aug 28 09:23:25 bst volumio[1349]: info: Loading plugin "volumio5onboarding"... Aug 28 09:23:25 bst sudo[1483]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 28 09:23:25 bst sudo[1483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:25 bst sudo[1486]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 28 09:23:25 bst sudo[1483]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:25 bst sudo[1486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:25 bst sudo[1486]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:25 bst volumio[1349]: info: Loading plugin "alsa_controller"... Aug 28 09:23:25 bst sudo[1492]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 28 09:23:25 bst sudo[1492]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:25 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 28 09:23:25 bst volumio[1349]: info: Loading plugin "wizard"... Aug 28 09:23:25 bst volumio[1349]: info: Loading plugin "networkfs"... Aug 28 09:23:25 bst volumio[1349]: info: Starting Udev Watcher for removable devices Aug 28 09:23:25 bst volumio[1349]: info: Ignoring mount for partition: boot Aug 28 09:23:25 bst volumio[1349]: info: Ignoring mount for partition: volumio Aug 28 09:23:25 bst volumio[1349]: info: Ignoring mount for partition: volumio_data Aug 28 09:23:25 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 28 09:23:25 bst volumio[1349]: info: Loading plugin "volumio_command_line_client"... Aug 28 09:23:25 bst volumio[1349]: info: Loading plugin "upnp"... Aug 28 09:23:25 bst volumio[1349]: info: [1787901805804] Starting Upmpd Daemon Aug 28 09:23:25 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 28 09:23:25 bst volumio[1349]: info: Loading plugin "my_music"... Aug 28 09:23:25 bst volumio[1349]: info: Loading plugin "mpd"... Aug 28 09:23:25 bst sudo[1519]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=bertsteelant,password=5578Albamar!!,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.179/muziek /mnt/NAS/NAS_Bert Aug 28 09:23:25 bst sudo[1519]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:25 bst kernel: netfs: FS-Cache loaded Aug 28 09:23:26 bst kernel: Key type cifs.spnego registered Aug 28 09:23:26 bst kernel: Key type cifs.idmap registered Aug 28 09:23:26 bst 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. Aug 28 09:23:26 bst kernel: CIFS: Attempting to mount //192.168.0.179/muziek Aug 28 09:23:26 bst volumio[1349]: info: Loading plugin "upnp_browser"... Aug 28 09:23:26 bst systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Aug 28 09:23:26 bst systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 28 09:23:26 bst sudo[1519]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:26 bst systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 28 09:23:26 bst upmpdcli[1556]: Could not open config: /tmp/upmpdcli.conf Aug 28 09:23:26 bst systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 28 09:23:26 bst systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 28 09:23:27 bst ntpd[1107]: CLOCK: time stepped by 0.707108 Aug 28 09:23:27 bst ntpd[1107]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Aug 28 09:23:28 bst volumio[1349]: info: Starting UPNP Browser Aug 28 09:23:28 bst volumio[1349]: info: Loading plugin "alarm-clock"... Aug 28 09:23:28 bst volumio[1349]: info: Loading plugin "airplay_emulation"... Aug 28 09:23:28 bst volumio[1349]: info: Starting Shairport Sync Aug 28 09:23:28 bst volumio[1349]: info: Loading plugin "last_100"... Aug 28 09:23:28 bst volumio[1349]: info: Loading plugin "webradio"... Aug 28 09:23:28 bst volumio[1349]: info: Loading plugin "i2s_dacs"... Aug 28 09:23:28 bst volumio[1349]: info: I2S DAC not set, start Auto-detection Aug 28 09:23:28 bst volumio[1349]: info: Loading plugin "volumiodiscovery"... Aug 28 09:23:28 bst volumio[1349]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 28 09:23:28 bst node[1349]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 28 09:23:28 bst volumio[1349]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 28 09:23:28 bst node[1349]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 28 09:23:28 bst volumio[1349]: *** WARNING *** For more information see Aug 28 09:23:28 bst node[1349]: *** WARNING *** For more information see Aug 28 09:23:28 bst volumio[1349]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 28 09:23:28 bst node[1349]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 28 09:23:28 bst volumio[1349]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 28 09:23:28 bst node[1349]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 28 09:23:28 bst volumio[1349]: *** WARNING *** For more information see Aug 28 09:23:28 bst node[1349]: *** WARNING *** For more information see Aug 28 09:23:28 bst volumio[1349]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 28 09:23:28 bst volumio[1349]: info: Discovery: Started advertising with name: BST Aug 28 09:23:28 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 28 09:23:28 bst volumio[1349]: info: Loading plugin "spop"... Aug 28 09:23:28 bst sudo[1492]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:30 bst volumio[1349]: info: Loading plugin "outputs"... Aug 28 09:23:30 bst volumio[1349]: info: Loading plugin "albumart"... Aug 28 09:23:30 bst volumio[1349]: info: Plugin example_plugin is not enabled Aug 28 09:23:30 bst volumio[1349]: info: Loading plugin "inputs"... Aug 28 09:23:30 bst volumio[1349]: info: Loading plugin "updater_comm"... Aug 28 09:23:30 bst volumio[1349]: info: Plugin mpdemulation is not enabled Aug 28 09:23:30 bst volumio[1349]: info: Loading plugin "rest_api"... Aug 28 09:23:30 bst volumio[1349]: info: Loading plugin "websocket"... Aug 28 09:23:30 bst volumio[1349]: info: Starting Socket.io Server version 1.7.4 Aug 28 09:23:30 bst volumio[1349]: info: Loading plugin "touch_display"... Aug 28 09:23:30 bst volumio[1349]: info: Applying required configuration parameters for plugin touch_display Aug 28 09:23:31 bst volumio[1349]: info: Loading i18n strings for locale nl Aug 28 09:23:31 bst volumio[1349]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Aug 28 09:23:31 bst volumio[1349]: Updating browse sources language Aug 28 09:23:31 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 28 09:23:31 bst volumio[1559]: Forking 3 albumart workers Aug 28 09:23:31 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 28 09:23:31 bst volumio[1349]: info: CoreCommandRouter::initPlayerControls Aug 28 09:23:31 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:31 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:31 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:31 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:31 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:31 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:31 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:31 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:31 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 28 09:23:31 bst volumio[1349]: Express server listening on port 3000 Aug 28 09:23:31 bst volumio[1349]: [Metrics] WebUI: 8s 341.27ms Aug 28 09:23:31 bst volumio[1349]: info: CoreStateMachine::resetVolumioState Aug 28 09:23:31 bst volumio[1349]: info: CoreStateMachine::getcurrentVolume Aug 28 09:23:31 bst volumio[1349]: info: CoreCommandRouter::volumioRetrievevolume Aug 28 09:23:31 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 28 09:23:31 bst volumio[1349]: info: Volumio Network Manager: Network status updated: 1 Aug 28 09:23:32 bst volumio[1349]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 28 09:23:32 bst volumio[1349]: info: Reloading queue from file Aug 28 09:23:33 bst volumio[1349]: info: VolumeController:: Volume=60 Mute =false Aug 28 09:23:33 bst volumio[1349]: info: CoreStateMachine::pushState Aug 28 09:23:33 bst volumio[1349]: info: CorePlayQueue::getTrack 0 Aug 28 09:23:33 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 28 09:23:33 bst volumio[1349]: info: CoreCommandRouter::volumioPushState Aug 28 09:23:33 bst volumio[1349]: info: CoreStateMachine::updateTrackBlock Aug 28 09:23:33 bst volumio[1349]: info: CorePlayQueue::getTrackBlock Aug 28 09:23:33 bst volumio[1349]: info: CoreCommandRouter::volumioRetrievevolume Aug 28 09:23:33 bst volumio[1349]: info: CoreStateMachine::setRepeat false single undefined Aug 28 09:23:33 bst volumio[1349]: info: CoreStateMachine::pushState Aug 28 09:23:33 bst volumio[1349]: info: CorePlayQueue::getTrack 0 Aug 28 09:23:33 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 28 09:23:33 bst volumio[1349]: info: CoreCommandRouter::volumioPushState Aug 28 09:23:33 bst volumio[1349]: info: CoreStateMachine::setRandom true Aug 28 09:23:33 bst volumio[1349]: info: CoreStateMachine::pushState Aug 28 09:23:33 bst volumio[1349]: info: CorePlayQueue::getTrack 0 Aug 28 09:23:33 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 28 09:23:33 bst volumio[1349]: info: CoreCommandRouter::volumioPushState Aug 28 09:23:33 bst volumio[1349]: info: Setting Device type: Raspberry PI Aug 28 09:23:33 bst volumio[1349]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 28 09:23:33 bst volumio[1349]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03115 Aug 28 09:23:33 bst volumio[1349]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 28 09:23:33 bst volumio[1349]: info: Discovery: adding 94d82188-6972-4eea-b18a-e0a52559e3d6 Aug 28 09:23:33 bst volumio[1349]: info: Discovery: Found device BST Aug 28 09:23:33 bst volumio[1349]: info: CoreCommandRouter::volumioGetState Aug 28 09:23:33 bst volumio[1349]: info: CorePlayQueue::getTrack 0 Aug 28 09:23:33 bst volumio[1349]: info: VolumeController:: Volume=60 Mute =false Aug 28 09:23:33 bst volumio[1349]: info: CoreStateMachine::pushState Aug 28 09:23:33 bst volumio[1349]: info: CorePlayQueue::getTrack 0 Aug 28 09:23:33 bst volumio[1349]: info: CoreCommandRouter::volumioPushState Aug 28 09:23:33 bst volumio[1349]: info: Discovery: this is already registered, 94d82188-6972-4eea-b18a-e0a52559e3d6 Aug 28 09:23:33 bst volumio[1349]: info: Discovery: Found device BST Aug 28 09:23:33 bst volumio[1349]: info: CoreCommandRouter::volumioGetState Aug 28 09:23:33 bst volumio[1349]: info: CorePlayQueue::getTrack 0 Aug 28 09:23:34 bst volumio[1349]: info: Completed loading Core Plugins Aug 28 09:23:34 bst volumio[1349]: info: Preparing to generate the ALSA configuration file Aug 28 09:23:34 bst volumio[1349]: info: Asound.conf file unchanged, so no further update is needed Aug 28 09:23:34 bst volumio[1349]: info: Output device has changed, restarting MPD Aug 28 09:23:34 bst volumio[1349]: info: Output device has changed, restarting Shairport Sync Aug 28 09:23:34 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:34 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 28 09:23:34 bst sudo[1616]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 28 09:23:34 bst sudo[1616]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:34 bst sudo[1616]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:34 bst volumio[1349]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 28 09:23:34 bst volumio[1349]: info: ___________ START PLUGINS ___________ Aug 28 09:23:34 bst sudo[1621]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 28 09:23:34 bst sudo[1621]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:34 bst volumio[1349]: info: ControllerMpd::onStart: Initializing MPD Aug 28 09:23:34 bst volumio[1349]: info: Creating MPD Configuration file Aug 28 09:23:34 bst sudo[1626]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 28 09:23:34 bst sudo[1626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:34 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 28 09:23:34 bst volumio[1349]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 28 09:23:34 bst volumio[1349]: info: [1787901814968] CoreMusicLibrary::Adding element Media Servers Aug 28 09:23:34 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 28 09:23:35 bst sudo[1628]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 28 09:23:35 bst volumio[1349]: info: UPNP Browser: Client initialized successfully Aug 28 09:23:35 bst sudo[1628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:35 bst sudo[1631]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 28 09:23:35 bst sudo[1631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:35 bst sudo[1628]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:35 bst systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 28 09:23:35 bst systemd[1]: Starting mpd.service - Music Player Daemon... Aug 28 09:23:35 bst systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 28 09:23:35 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:35 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 28 09:23:35 bst sudo[1626]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:35 bst volumio[1349]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 28 09:23:35 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:35 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 28 09:23:35 bst sudo[1634]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 28 09:23:35 bst sudo[1634]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 28 09:23:35 bst sudo[1646]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 28 09:23:35 bst sudo[1634]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:35 bst systemd[1]: mpd.service: Deactivated successfully. Aug 28 09:23:35 bst systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 28 09:23:35 bst systemd[1]: mpd.socket: Deactivated successfully. Aug 28 09:23:35 bst systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 28 09:23:35 bst systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 28 09:23:35 bst systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 28 09:23:35 bst systemd[1]: Starting mpd.service - Music Player Daemon... Aug 28 09:23:35 bst volumio[1349]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 28 09:23:35 bst volumio[1349]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 28 09:23:35 bst volumio[1349]: info: [1787901815467] CoreMusicLibrary::Adding element Last_100 Aug 28 09:23:35 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 28 09:23:35 bst volumio[1349]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 28 09:23:35 bst volumio[1349]: info: [1787901815514] CoreMusicLibrary::Adding element Webradio Aug 28 09:23:35 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 28 09:23:35 bst sudo[1653]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 28 09:23:35 bst sudo[1653]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 28 09:23:35 bst sudo[1654]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 28 09:23:35 bst sudo[1653]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:35 bst volumio5-onboarding[1636]: time=2026-08-28T09:23:35.527+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 28 09:23:35 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 28 09:23:35 bst volumio[1349]: info: Initializing BBC Radios Aug 28 09:23:36 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 28 09:23:36 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 28 09:23:36 bst volumio[1349]: info: Creating Spotify config file Aug 28 09:23:36 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:36 bst volumio[1569]: Starting albumart workers Aug 28 09:23:37 bst volumio[1349]: info: Loading i18n strings for locale nl Aug 28 09:23:37 bst volumio[1349]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Aug 28 09:23:37 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 28 09:23:37 bst volumio[1349]: info: Volumio Calling Home Aug 28 09:23:37 bst sudo[1687]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge Aug 28 09:23:37 bst sudo[1687]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:37 bst sudo[1692]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Aug 28 09:23:37 bst sudo[1687]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:37 bst sudo[1692]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:37 bst sudo[1695]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Aug 28 09:23:37 bst sudo[1695]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:37 bst sudo[1692]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:37 bst volumio[1570]: Starting albumart workers Aug 28 09:23:37 bst sudo[1698]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Aug 28 09:23:37 bst volumio[1573]: Starting albumart workers Aug 28 09:23:37 bst sudo[1698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:37 bst systemd[1]: Reloading. Aug 28 09:23:39 bst sudo[1721]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 28 09:23:39 bst sudo[1721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:39 bst sudo[1721]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:39 bst sudo[1719]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 28 09:23:39 bst sudo[1719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:39 bst sudo[1719]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:39 bst volumio[1349]: info: touch_display: Backlight interface detected. Aug 28 09:23:39 bst systemd[1]: Reloading. Aug 28 09:23:39 bst sudo[1695]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:39 bst volumio-remote-updater[857]: [2026-08-28 09:23:39] [connect] Successful connection Aug 28 09:23:39 bst volumio[1349]: info: touch_display: systemctl stop getty@tty1.service succeeded. Aug 28 09:23:39 bst volumio[1349]: info: MPD Permissions set Aug 28 09:23:39 bst volumio[1349]: info: MPD Permissions set Aug 28 09:23:39 bst volumio[1349]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 28 09:23:40 bst sudo[1751]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/cp -r /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/content.js /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/manifest.json /data/volumiokioskextensions/IframeKeyboardBridge/ Aug 28 09:23:40 bst sudo[1751]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:40 bst volumio[1349]: info: touch_display: systemctl disable getty@tty1.service succeeded. Aug 28 09:23:40 bst volumio[1349]: info: Volumio called home Aug 28 09:23:40 bst volumio[1349]: info: Spotify config file written Aug 28 09:23:40 bst mpd[1657]: 2026-08-28T09:23:40 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 28 09:23:40 bst volumio[1349]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 28 09:23:40 bst sudo[1751]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:40 bst sudo[1757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 28 09:23:40 bst sudo[1757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:40 bst volumio[1349]: info: Received Get System Info Aug 28 09:23:40 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 09:23:40 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 09:23:40 bst volumio[1349]: info: Discovery: Getting this device information Aug 28 09:23:40 bst volumio[1349]: info: CoreCommandRouter::volumioGetState Aug 28 09:23:40 bst volumio[1349]: info: CorePlayQueue::getTrack 0 Aug 28 09:23:40 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 09:23:40 bst volumio5-onboarding[1636]: time=2026-08-28T09:23:40.265+02:00 level=INFO msg="system info for cfcbd094d7eb059e04013f9909927851" deviceName=BST deviceVariant=volumio deviceModel= softwareVersion=4.119 Aug 28 09:23:40 bst volumio5-onboarding[1636]: time=2026-08-28T09:23:40.298+02:00 level=INFO msg="bootstrapping state" hasInternet=true Aug 28 09:23:40 bst systemd[1]: Started mpd.service - Music Player Daemon. Aug 28 09:23:40 bst systemd[1]: systemd-fsckd.service: Deactivated successfully. Aug 28 09:23:40 bst sudo[1631]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:40 bst 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. Aug 28 09:23:40 bst 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. Aug 28 09:23:40 bst sudo[1621]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:40 bst sudo[1698]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:40 bst systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:23:40 bst go-librespot[1762]: go-librespot daemon starting... Aug 28 09:23:40 bst sudo[1757]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:41 bst volumio[1349]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:41 bst go-librespot[1763]: time="2026-08-28T09:23:41+02:00" level=info msg="running go-librespot 0.7.1" Aug 28 09:23:41 bst go-librespot[1763]: time="2026-08-28T09:23:41+02:00" level=debug msg="app state loaded" Aug 28 09:23:41 bst go-librespot[1763]: time="2026-08-28T09:23:41+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 09:23:41 bst volumio[1349]: info: No need to fix Spotify hosts Aug 28 09:23:41 bst volumio[1349]: info: Received Get System Info Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 09:23:41 bst volumio[1349]: info: Discovery: Getting this device information Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::volumioGetState Aug 28 09:23:41 bst volumio[1349]: info: CorePlayQueue::getTrack 0 Aug 28 09:23:41 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 09:23:41 bst volumio-remote-updater[857]: [2026-08-28 09:23:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1787901819 101 Aug 28 09:23:41 bst go-librespot[1763]: time="2026-08-28T09:23:41+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 09:23:41 bst go-librespot[1763]: time="2026-08-28T09:23:41+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 09:23:41 bst go-librespot[1763]: time="2026-08-28T09:23:41+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 09:23:41 bst go-librespot[1763]: time="2026-08-28T09:23:41+02:00" level=info msg="zeroconf server listening on port 40497" Aug 28 09:23:41 bst go-librespot[1763]: time="2026-08-28T09:23:41+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 28 09:23:41 bst volumio[1349]: 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: 4 Aug 28 09:23:41 bst volumio[1349]: info: touch_display: systemctl daemon-reload succeeded. Aug 28 09:23:42 bst go-librespot[1763]: time="2026-08-28T09:23:42+02:00" level=debug msg="obtained new client token: AAHFutyIIDEaYJnkMEhtJ/fsoOdQ3WkiJ+0q4OVzt9h1U6eMsrtVCXWyAKBUmTgzOjZbAD4PNCsnQfKxhIJuwUi2lp2NujlpTNpUhOHfXEK+dOUrb9DpK98Hwvo54+Ysr0NJqseA88/W51XuBkIhY67HDP8gyOdW3xoWvkiMemA4MgNWq66uARJBtfMHnrSbK6k4Kbkhj+G5QY8PbVYI5ROnaanY25amHVKiC/1AbrJLqbvyNugxeg==" Aug 28 09:23:42 bst sudo[1798]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Aug 28 09:23:42 bst volumio[1349]: info: touch_display: IframeKeyboardBridge extension installed successfully Aug 28 09:23:42 bst sudo[1798]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:42 bst volumio-remote-updater[857]: Test mode disabled Aug 28 09:23:42 bst volumio-remote-updater[857]: Alpha mode disabled Aug 28 09:23:42 bst volumio-remote-updater[857]: Alpha legacy test mode disabled Aug 28 09:23:42 bst go-librespot[1763]: time="2026-08-28T09:23:42+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Aug 28 09:23:42 bst systemd[1]: Started volumio-kiosk.service - Volumio Kiosk. Aug 28 09:23:42 bst go-librespot[1763]: time="2026-08-28T09:23:42+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 28 09:23:42 bst volumio[1349]: info: touch_display: Raspberry Pi Foundation touch screen detected. Aug 28 09:23:42 bst sudo[1798]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:42 bst go-librespot[1763]: time="2026-08-28T09:23:42+02:00" level=debug msg="completed keyexchange" Aug 28 09:23:42 bst go-librespot[1763]: time="2026-08-28T09:23:42+02:00" level=debug msg="completed challenge" Aug 28 09:23:42 bst sudo[1805]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/10-0045/brightness Aug 28 09:23:42 bst volumio[1349]: info: New Spotify access tokenBQCup4edBv... Aug 28 09:23:42 bst sudo[1805]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:42 bst sudo[1808]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Aug 28 09:23:42 bst sudo[1808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:42 bst go-librespot[1763]: time="2026-08-28T09:23:42+02:00" level=info msg="authenticated AP" username="be********nt" Aug 28 09:23:42 bst sudo[1805]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:42 bst volumio[1349]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 28 09:23:42 bst sudo[1808]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:42 bst sudo[1821]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Aug 28 09:23:42 bst sudo[1821]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:42 bst sudo[1821]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:42 bst startx[1833]: X.Org X Server 1.21.1.7 Aug 28 09:23:42 bst startx[1833]: X Protocol Version 11, Revision 0 Aug 28 09:23:42 bst startx[1833]: Current Operating System: Linux bst 6.12.74-v7l+ #1948 SMP Mon Mar 2 11:27:49 GMT 2026 armv7l Aug 28 09:23:42 bst startx[1833]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 cgroup_disable=memory numa_policy=interleave nvme.max_host_mem_size_mb=0 snd_bcm2835.enable_hdmi=0 video=HDMI-A-1:640x480M@60D numa=fake=2 system_heap.max_order=0 iommu_dma_numa_policy=interleave smsc95xx.macaddr=D8:3A:DD:CA:74:BD vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=UUID=dafa3844-b779-48cd-9b4c-01ecfd09e0f4 imgfile=/volumio_current.sqsh bootpart=UUID=3B89-0B23 datapart=UUID=752d19ad-b702-471d-847a-f79ae83515d0 uuidconfig=cmdline.txt rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Aug 28 09:23:42 bst startx[1833]: xorg-server 2:21.1.7-3+rpt3+deb12u11 (https://www.debian.org/support) Aug 28 09:23:42 bst startx[1833]: Current version of pixman: 0.44.0 Aug 28 09:23:42 bst startx[1833]: Before reporting problems, check http://wiki.x.org Aug 28 09:23:42 bst startx[1833]: to make sure that you have the latest version. Aug 28 09:23:42 bst startx[1833]: Markers: (--) probed, (**) from config file, (==) default setting, Aug 28 09:23:42 bst startx[1833]: (++) from command line, (!!) notice, (II) informational, Aug 28 09:23:42 bst startx[1833]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Aug 28 09:23:42 bst startx[1833]: (==) Log file: "/var/log/Xorg.0.log", Time: Fri Aug 28 09:23:42 2026 Aug 28 09:23:42 bst startx[1833]: (==) Using config directory: "/etc/X11/xorg.conf.d" Aug 28 09:23:42 bst startx[1833]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Aug 28 09:23:42 bst go-librespot[1763]: time="2026-08-28T09:23:42+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 09:23:42 bst systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 09:23:42 bst systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 09:23:42 bst systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Aug 28 09:23:42 bst systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 28 09:23:42 bst systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 28 09:23:42 bst volumio[1349]: error: MPD error: The expression evaluated to a falsy value: Aug 28 09:23:42 bst volumio[1349]: assert.ok(self.idling) Aug 28 09:23:42 bst volumio[1349]: error: The expression evaluated to a falsy value: Aug 28 09:23:42 bst volumio[1349]: assert.ok(self.idling) Aug 28 09:23:42 bst volumio[1349]: info: Starting Shairport Sync Aug 28 09:23:42 bst sudo[1848]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 28 09:23:42 bst sudo[1848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:42 bst systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 28 09:23:42 bst systemd[1]: shairport-sync.service: Deactivated successfully. Aug 28 09:23:42 bst systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 28 09:23:42 bst systemd[1]: shairport-sync.service: Consumed 1.614s CPU time. Aug 28 09:23:42 bst volumio[1349]: info: Starting Shairport Sync Aug 28 09:23:42 bst systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 28 09:23:42 bst sudo[1848]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:42 bst volumio[1349]: info: Starting Shairport Sync Aug 28 09:23:43 bst volumio[1349]: error: updateQueue error: null Aug 28 09:23:43 bst volumio[1349]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 28 09:23:43 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 28 09:23:43 bst sudo[1870]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 28 09:23:43 bst sudo[1870]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:43 bst sudo[1854]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 28 09:23:43 bst sudo[1854]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:43 bst sudo[1851]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 28 09:23:43 bst sudo[1851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:23:43 bst systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 28 09:23:43 bst systemd[1]: shairport-sync.service: Deactivated successfully. Aug 28 09:23:43 bst systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 28 09:23:43 bst volumio[1349]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Aug 28 09:23:43 bst volumio[1349]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Aug 28 09:23:43 bst volumio[1349]: info: touch_display: File permissions for backlight brightness control set. Aug 28 09:23:43 bst volumio[1349]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Aug 28 09:23:43 bst volumio[1349]: info: touch_display: Volumio Kiosk started. Aug 28 09:23:43 bst systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 28 09:23:43 bst sudo[1870]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:43 bst systemd[1]: systemd-hostnamed.service: Deactivated successfully. Aug 28 09:23:43 bst volumio[1349]: info: CoreCommandRouter::volumioGetState Aug 28 09:23:43 bst volumio[1349]: info: CorePlayQueue::getTrack 0 Aug 28 09:23:43 bst sudo[1854]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:43 bst sudo[1851]: pam_unix(sudo:session): session closed for user root Aug 28 09:23:43 bst volumio[1349]: info: Completed starting Core Plugins Aug 28 09:23:43 bst volumio[1349]: info: ------------------------------------------- Aug 28 09:23:43 bst volumio[1349]: info: ----- MyVolumio plugins startup ---- Aug 28 09:23:43 bst volumio[1349]: info: ------------------------------------------- Aug 28 09:23:43 bst volumio[1349]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 28 09:23:43 bst volumio[1349]: info: MPD running with PID1657 Aug 28 09:23:43 bst volumio[1349]: ,establishing connection Aug 28 09:23:43 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 28 09:23:43 bst volumio[1349]: info: CoreCommandRouter::volumioGetState Aug 28 09:23:43 bst volumio[1349]: info: CorePlayQueue::getTrack 0 Aug 28 09:23:43 bst volumio[1349]: info: Shairport-Sync Started Aug 28 09:23:43 bst volumio[1349]: Error adding Membership: Error: addMembership EINVAL Aug 28 09:23:43 bst volumio[1349]: info: Shairport-Sync Started Aug 28 09:23:43 bst volumio[1349]: info: Upmpdcli Daemon Started Aug 28 09:23:43 bst volumio[1349]: info: Shairport-Sync Started Aug 28 09:23:43 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 28 09:23:44 bst volumio[1349]: info: touch_display: X display number found: 0 Aug 28 09:23:44 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 28 09:23:44 bst kernel: ------------[ cut here ]------------ Aug 28 09:23:44 bst kernel: WARNING: CPU: 1 PID: 1833 at drivers/gpu/drm/vc4/vc4_hvs.c:1064 __vc4_hvs_stop_channel+0x168/0x1dc [vc4] Aug 28 09:23:44 bst kernel: Modules linked in: md5 ghash_generic gf128mul gcm crypto_null sha512_generic nls_utf8 cifs cifs_arc4 nls_ucs2_utils netfs cifs_md4 cmac algif_hash aes_arm_bs crypto_simd cryptd aes_arm aes_generic algif_skcipher af_alg bnep nft_chain_nat xt_REDIRECT nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 xt_tcpudp nft_compat nf_tables joydev nfnetlink snd_usb_audio brcmfmac_wcc binfmt_misc snd_hwdep 8021q garp stp brcmfmac llc snd_usbmidi_lib hci_uart snd_seq_midi btbcm snd_seq_midi_event brcmutil bluetooth snd_seq cfg80211 edt_ft5x06 snd_rawmidi bcm2835_codec(C) snd_seq_device bcm2835_v4l2(C) bcm2835_isp(C) rpi_hevc_dec bcm2835_mmal_vchiq(C) ecdh_generic raspberrypi_hwmon ecc v4l2_mem2mem vc_sm_cma(C) videobuf2_dma_contig videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 rfkill videodev libaes videobuf2_common mc raspberrypi_gpiomem nvmem_rmem uio_pdrv_genirq uio i2c_dev dm_mod ip_tables x_tables ipv6 ads7846 fb_hx8357d(C) fb_st7789v(C) fb_st7735r(C) fb_ili9341(C) fb_ili9340(C) fbtft(C) panel_waveshare_dsi_v2 Aug 28 09:23:44 bst kernel: panel_waveshare_dsi panel_ilitek_ili9881c panel_raspberrypi_touchscreen pwm_bcm2835 spi_bcm2835 snd_soc_bcm2835_i2s squashfs overlay nls_iso8859_1 fuse tc358762 vc4 rpi_panel_attiny_regulator regmap_i2c snd_soc_hdmi_codec drm_display_helper v3d cec drm_dma_helper gpu_sched drm_shmem_helper snd_soc_core drm_kms_helper snd_compress snd_bcm2835(C) i2c_brcmstb panel_simple snd_pcm_dmaengine i2c_mux_pinctrl i2c_mux drm snd_pcm snd_timer i2c_bcm2835 snd drm_panel_orientation_quirks backlight Aug 28 09:23:44 bst kernel: CPU: 1 UID: 0 PID: 1833 Comm: Xorg Tainted: G C 6.12.74-v7l+ #1948 Aug 28 09:23:44 bst kernel: Tainted: [C]=CRAP Aug 28 09:23:44 bst kernel: Hardware name: BCM2711 Aug 28 09:23:44 bst kernel: Call trace: Aug 28 09:23:44 bst kernel: unwind_backtrace from show_stack+0x18/0x1c Aug 28 09:23:44 bst kernel: show_stack from dump_stack_lvl+0x5c/0x80 Aug 28 09:23:44 bst kernel: dump_stack_lvl from __warn+0x88/0x124 Aug 28 09:23:44 bst kernel: __warn from warn_slowpath_fmt+0x184/0x190 Aug 28 09:23:44 bst kernel: warn_slowpath_fmt from __vc4_hvs_stop_channel+0x168/0x1dc [vc4] Aug 28 09:23:44 bst kernel: __vc4_hvs_stop_channel [vc4] from vc4_crtc_disable+0x138/0x1dc [vc4] Aug 28 09:23:44 bst kernel: vc4_crtc_disable [vc4] from vc4_crtc_atomic_disable+0x9c/0xc0 [vc4] Aug 28 09:23:44 bst kernel: vc4_crtc_atomic_disable [vc4] from disable_outputs+0x268/0x3a0 [drm_kms_helper] Aug 28 09:23:44 bst kernel: disable_outputs [drm_kms_helper] from drm_atomic_helper_commit_modeset_disables+0x18/0x3c [drm_kms_helper] Aug 28 09:23:44 bst kernel: drm_atomic_helper_commit_modeset_disables [drm_kms_helper] from vc4_atomic_commit_tail+0x194/0x998 [vc4] Aug 28 09:23:44 bst kernel: vc4_atomic_commit_tail [vc4] from commit_tail+0xa4/0x18c [drm_kms_helper] Aug 28 09:23:44 bst kernel: commit_tail [drm_kms_helper] from drm_atomic_helper_commit+0x140/0x164 [drm_kms_helper] Aug 28 09:23:44 bst kernel: drm_atomic_helper_commit [drm_kms_helper] from drm_atomic_commit+0xc8/0x100 [drm] Aug 28 09:23:44 bst kernel: drm_atomic_commit [drm] from drm_atomic_helper_set_config+0x90/0xc8 [drm_kms_helper] Aug 28 09:23:44 bst kernel: drm_atomic_helper_set_config [drm_kms_helper] from drm_mode_setcrtc+0x200/0x814 [drm] Aug 28 09:23:44 bst kernel: drm_mode_setcrtc [drm] from drm_ioctl+0x2b4/0x4d0 [drm] Aug 28 09:23:44 bst kernel: drm_ioctl [drm] from sys_ioctl+0x130/0xbcc Aug 28 09:23:44 bst kernel: sys_ioctl from ret_fast_syscall+0x0/0x5c Aug 28 09:23:44 bst kernel: Exception stack(0xf10cdfa8 to 0xf10cdff0) Aug 28 09:23:44 bst kernel: dfa0: 0000000c bed189d0 0000000c c06864a2 bed189d0 bed189b0 Aug 28 09:23:44 bst kernel: dfc0: 0000000c bed189d0 c06864a2 00000036 bed18a88 01977df8 0100bc88 00000000 Aug 28 09:23:44 bst kernel: dfe0: 00000000 bed18998 b69a5000 b69281e4 Aug 28 09:23:44 bst kernel: ---[ end trace 0000000000000000 ]--- Aug 28 09:23:44 bst volumio[1349]: error: updateQueue error: null Aug 28 09:23:44 bst volumio[1349]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Aug 28 09:23:44 bst volumio[1349]: info: Received Get System Info Aug 28 09:23:44 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 09:23:44 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 09:23:44 bst volumio[1349]: info: Discovery: Getting this device information Aug 28 09:23:44 bst volumio[1349]: info: CoreCommandRouter::volumioGetState Aug 28 09:23:44 bst volumio[1349]: info: CorePlayQueue::getTrack 0 Aug 28 09:23:44 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 09:23:44 bst volumio[1349]: info: touch_display: X display number found: 0 Aug 28 09:23:44 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 28 09:23:44 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 28 09:23:44 bst volumio5-onboarding[1636]: time=2026-08-28T09:23:44.456+02:00 level=INFO msg="enabling local network discovery" Aug 28 09:23:44 bst volumio5-onboarding[1636]: time=2026-08-28T09:23:44.486+02:00 level=INFO msg="enabling BLE discovery" Aug 28 09:23:44 bst volumio[1349]: info: CoreCommandRouter::volumioGetState Aug 28 09:23:44 bst volumio[1349]: info: CorePlayQueue::getTrack 0 Aug 28 09:23:44 bst volumio[1349]: info: CoreCommandRouter::volumioGetState Aug 28 09:23:44 bst volumio[1349]: info: CorePlayQueue::getTrack 0 Aug 28 09:23:44 bst volumio[1349]: info: go-librespot daemon successfully initialized Aug 28 09:23:44 bst volumio[1349]: SPOTIFY: User informations: {"account_id":"LvkMLp41tx","country":"BE","display_name":"bertsteelant","email":"bertsteelant@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/bertsteelant"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/bertsteelant","id":"bertsteelant","images":[],"product":"premium","type":"user","uri":"spotify:user:bertsteelant"} Aug 28 09:23:44 bst volumio[1349]: info: Spotify Successfully logged in Aug 28 09:23:44 bst volumio[1349]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 28 09:23:44 bst volumio[1349]: info: [1787901824923] CoreMusicLibrary::Adding element Spotify Aug 28 09:23:44 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 28 09:23:44 bst volumio[1349]: Cannot find translation for source Spotify Aug 28 09:23:45 bst volumio[1349]: info: touch_display: Setting screensaver timeout to 120 seconds. Aug 28 09:23:45 bst systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 28 09:23:45 bst systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:23:45 bst systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:23:45 bst go-librespot[1976]: go-librespot daemon starting... Aug 28 09:23:45 bst volumio5-onboarding[1636]: time=2026-08-28T09:23:45.571+02:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 28 09:23:45 bst go-librespot[1977]: time="2026-08-28T09:23:45+02:00" level=info msg="running go-librespot 0.7.1" Aug 28 09:23:45 bst go-librespot[1977]: time="2026-08-28T09:23:45+02:00" level=debug msg="app state loaded" Aug 28 09:23:45 bst go-librespot[1977]: time="2026-08-28T09:23:45+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 09:23:45 bst go-librespot[1977]: time="2026-08-28T09:23:45+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 09:23:45 bst go-librespot[1977]: time="2026-08-28T09:23:45+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 09:23:45 bst go-librespot[1977]: time="2026-08-28T09:23:45+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 09:23:45 bst go-librespot[1977]: time="2026-08-28T09:23:45+02:00" level=info msg="zeroconf server listening on port 46385" Aug 28 09:23:45 bst go-librespot[1977]: time="2026-08-28T09:23:45+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 28 09:23:46 bst go-librespot[1977]: time="2026-08-28T09:23:46+02:00" level=debug msg="obtained new client token: AAEPWnmJr6MBk4MMtGeFVboA2zDshhxLmCd5IjQ8w9Ly3wRxCgbgNEo3Ja3NQCOCQYjWOIhr/eD+wN008DZDeQ+HSw+Rdts7a7KpNTZ+kXCYJqpPXrg1QfwmzErHRRvtHDmJL/oV+KoliO6LCnliFLNhtRrE+5vhIbC8jZc+b35Bu/QKPpyxE+9SkHwaOe/hGceeLqs5Ok9deYrzOnB6Las6FdR/PjtkQccmg+o1MT88OpEjrEUXjPZv" Aug 28 09:23:46 bst go-librespot[1977]: time="2026-08-28T09:23:46+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 28 09:23:46 bst go-librespot[1977]: time="2026-08-28T09:23:46+02:00" level=debug msg="completed keyexchange" Aug 28 09:23:46 bst go-librespot[1977]: time="2026-08-28T09:23:46+02:00" level=debug msg="completed challenge" Aug 28 09:23:46 bst go-librespot[1977]: time="2026-08-28T09:23:46+02:00" level=info msg="authenticated AP" username="be********nt" Aug 28 09:23:46 bst go-librespot[1977]: time="2026-08-28T09:23:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 09:23:46 bst systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 09:23:46 bst systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 09:23:47 bst volumio[1349]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 28 09:23:47 bst volumio[1349]: info: Initializing connection to go-librespot Websocket Aug 28 09:23:48 bst volumio[1349]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 09:23:49 bst systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 28 09:23:49 bst systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:23:49 bst systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:23:49 bst go-librespot[2044]: go-librespot daemon starting... Aug 28 09:23:49 bst go-librespot[2045]: time="2026-08-28T09:23:49+02:00" level=info msg="running go-librespot 0.7.1" Aug 28 09:23:49 bst go-librespot[2045]: time="2026-08-28T09:23:49+02:00" level=debug msg="app state loaded" Aug 28 09:23:49 bst go-librespot[2045]: time="2026-08-28T09:23:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 09:23:49 bst go-librespot[2045]: time="2026-08-28T09:23:49+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 09:23:49 bst go-librespot[2045]: time="2026-08-28T09:23:49+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 09:23:49 bst go-librespot[2045]: time="2026-08-28T09:23:49+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 09:23:49 bst go-librespot[2045]: time="2026-08-28T09:23:49+02:00" level=info msg="zeroconf server listening on port 34345" Aug 28 09:23:49 bst go-librespot[2045]: time="2026-08-28T09:23:49+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 28 09:23:50 bst go-librespot[2045]: time="2026-08-28T09:23:50+02:00" level=debug msg="obtained new client token: AAEnpG7MYYnnJr4iPqUFZ+9ap2qting+i3wQ5HzgiDFmPEdyPAnt0gZxZOnsq87SWqlERSXr045ys5Xx6guQ2ZTLezxZK+j0czJspIkPHnCg20dtJjk1N3pADKT0R2Qjdog5qRHmVN2qwZbyyXyxWVURym5stn7KKAJ4P7l7im7eLJKEhM0mYXNE/uXzZULlmbirLqRuAw/O+uy/7ckJf18rOOk495/wdZ5TVog80gRvcfu/Kcs01Qbu" Aug 28 09:23:50 bst go-librespot[2045]: time="2026-08-28T09:23:50+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 28 09:23:50 bst go-librespot[2045]: time="2026-08-28T09:23:50+02:00" level=debug msg="completed keyexchange" Aug 28 09:23:50 bst go-librespot[2045]: time="2026-08-28T09:23:50+02:00" level=debug msg="completed challenge" Aug 28 09:23:50 bst go-librespot[2045]: time="2026-08-28T09:23:50+02:00" level=info msg="authenticated AP" username="be********nt" Aug 28 09:23:50 bst go-librespot[2045]: time="2026-08-28T09:23:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 09:23:50 bst systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 09:23:50 bst systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 09:23:51 bst volumio[1349]: info: Initializing connection to go-librespot Websocket Aug 28 09:23:51 bst volumio[1349]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 28 09:23:51 bst volumio[1349]: info: Adding plugin bluetooth to MyMusic Plugins Aug 28 09:23:51 bst volumio[1349]: info: Adding plugin multiroom to MyMusic Plugins Aug 28 09:23:51 bst volumio[1349]: info: Adding plugin metavolumio to MyMusic Plugins Aug 28 09:23:51 bst volumio[1349]: info: Adding plugin cd_controller to MyMusic Plugins Aug 28 09:23:51 bst volumio[1349]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 28 09:23:51 bst volumio[1349]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 28 09:23:51 bst volumio[1349]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 28 09:23:51 bst volumio[1349]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 28 09:23:53 bst systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Aug 28 09:23:53 bst systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 28 09:23:53 bst systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:23:53 bst systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:23:53 bst go-librespot[2119]: go-librespot daemon starting... Aug 28 09:23:53 bst go-librespot[2122]: time="2026-08-28T09:23:53+02:00" level=info msg="running go-librespot 0.7.1" Aug 28 09:23:53 bst go-librespot[2122]: time="2026-08-28T09:23:53+02:00" level=debug msg="app state loaded" Aug 28 09:23:53 bst go-librespot[2122]: time="2026-08-28T09:23:53+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 09:23:53 bst go-librespot[2122]: time="2026-08-28T09:23:53+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-gew1.spotify.com:80]" Aug 28 09:23:53 bst go-librespot[2122]: time="2026-08-28T09:23:53+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 28 09:23:53 bst go-librespot[2122]: time="2026-08-28T09:23:53+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 28 09:23:53 bst go-librespot[2122]: time="2026-08-28T09:23:53+02:00" level=info msg="zeroconf server listening on port 45471" Aug 28 09:23:53 bst go-librespot[2122]: time="2026-08-28T09:23:53+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 28 09:23:53 bst go-librespot[2122]: time="2026-08-28T09:23:53+02:00" level=debug msg="obtained new client token: AAFQb6N/zRBgdh/QZP0cb58Vb8zW6+EcpbRF2t57YMeL2NnGpxbpuSmoBMHuphsKi5c2zbSazKvFwdfpgsmcE2dO5ZadDxpVvJMkHZAk/CHhLbufrbLhPm285E6GiCgT3tDBlj6/dtwbvhsst4ERcP0gCSV0RiqvdwpSjrEhTX3ycFrQ2RodHAu8SEqMUrl3vZVPycFQWLw+C03g/ihzY/MgYrleUqa8nGNyK6uNsGo4B/viYgyIrKoTfCQ=" Aug 28 09:23:54 bst go-librespot[2122]: time="2026-08-28T09:23:54+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 28 09:23:54 bst go-librespot[2122]: time="2026-08-28T09:23:54+02:00" level=debug msg="completed keyexchange" Aug 28 09:23:54 bst go-librespot[2122]: time="2026-08-28T09:23:54+02:00" level=debug msg="completed challenge" Aug 28 09:23:54 bst go-librespot[2122]: time="2026-08-28T09:23:54+02:00" level=info msg="authenticated AP" username="be********nt" Aug 28 09:23:54 bst go-librespot[2122]: time="2026-08-28T09:23:54+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 09:23:54 bst systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 09:23:54 bst systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 09:23:54 bst upmpdcli[2143]: writing RSA key Aug 28 09:23:55 bst systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 28 09:23:55 bst systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 28 09:23:57 bst volumio[1349]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 28 09:23:57 bst volumio[1349]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 28 09:23:57 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 28 09:23:57 bst volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 28 09:23:57 bst volumio[1349]: info: Starting MyVolumio Remote Streaming Endpoints Aug 28 09:23:57 bst volumio[1349]: info: MyVolumio login type: Token Aug 28 09:23:57 bst volumio[1349]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 28 09:23:57 bst volumio[1349]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 28 09:23:57 bst systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 28 09:23:57 bst systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:23:57 bst systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:23:57 bst go-librespot[2186]: go-librespot daemon starting... Aug 28 09:23:57 bst go-librespot[2188]: time="2026-08-28T09:23:57+02:00" level=info msg="running go-librespot 0.7.1" Aug 28 09:23:57 bst go-librespot[2188]: time="2026-08-28T09:23:57+02:00" level=debug msg="app state loaded" Aug 28 09:23:57 bst go-librespot[2188]: time="2026-08-28T09:23:57+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 09:23:57 bst go-librespot[2188]: time="2026-08-28T09:23:57+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-gew1.spotify.com:80]" Aug 28 09:23:57 bst go-librespot[2188]: time="2026-08-28T09:23:57+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 28 09:23:57 bst go-librespot[2188]: time="2026-08-28T09:23:57+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 28 09:23:57 bst go-librespot[2188]: time="2026-08-28T09:23:57+02:00" level=info msg="zeroconf server listening on port 43797" Aug 28 09:23:57 bst go-librespot[2188]: time="2026-08-28T09:23:57+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 28 09:23:58 bst go-librespot[2188]: time="2026-08-28T09:23:58+02:00" level=debug msg="obtained new client token: AAFUHuiIAaqGobyKTq3P1igwVVJzXE5ZtV0OaPu/oVW+RxStYKRszT/ggu3d+Y4LsXotZYJklWbKygphEclYQ3HvCBMbPtNseUedZrt5ZizSMT4/nN8f3+AVtlIoRk5AaXW+TOg+1zhmGhVKJwFrsrDRMCf6A3jEJQtb8Nnkv020A6Q9qoDYfv32ajoT5PD3pF7/1DJrll9IsjHP1TmE1FrLSNTcVxpHziJjRCSWyW8arQCWLjzjxRmO" Aug 28 09:23:58 bst go-librespot[2188]: time="2026-08-28T09:23:58+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 28 09:23:58 bst go-librespot[2188]: time="2026-08-28T09:23:58+02:00" level=debug msg="completed keyexchange" Aug 28 09:23:58 bst go-librespot[2188]: time="2026-08-28T09:23:58+02:00" level=debug msg="completed challenge" Aug 28 09:23:58 bst go-librespot[2188]: time="2026-08-28T09:23:58+02:00" level=info msg="authenticated AP" username="be********nt" Aug 28 09:23:58 bst go-librespot[2188]: time="2026-08-28T09:23:58+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 09:23:58 bst systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 09:23:58 bst systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 09:24:01 bst systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 28 09:24:01 bst systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:24:01 bst volumio[1349]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 28 09:24:01 bst volumio[1349]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 28 09:24:01 bst volumio[1349]: info: Streaming services startup Aug 28 09:24:01 bst volumio[1349]: info: Starting Streaming Daemon Aug 28 09:24:01 bst systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:24:01 bst sudo[2199]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 28 09:24:01 bst go-librespot[2197]: go-librespot daemon starting... Aug 28 09:24:01 bst volumio[1349]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 28 09:24:01 bst sudo[2199]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:24:01 bst go-librespot[2204]: time="2026-08-28T09:24:01+02:00" level=info msg="running go-librespot 0.7.1" Aug 28 09:24:01 bst go-librespot[2204]: time="2026-08-28T09:24:01+02:00" level=debug msg="app state loaded" Aug 28 09:24:01 bst go-librespot[2204]: time="2026-08-28T09:24:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 09:24:01 bst sudo[2199]: pam_unix(sudo:session): session closed for user root Aug 28 09:24:01 bst go-librespot[2204]: time="2026-08-28T09:24:01+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]" Aug 28 09:24:01 bst go-librespot[2204]: time="2026-08-28T09:24:01+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]" Aug 28 09:24:01 bst go-librespot[2204]: time="2026-08-28T09:24:01+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]" Aug 28 09:24:01 bst go-librespot[2204]: time="2026-08-28T09:24:01+02:00" level=info msg="zeroconf server listening on port 35725" Aug 28 09:24:01 bst go-librespot[2204]: time="2026-08-28T09:24:01+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 28 09:24:01 bst volumio[1349]: info: Initializing connection to go-librespot Websocket Aug 28 09:24:02 bst volumio[1349]: error: Cannot start Volumio Streaming Daemon Aug 28 09:24:02 bst volumio[1349]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 28 09:24:02 bst volumio[1349]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 28 09:24:02 bst go-librespot[2204]: time="2026-08-28T09:24:02+02:00" level=debug msg="obtained new client token: AAF2tzFck3ZKAr+lMObZOsRJIDvhtLctw8udiV7HpiDApFzqFyem32H5tHE+zznslG68YaO49D3KyCMPf6jgk1pdcdjYGg26oIoUkyqfQTw3m9/BHr9GYdWJrAtP4QMr7wYpQhXPcMfwSDT9zR1XqJAeKARIUyCpbcod7DoNmysIR4EkZMOCOMeANRdeaKvLxUeo+MqyJjMG6vztTWxabn+aEw0D6NX9vMv85gTfX60CSEv9jK+9dPzx" Aug 28 09:24:02 bst go-librespot[2204]: time="2026-08-28T09:24:02+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 28 09:24:02 bst go-librespot[2204]: time="2026-08-28T09:24:02+02:00" level=debug msg="completed keyexchange" Aug 28 09:24:02 bst go-librespot[2204]: time="2026-08-28T09:24:02+02:00" level=debug msg="completed challenge" Aug 28 09:24:02 bst go-librespot[2204]: time="2026-08-28T09:24:02+02:00" level=debug msg="new websocket client" Aug 28 09:24:02 bst volumio[1349]: info: Connection to go-librespot Websocket established Aug 28 09:24:02 bst go-librespot[2204]: time="2026-08-28T09:24:02+02:00" level=info msg="authenticated AP" username="be********nt" Aug 28 09:24:02 bst go-librespot[2204]: time="2026-08-28T09:24:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 09:24:02 bst systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 09:24:02 bst systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 09:24:02 bst volumio[1349]: info: Connection to go-librespot Websocket closed Aug 28 09:24:02 bst volumio[1349]: error: MyVolumio Custom Token format not valid, refreshing it Aug 28 09:24:03 bst volumio[1349]: info: MyVolumio login type: Token Aug 28 09:24:04 bst volumio[1349]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 28 09:24:05 bst volumio[1349]: info: Getting Spotify volume Aug 28 09:24:05 bst volumio[1349]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 28 09:24:05 bst systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 28 09:24:05 bst systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:24:05 bst volumio[1349]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 09:24:05 bst volumio[1349]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 28 09:24:05 bst volumio[1349]: errno: -111, Aug 28 09:24:05 bst volumio[1349]: code: 'ECONNREFUSED', Aug 28 09:24:05 bst volumio[1349]: syscall: 'connect', Aug 28 09:24:05 bst volumio[1349]: address: '127.0.0.1', Aug 28 09:24:05 bst volumio[1349]: port: 9879, Aug 28 09:24:05 bst volumio[1349]: response: undefined Aug 28 09:24:05 bst volumio[1349]: } Aug 28 09:24:05 bst volumio[1349]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 28 09:24:05 bst systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:24:05 bst go-librespot[2218]: go-librespot daemon starting... Aug 28 09:24:05 bst go-librespot[2221]: time="2026-08-28T09:24:05+02:00" level=info msg="running go-librespot 0.7.1" Aug 28 09:24:05 bst go-librespot[2221]: time="2026-08-28T09:24:05+02:00" level=debug msg="app state loaded" Aug 28 09:24:05 bst go-librespot[2221]: time="2026-08-28T09:24:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 09:24:05 bst go-librespot[2221]: time="2026-08-28T09:24:05+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-gew1.spotify.com:80]" Aug 28 09:24:05 bst go-librespot[2221]: time="2026-08-28T09:24:05+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 28 09:24:05 bst go-librespot[2221]: time="2026-08-28T09:24:05+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 28 09:24:05 bst go-librespot[2221]: time="2026-08-28T09:24:05+02:00" level=info msg="zeroconf server listening on port 41445" Aug 28 09:24:05 bst go-librespot[2221]: time="2026-08-28T09:24:05+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 28 09:24:06 bst go-librespot[2221]: time="2026-08-28T09:24:06+02:00" level=debug msg="obtained new client token: AAGqKjkIidPOU3dOuosWPzdv9aLpIzLrmEoqvTjnK0p6X0kjOPAuvT9p9WkOdQQuijjwFCT8YjoK4SSKSBdEz0/iMgYGDDvrRm9LD1QoAHqOSzZFOEHndt9wuLJygSfD36nwItErdL67V1mfyo3ta47ELfFcrM8unb7No/g+8HYbaMIiboRgB92Dggw/vuU98Ofl6YdHTkWr+cbUJxVWgaejNfOHJpIwc5Nj1fEj/Yo0NRlaFt1aRulf" Aug 28 09:24:06 bst go-librespot[2221]: time="2026-08-28T09:24:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 28 09:24:06 bst go-librespot[2221]: time="2026-08-28T09:24:06+02:00" level=debug msg="completed keyexchange" Aug 28 09:24:06 bst go-librespot[2221]: time="2026-08-28T09:24:06+02:00" level=debug msg="completed challenge" Aug 28 09:24:06 bst go-librespot[2221]: time="2026-08-28T09:24:06+02:00" level=info msg="authenticated AP" username="be********nt" Aug 28 09:24:06 bst go-librespot[2221]: time="2026-08-28T09:24:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 09:24:06 bst systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 09:24:06 bst systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 09:24:09 bst sudo[2257]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-28 09:23' Aug 28 09:24:09 bst sudo[2257]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:24:09 bst systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 28 09:24:09 bst systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:24:09 bst systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:24:09 bst go-librespot[2259]: go-librespot daemon starting... Aug 28 09:24:09 bst go-librespot[2260]: time="2026-08-28T09:24:09+02:00" level=info msg="running go-librespot 0.7.1" Aug 28 09:24:09 bst go-librespot[2260]: time="2026-08-28T09:24:09+02:00" level=debug msg="app state loaded" Aug 28 09:24:09 bst go-librespot[2260]: time="2026-08-28T09:24:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" 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"