Aug 27 07:09:08 dac systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 27 07:09:08 dac systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 27 07:09:08 dac systemd[1]: setdatetime-helper.service: Consumed 1.284s CPU time. Aug 27 07:09:08 dac systemd[1]: Reached target multi-user.target - Multi-User System. Aug 27 07:09:08 dac systemd[1]: Reached target graphical.target - Graphical Interface. Aug 27 07:09:08 dac systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Aug 27 07:09:08 dac systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems... Aug 27 07:09:08 dac systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Aug 27 07:09:08 dac systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Aug 27 07:09:08 dac systemd[1]: e2scrub_all.service: Deactivated successfully. Aug 27 07:09:08 dac systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems. Aug 27 07:09:08 dac systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Aug 27 07:09:08 dac systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Aug 27 07:09:08 dac systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Aug 27 07:09:08 dac systemd[1]: dpkg-db-backup.service: Deactivated successfully. Aug 27 07:09:08 dac systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Aug 27 07:09:08 dac systemd[1]: Startup finished in 14.469s (kernel) + 16.892s (userspace) = 31.361s. Aug 27 07:09:08 dac volumio-remote-updater[810]: [2026-08-27 07:09:08] [connect] Successful connection Aug 27 07:09:08 dac volumio[1267]: info: Starting UPNP Browser Aug 27 07:09:08 dac volumio[1267]: info: Loading plugin "alarm-clock"... Aug 27 07:09:08 dac volumio[1267]: info: Loading plugin "airplay_emulation"... Aug 27 07:09:08 dac volumio[1267]: info: Starting Shairport Sync Aug 27 07:09:08 dac volumio[1267]: info: Loading plugin "last_100"... Aug 27 07:09:08 dac volumio[1267]: info: Loading plugin "webradio"... Aug 27 07:09:09 dac volumio[1267]: info: Loading plugin "i2s_dacs"... Aug 27 07:09:09 dac volumio[1267]: info: Loading plugin "volumiodiscovery"... Aug 27 07:09:09 dac volumio[1267]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 27 07:09:09 dac volumio[1267]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 07:09:09 dac volumio[1267]: *** WARNING *** For more information see Aug 27 07:09:09 dac volumio[1267]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 27 07:09:09 dac volumio[1267]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 07:09:09 dac node[1267]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 27 07:09:09 dac volumio[1267]: *** WARNING *** For more information see Aug 27 07:09:09 dac node[1267]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 07:09:09 dac node[1267]: *** WARNING *** For more information see Aug 27 07:09:09 dac node[1267]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 27 07:09:09 dac node[1267]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 07:09:09 dac node[1267]: *** WARNING *** For more information see Aug 27 07:09:09 dac volumio[1267]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 27 07:09:09 dac volumio[1267]: info: Discovery: Started advertising with name: DAC Aug 27 07:09:09 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 27 07:09:09 dac volumio[1267]: info: Loading plugin "spop"... Aug 27 07:09:10 dac nmbd[1228]: [2026/08/27 07:09:10.714053, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Aug 27 07:09:10 dac nmbd[1228]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.21 for name WORKGROUP<1d>. Aug 27 07:09:10 dac nmbd[1228]: This response was from IP 192.168.1.10, reporting an IP address of 192.168.1.10. Aug 27 07:09:11 dac volumio[1267]: info: Loading plugin "now_playing"... Aug 27 07:09:11 dac systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Aug 27 07:09:11 dac systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 27 07:09:11 dac systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 27 07:09:11 dac upmpdcli[1485]: Could not open config: /tmp/upmpdcli.conf Aug 27 07:09:11 dac systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 27 07:09:11 dac systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 27 07:09:13 dac volumio[1267]: info: Loading plugin "outputs"... Aug 27 07:09:13 dac volumio[1267]: info: Loading plugin "albumart"... Aug 27 07:09:13 dac volumio[1267]: info: Plugin example_plugin is not enabled Aug 27 07:09:13 dac volumio[1267]: info: Loading plugin "inputs"... Aug 27 07:09:13 dac volumio[1267]: info: Loading plugin "updater_comm"... Aug 27 07:09:13 dac volumio[1267]: info: Plugin mpdemulation is not enabled Aug 27 07:09:13 dac volumio[1267]: info: Loading plugin "rest_api"... Aug 27 07:09:13 dac volumio[1267]: info: Loading plugin "websocket"... Aug 27 07:09:13 dac volumio[1267]: info: Starting Socket.io Server version 1.7.4 Aug 27 07:09:13 dac volumio[1267]: info: Loading plugin "fusiondsp"... Aug 27 07:09:14 dac volumio[1487]: Forking 3 albumart workers Aug 27 07:09:15 dac volumio[1267]: info: Applying required configuration parameters for plugin fusiondsp Aug 27 07:09:15 dac volumio[1267]: info: Loading plugin "mqtt_client"... Aug 27 07:09:18 dac volumio[1498]: Starting albumart workers Aug 27 07:09:20 dac volumio[1497]: Starting albumart workers Aug 27 07:09:20 dac volumio[1267]: info: Loading plugin "touch_display"... Aug 27 07:09:20 dac volumio[1499]: Starting albumart workers Aug 27 07:09:21 dac volumio[1267]: info: Applying required configuration parameters for plugin touch_display Aug 27 07:09:22 dac volumio[1267]: info: Loading i18n strings for locale en Aug 27 07:09:22 dac volumio[1267]: Updating browse sources language Aug 27 07:09:22 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 07:09:22 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 07:09:22 dac volumio[1267]: info: CoreCommandRouter::initPlayerControls Aug 27 07:09:22 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:22 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:22 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:22 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:22 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:22 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:22 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:22 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:22 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 07:09:22 dac volumio[1267]: Express server listening on port 3000 Aug 27 07:09:22 dac volumio[1267]: [Metrics] WebUI: 19s 540.05ms Aug 27 07:09:22 dac volumio[1267]: info: CoreStateMachine::resetVolumioState Aug 27 07:09:23 dac volumio[1267]: info: CoreStateMachine::getcurrentVolume Aug 27 07:09:23 dac volumio[1267]: info: CoreCommandRouter::volumioRetrievevolume Aug 27 07:09:23 dac sudo[1564]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 07:09:23 dac sudo[1564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:23 dac sudo[1566]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 07:09:23 dac sudo[1566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:23 dac sudo[1566]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:23 dac volumio[1267]: info: Volumio Network Manager: Network status updated: 1 Aug 27 07:09:23 dac sudo[1564]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:23 dac volumio-remote-updater[810]: [2026-08-27 07:09:23] [connect] Successful connection Aug 27 07:09:23 dac systemd[1]: systemd-fsckd.service: Deactivated successfully. Aug 27 07:09:23 dac volumio[1267]: info: VolumeController:: Volume=55 Mute =false Aug 27 07:09:23 dac volumio[1267]: info: CoreStateMachine::pushState Aug 27 07:09:23 dac volumio[1267]: info: CorePlayQueue::getTrack 0 Aug 27 07:09:23 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 07:09:23 dac volumio[1267]: info: CoreCommandRouter::volumioPushState Aug 27 07:09:23 dac volumio[1267]: info: CoreStateMachine::updateTrackBlock Aug 27 07:09:24 dac volumio[1267]: info: CorePlayQueue::getTrackBlock Aug 27 07:09:24 dac volumio[1267]: info: CoreCommandRouter::volumioRetrievevolume Aug 27 07:09:24 dac volumio[1267]: info: CoreCommandRouter::volumioGetState Aug 27 07:09:24 dac volumio[1267]: info: CorePlayQueue::getTrack 0 Aug 27 07:09:24 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 07:09:24 dac volumio[1267]: info: Reloading queue from file Aug 27 07:09:24 dac volumio[1267]: 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 27 07:09:24 dac volumio[1267]: info: CoreStateMachine::setRepeat null single undefined Aug 27 07:09:24 dac volumio[1267]: info: CoreStateMachine::pushState Aug 27 07:09:24 dac volumio[1267]: info: CorePlayQueue::getTrack 0 Aug 27 07:09:24 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 07:09:24 dac volumio[1267]: info: CoreCommandRouter::volumioPushState Aug 27 07:09:24 dac volumio[1267]: info: CoreStateMachine::setRandom false Aug 27 07:09:24 dac volumio[1267]: info: CoreStateMachine::pushState Aug 27 07:09:24 dac volumio[1267]: info: CorePlayQueue::getTrack 0 Aug 27 07:09:24 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 07:09:24 dac volumio[1267]: info: CoreCommandRouter::volumioPushState Aug 27 07:09:24 dac volumio-remote-updater[810]: [2026-08-27 07:09:24] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1787810963 101 Aug 27 07:09:24 dac volumio[1267]: 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: 2 Aug 27 07:09:24 dac volumio[1267]: info: Setting Device type: Raspberry PI Aug 27 07:09:24 dac volumio[1267]: info: Completed loading Core Plugins Aug 27 07:09:24 dac volumio[1267]: info: Preparing to generate the ALSA configuration file Aug 27 07:09:24 dac volumio[1267]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 27 07:09:24 dac volumio[1267]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d03114 Aug 27 07:09:24 dac volumio[1267]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 27 07:09:24 dac volumio[1267]: info: Listing playlists Aug 27 07:09:24 dac volumio[1267]: info: Listing playlists Aug 27 07:09:24 dac volumio[1267]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Aug 27 07:09:24 dac volumio[1267]: info: Reading ALSA contributions from plugins. Aug 27 07:09:24 dac volumio[1267]: info: VolumeController:: Volume=55 Mute =false Aug 27 07:09:24 dac volumio[1267]: info: CoreStateMachine::pushState Aug 27 07:09:24 dac volumio[1267]: info: CorePlayQueue::getTrack 0 Aug 27 07:09:24 dac volumio[1267]: info: CoreCommandRouter::volumioPushState Aug 27 07:09:24 dac sudo[1581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 27 07:09:24 dac sudo[1581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:25 dac volumio[1267]: info: Asound.conf file written Aug 27 07:09:25 dac sudo[1586]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Aug 27 07:09:25 dac sudo[1586]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:25 dac sudo[1586]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:25 dac volumio[1267]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Aug 27 07:09:25 dac volumio[1267]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Aug 27 07:09:25 dac volumio[1267]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Aug 27 07:09:25 dac volumio[1267]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2 Aug 27 07:09:25 dac volumio[1267]: info: Output device has changed, restarting MPD Aug 27 07:09:25 dac volumio[1267]: info: Output device has changed, restarting Shairport Sync Aug 27 07:09:25 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:25 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 07:09:25 dac sudo[1595]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 27 07:09:25 dac sudo[1595]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:25 dac sudo[1593]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 27 07:09:25 dac sudo[1593]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:25 dac sudo[1593]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:25 dac volumio[1267]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 07:09:25 dac volumio[1267]: info: ___________ START PLUGINS ___________ Aug 27 07:09:25 dac volumio[1267]: info: ControllerMpd::onStart: Initializing MPD Aug 27 07:09:25 dac volumio[1267]: info: Creating MPD Configuration file Aug 27 07:09:25 dac systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 27 07:09:25 dac systemd[1]: Starting mpd.service - Music Player Daemon... Aug 27 07:09:25 dac sudo[1604]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 27 07:09:25 dac sudo[1604]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:25 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 07:09:25 dac volumio[1267]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 07:09:25 dac volumio[1267]: info: [1787810965810] CoreMusicLibrary::Adding element Media Servers Aug 27 07:09:25 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 07:09:25 dac sudo[1609]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 27 07:09:25 dac sudo[1607]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 27 07:09:25 dac sudo[1607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:25 dac sudo[1609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:25 dac sudo[1605]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 27 07:09:25 dac sudo[1605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 27 07:09:25 dac sudo[1607]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:25 dac volumio[1267]: info: UPNP Browser: Client initialized successfully Aug 27 07:09:25 dac sudo[1614]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 27 07:09:25 dac sudo[1605]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:25 dac systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 27 07:09:25 dac sudo[1604]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:25 dac systemd[1]: mpd.service: Deactivated successfully. Aug 27 07:09:25 dac systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 27 07:09:25 dac systemd[1]: mpd.socket: Deactivated successfully. Aug 27 07:09:25 dac systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 27 07:09:25 dac systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 27 07:09:25 dac systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 27 07:09:25 dac systemd[1]: Starting mpd.service - Music Player Daemon... Aug 27 07:09:26 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:26 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 07:09:26 dac volumio[1267]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 07:09:26 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:26 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 07:09:26 dac sudo[1617]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 27 07:09:26 dac sudo[1617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 27 07:09:26 dac sudo[1629]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 27 07:09:26 dac sudo[1617]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:26 dac volumio[1267]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 07:09:26 dac volumio[1267]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 07:09:26 dac volumio[1267]: info: [1787810966309] CoreMusicLibrary::Adding element Last_100 Aug 27 07:09:26 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 07:09:26 dac volumio[1267]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 07:09:26 dac volumio[1267]: info: [1787810966335] CoreMusicLibrary::Adding element Webradio Aug 27 07:09:26 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 07:09:26 dac volumio5-onboarding[1613]: time=2026-08-27T07:09:26.358+01:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 27 07:09:26 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 07:09:26 dac volumio[1267]: info: Initializing BBC Radios Aug 27 07:09:26 dac kernel: edt_ft5x06 10-0038: Unable to fetch data, error: -121 Aug 27 07:09:26 dac systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Aug 27 07:09:26 dac systemd[1]: systemd-hostnamed.service: Deactivated successfully. Aug 27 07:09:26 dac systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 27 07:09:26 dac systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 27 07:09:26 dac sudo[1581]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:26 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 07:09:26 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 07:09:27 dac volumio[1267]: info: Creating Spotify config file Aug 27 07:09:27 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:28 dac volumio[1267]: info: [now-playing] ConfigUpdater: config is up to date. Aug 27 07:09:28 dac volumio[1267]: info: FusionDsp - CamillaDSP binary found. Aug 27 07:09:28 dac volumio[1267]: info: Loading i18n strings for locale en Aug 27 07:09:28 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Aug 27 07:09:28 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:28 dac volumio[1267]: info: FusionDsp - mixtype--------------------- Hardware Aug 27 07:09:28 dac volumio[1267]: info: [MQTT] Starting MQTT Client plugin Aug 27 07:09:28 dac volumio[1267]: info: [MQTT] Device ID: lounge Aug 27 07:09:28 dac volumio[1267]: info: [MQTT] Base topic: volumio Aug 27 07:09:28 dac volumio[1267]: info: [MQTT] Connecting to MQTT broker: mqtt://192.168.1.11:1883 Aug 27 07:09:29 dac volumio[1267]: info: Loading i18n strings for locale en Aug 27 07:09:29 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 07:09:29 dac volumio[1267]: info: Volumio Calling Home Aug 27 07:09:29 dac sudo[1677]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge Aug 27 07:09:29 dac sudo[1677]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:29 dac sudo[1677]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:29 dac volumio[1267]: info: Preparing to generate the ALSA configuration file Aug 27 07:09:30 dac sudo[1683]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Aug 27 07:09:30 dac sudo[1683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:30 dac sudo[1686]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Aug 27 07:09:30 dac sudo[1683]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:30 dac sudo[1688]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Aug 27 07:09:30 dac sudo[1688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:30 dac sudo[1686]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:30 dac mpd[1630]: 2026-08-27T07:09:30 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 27 07:09:30 dac systemd[1]: Reloading. Aug 27 07:09:31 dac volumio[1267]: info: [now-playing] App is listening on port 4004. Aug 27 07:09:31 dac volumio[1267]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Aug 27 07:09:31 dac systemd[1]: Started mpd.service - Music Player Daemon. Aug 27 07:09:31 dac sudo[1609]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:31 dac systemd[1]: Reloading. Aug 27 07:09:31 dac sudo[1688]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:31 dac volumio[1267]: info: Discovery: adding 8d39747c-6999-4851-9c27-976b2f160fae Aug 27 07:09:31 dac volumio[1267]: info: Discovery: Found device DAC Aug 27 07:09:31 dac volumio[1267]: info: CoreCommandRouter::volumioGetState Aug 27 07:09:31 dac volumio[1267]: info: CorePlayQueue::getTrack 0 Aug 27 07:09:31 dac volumio[1267]: info: Discovery: this is already registered, 8d39747c-6999-4851-9c27-976b2f160fae Aug 27 07:09:31 dac volumio[1267]: info: Discovery: Found device DAC Aug 27 07:09:31 dac volumio[1267]: info: CoreCommandRouter::volumioGetState Aug 27 07:09:31 dac volumio[1267]: info: CorePlayQueue::getTrack 0 Aug 27 07:09:31 dac sudo[1595]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:31 dac volumio[1267]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Aug 27 07:09:31 dac volumio[1267]: info: Reading ALSA contributions from plugins. Aug 27 07:09:31 dac volumio[1267]: info: touch_display: Backlight interface detected. Aug 27 07:09:32 dac volumio[1267]: info: touch_display: systemctl disable getty@tty1.service succeeded. Aug 27 07:09:32 dac volumio[1267]: info: touch_display: systemctl stop getty@tty1.service succeeded. Aug 27 07:09:32 dac volumio[1267]: info: MPD Permissions set Aug 27 07:09:32 dac volumio[1267]: info: MPD Permissions set Aug 27 07:09:32 dac volumio[1267]: info: Upmpdcli Daemon Started Aug 27 07:09:32 dac volumio[1267]: info: [MQTT] Connected to MQTT broker Aug 27 07:09:32 dac volumio[1267]: info: CoreCommandRouter::volumioGetState Aug 27 07:09:32 dac volumio[1267]: info: CorePlayQueue::getTrack 0 Aug 27 07:09:32 dac sudo[1686]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:32 dac volumio[1267]: 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: 3 Aug 27 07:09:32 dac sudo[1729]: 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 27 07:09:32 dac sudo[1729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:32 dac sudo[1729]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:32 dac volumio[1267]: info: Volumio called home Aug 27 07:09:32 dac volumio[1267]: info: Spotify config file written Aug 27 07:09:32 dac sudo[1737]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 27 07:09:32 dac sudo[1737]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:32 dac 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 27 07:09:32 dac 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 27 07:09:33 dac systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 07:09:33 dac go-librespot[1739]: go-librespot daemon starting... Aug 27 07:09:33 dac sudo[1737]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:33 dac volumio[1267]: 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: 3 Aug 27 07:09:33 dac volumio[1267]: info: Received Get System Info Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 07:09:33 dac volumio[1267]: info: Discovery: Getting this device information Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::volumioGetState Aug 27 07:09:33 dac volumio[1267]: info: CorePlayQueue::getTrack 0 Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 07:09:33 dac volumio5-onboarding[1613]: time=2026-08-27T07:09:33.332+01:00 level=INFO msg="system info for a6dc3a8a986337449d1fd1a88f3e1112" deviceName=DAC deviceVariant=volumio deviceModel= softwareVersion=4.119 Aug 27 07:09:33 dac volumio5-onboarding[1613]: time=2026-08-27T07:09:33.338+01:00 level=INFO msg="bootstrapping state" hasInternet=true Aug 27 07:09:33 dac go-librespot[1740]: time="2026-08-27T07:09:33+01:00" level=info msg="running go-librespot 0.7.1" Aug 27 07:09:33 dac go-librespot[1740]: time="2026-08-27T07:09:33+01:00" level=debug msg="app state loaded" Aug 27 07:09:33 dac go-librespot[1740]: time="2026-08-27T07:09:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 07:09:33 dac volumio[1267]: info: touch_display: systemctl daemon-reload succeeded. Aug 27 07:09:33 dac volumio[1267]: info: touch_display: IframeKeyboardBridge extension installed successfully Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:33 dac go-librespot[1740]: time="2026-08-27T07:09:33+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 27 07:09:33 dac go-librespot[1740]: time="2026-08-27T07:09:33+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 27 07:09:33 dac go-librespot[1740]: time="2026-08-27T07:09:33+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 27 07:09:33 dac go-librespot[1740]: time="2026-08-27T07:09:33+01:00" level=info msg="zeroconf server listening on port 33923" Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:33 dac go-librespot[1740]: time="2026-08-27T07:09:33+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 27 07:09:33 dac sudo[1751]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Aug 27 07:09:33 dac sudo[1751]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:33 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:33 dac systemd[1]: Started volumio-kiosk.service - Volumio Kiosk. Aug 27 07:09:33 dac sudo[1751]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:34 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 07:09:34 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:34 dac volumio[1267]: info: No need to fix Spotify hosts Aug 27 07:09:34 dac go-librespot[1740]: time="2026-08-27T07:09:34+01:00" level=debug msg="obtained new client token: AAHNQa8TD2kV9CSSRWyCiKwNi93/xirTszW7UzuWFtP1rB53puuTwn/dHipUaW8Hw3v+a2Fud51e9u0uaGqiq04X7k1d2bUu71R1NFDbgUBzMUsOsvTxwOmbWADj1WPaspZZsQFN3+yaLZzUVe0+a5o2u1cdDviyC2zbhvrMqe6BxpYC6ZZ9cyfMO+zZfaIytaPlenIvUW2xSwYmPZ709OAbePQI0QAx2TB+Rro3cyWn9xvmBfKGg/uNQA==" Aug 27 07:09:34 dac startx[1786]: X.Org X Server 1.21.1.7 Aug 27 07:09:34 dac startx[1786]: X Protocol Version 11, Revision 0 Aug 27 07:09:34 dac startx[1786]: Current Operating System: Linux dac 6.12.74-v7l+ #1948 SMP Mon Mar 2 11:27:49 GMT 2026 armv7l Aug 27 07:09:34 dac startx[1786]: 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=DC:A6:32:E1:3B:7E 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=9caf6474-168f-4972-add4-ace36a467bc2 imgfile=/volumio_current.sqsh bootpart=UUID=807D-2966 datapart=UUID=bea3e05c-62cf-4b22-a58d-66213927f56a 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 27 07:09:34 dac startx[1786]: xorg-server 2:21.1.7-3+rpt3+deb12u11 (https://www.debian.org/support) Aug 27 07:09:34 dac startx[1786]: Current version of pixman: 0.44.0 Aug 27 07:09:34 dac startx[1786]: Before reporting problems, check http://wiki.x.org Aug 27 07:09:34 dac startx[1786]: to make sure that you have the latest version. Aug 27 07:09:34 dac startx[1786]: Markers: (--) probed, (**) from config file, (==) default setting, Aug 27 07:09:34 dac startx[1786]: (++) from command line, (!!) notice, (II) informational, Aug 27 07:09:34 dac startx[1786]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Aug 27 07:09:34 dac startx[1786]: (==) Log file: "/var/log/Xorg.0.log", Time: Thu Aug 27 07:09:34 2026 Aug 27 07:09:34 dac startx[1786]: (==) Using config directory: "/etc/X11/xorg.conf.d" Aug 27 07:09:34 dac startx[1786]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Aug 27 07:09:34 dac go-librespot[1740]: time="2026-08-27T07:09:34+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 27 07:09:34 dac go-librespot[1740]: time="2026-08-27T07:09:34+01:00" level=debug msg="completed keyexchange" Aug 27 07:09:34 dac go-librespot[1740]: time="2026-08-27T07:09:34+01:00" level=debug msg="completed challenge" Aug 27 07:09:34 dac go-librespot[1740]: time="2026-08-27T07:09:34+01:00" level=info msg="authenticated AP" username="ja***ju" Aug 27 07:09:34 dac go-librespot[1740]: time="2026-08-27T07:09:34+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 27 07:09:34 dac systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 07:09:34 dac systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 07:09:34 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 07:09:34 dac volumio[1267]: info: Discovery: Getting this device information Aug 27 07:09:34 dac volumio[1267]: info: CoreCommandRouter::volumioGetState Aug 27 07:09:34 dac volumio[1267]: info: CorePlayQueue::getTrack 0 Aug 27 07:09:34 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 07:09:34 dac volumio[1267]: info: Received Get System Info Aug 27 07:09:34 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 07:09:34 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 07:09:34 dac volumio[1267]: info: Discovery: Getting this device information Aug 27 07:09:34 dac volumio[1267]: info: CoreCommandRouter::volumioGetState Aug 27 07:09:34 dac volumio[1267]: info: CorePlayQueue::getTrack 0 Aug 27 07:09:34 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 07:09:35 dac volumio[1267]: error: MPD error: The expression evaluated to a falsy value: Aug 27 07:09:35 dac volumio[1267]: assert.ok(self.idling) Aug 27 07:09:35 dac volumio[1267]: error: The expression evaluated to a falsy value: Aug 27 07:09:35 dac volumio[1267]: assert.ok(self.idling) Aug 27 07:09:35 dac volumio[1267]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Aug 27 07:09:35 dac volumio[1267]: info: MPD running with PID1630 Aug 27 07:09:35 dac volumio[1267]: ,establishing connection Aug 27 07:09:35 dac kernel: ------------[ cut here ]------------ Aug 27 07:09:35 dac kernel: WARNING: CPU: 2 PID: 1786 at drivers/gpu/drm/vc4/vc4_hvs.c:1064 __vc4_hvs_stop_channel+0x168/0x1dc [vc4] Aug 27 07:09:35 dac kernel: Modules linked in: 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 nfnetlink joydev bcm2835_v4l2(C) brcmfmac_wcc rpi_hevc_dec bcm2835_isp(C) videobuf2_vmalloc bcm2835_codec(C) 8021q bcm2835_mmal_vchiq(C) vc_sm_cma(C) garp v4l2_mem2mem stp videobuf2_dma_contig llc videobuf2_memops videobuf2_v4l2 brcmfmac videodev binfmt_misc hci_uart snd_soc_pcm179x_i2c btbcm brcmutil bluetooth snd_soc_hifiberry_dacplushd snd_soc_pcm179x_codec raspberrypi_hwmon videobuf2_common ecdh_generic edt_ft5x06 cfg80211 ecc libaes rfkill 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 panel_waveshare_dsi panel_ilitek_ili9881c panel_raspberrypi_touchscreen pwm_bcm2835 spi_bcm2835 squashfs overlay nls_iso8859_1 fuse tc358762 Aug 27 07:09:35 dac kernel: clk_hifiberry_dachd rpi_panel_attiny_regulator regmap_i2c vc4 snd_soc_hdmi_codec drm_display_helper cec drm_dma_helper snd_soc_bcm2835_i2s v3d gpu_sched snd_soc_core snd_compress i2c_mux_pinctrl snd_pcm_dmaengine drm_shmem_helper snd_bcm2835(C) snd_pcm i2c_mux drm_kms_helper snd_timer i2c_brcmstb i2c_bcm2835 snd panel_simple drm drm_panel_orientation_quirks backlight Aug 27 07:09:35 dac kernel: CPU: 2 UID: 0 PID: 1786 Comm: Xorg Tainted: G C 6.12.74-v7l+ #1948 Aug 27 07:09:35 dac kernel: Tainted: [C]=CRAP Aug 27 07:09:35 dac kernel: Hardware name: BCM2711 Aug 27 07:09:35 dac kernel: Call trace: Aug 27 07:09:35 dac kernel: unwind_backtrace from show_stack+0x18/0x1c Aug 27 07:09:35 dac kernel: show_stack from dump_stack_lvl+0x5c/0x80 Aug 27 07:09:35 dac kernel: dump_stack_lvl from __warn+0x88/0x124 Aug 27 07:09:35 dac kernel: __warn from warn_slowpath_fmt+0x184/0x190 Aug 27 07:09:35 dac kernel: warn_slowpath_fmt from __vc4_hvs_stop_channel+0x168/0x1dc [vc4] Aug 27 07:09:35 dac kernel: __vc4_hvs_stop_channel [vc4] from vc4_crtc_disable+0x138/0x1dc [vc4] Aug 27 07:09:35 dac kernel: vc4_crtc_disable [vc4] from vc4_crtc_atomic_disable+0x9c/0xc0 [vc4] Aug 27 07:09:35 dac kernel: vc4_crtc_atomic_disable [vc4] from disable_outputs+0x268/0x3a0 [drm_kms_helper] Aug 27 07:09:35 dac kernel: disable_outputs [drm_kms_helper] from drm_atomic_helper_commit_modeset_disables+0x18/0x3c [drm_kms_helper] Aug 27 07:09:35 dac kernel: drm_atomic_helper_commit_modeset_disables [drm_kms_helper] from vc4_atomic_commit_tail+0x194/0x998 [vc4] Aug 27 07:09:35 dac kernel: vc4_atomic_commit_tail [vc4] from commit_tail+0xa4/0x18c [drm_kms_helper] Aug 27 07:09:35 dac kernel: commit_tail [drm_kms_helper] from drm_atomic_helper_commit+0x140/0x164 [drm_kms_helper] Aug 27 07:09:35 dac kernel: drm_atomic_helper_commit [drm_kms_helper] from drm_atomic_commit+0xc8/0x100 [drm] Aug 27 07:09:35 dac kernel: drm_atomic_commit [drm] from drm_atomic_helper_set_config+0x90/0xc8 [drm_kms_helper] Aug 27 07:09:35 dac kernel: drm_atomic_helper_set_config [drm_kms_helper] from drm_mode_setcrtc+0x200/0x814 [drm] Aug 27 07:09:35 dac kernel: drm_mode_setcrtc [drm] from drm_ioctl+0x2b4/0x4d0 [drm] Aug 27 07:09:35 dac kernel: drm_ioctl [drm] from sys_ioctl+0x130/0xbcc Aug 27 07:09:35 dac kernel: sys_ioctl from ret_fast_syscall+0x0/0x5c Aug 27 07:09:35 dac kernel: Exception stack(0xf0f39fa8 to 0xf0f39ff0) Aug 27 07:09:35 dac kernel: 9fa0: 0000000c bebbd9e0 0000000c c06864a2 bebbd9e0 bebbd9c0 Aug 27 07:09:35 dac kernel: 9fc0: 0000000c bebbd9e0 c06864a2 00000036 bebbda98 018645d0 00f5e4f8 00000000 Aug 27 07:09:35 dac kernel: 9fe0: 00000000 bebbd9a8 b69e5000 b69681e4 Aug 27 07:09:35 dac kernel: ---[ end trace 0000000000000000 ]--- Aug 27 07:09:36 dac volumio-remote-updater[810]: Test mode disabled Aug 27 07:09:36 dac volumio-remote-updater[810]: Alpha mode disabled Aug 27 07:09:36 dac volumio-remote-updater[810]: Alpha legacy test mode disabled Aug 27 07:09:36 dac volumio[1267]: error: updateQueue error: null Aug 27 07:09:36 dac volumio[1267]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Aug 27 07:09:36 dac volumio[1267]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Aug 27 07:09:36 dac volumio[1267]: info: touch_display: Volumio Kiosk started. Aug 27 07:09:36 dac volumio[1267]: info: CoreCommandRouter::volumioGetState Aug 27 07:09:36 dac volumio[1267]: info: CorePlayQueue::getTrack 0 Aug 27 07:09:36 dac volumio[1267]: info: Completed starting Core Plugins Aug 27 07:09:36 dac volumio[1267]: info: ------------------------------------------- Aug 27 07:09:36 dac volumio[1267]: info: ----- MyVolumio plugins startup ---- Aug 27 07:09:36 dac volumio[1267]: info: ------------------------------------------- Aug 27 07:09:36 dac volumio[1267]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 27 07:09:36 dac sudo[1815]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/10-0045/brightness Aug 27 07:09:36 dac sudo[1815]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:37 dac sudo[1815]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:37 dac volumio[1267]: info: touch_display: Raspberry Pi Foundation touch screen detected. Aug 27 07:09:37 dac sudo[1819]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Aug 27 07:09:37 dac sudo[1819]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:37 dac sudo[1819]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:37 dac sudo[1823]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Aug 27 07:09:37 dac sudo[1823]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:37 dac sudo[1823]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:37 dac volumio[1267]: info: New Spotify access tokenBQD8N71Rdg... Aug 27 07:09:37 dac volumio[1267]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 27 07:09:37 dac volumio[1267]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 27 07:09:37 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 27 07:09:37 dac volumio[1267]: info: touch_display: X display number found: 0 Aug 27 07:09:37 dac systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 27 07:09:37 dac systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 07:09:37 dac systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 07:09:37 dac systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Aug 27 07:09:37 dac go-librespot[1879]: go-librespot daemon starting... Aug 27 07:09:37 dac go-librespot[1884]: time="2026-08-27T07:09:37+01:00" level=info msg="running go-librespot 0.7.1" Aug 27 07:09:37 dac go-librespot[1884]: time="2026-08-27T07:09:37+01:00" level=debug msg="app state loaded" Aug 27 07:09:37 dac go-librespot[1884]: time="2026-08-27T07:09:37+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 07:09:38 dac volumio[1267]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 27 07:09:38 dac go-librespot[1884]: time="2026-08-27T07:09:38+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 27 07:09:38 dac go-librespot[1884]: time="2026-08-27T07:09:38+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 27 07:09:38 dac go-librespot[1884]: time="2026-08-27T07:09:38+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 27 07:09:38 dac go-librespot[1884]: time="2026-08-27T07:09:38+01:00" level=info msg="zeroconf server listening on port 41585" Aug 27 07:09:38 dac go-librespot[1884]: time="2026-08-27T07:09:38+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 27 07:09:38 dac go-librespot[1884]: time="2026-08-27T07:09:38+01:00" level=debug msg="obtained new client token: AAFRVegy3Uj/CLuDlXRHc39zFI7XmLvMFVuh+P9ESLPoIVSo2CpDYe6EpLIhROh6wS8odGVFEkDJe21auObJIB0YNYE2yyTOFySQe8PwFQzM1rBpWHtIcYkrX48cBXHqSWjnvq/KaSQygDxLskQsXXK0Ez84hLi7MtOm6OTR5wu15lDY0qCUsTtXuhpnmtY070lPegr7W8IkgLH7clys872ufEFrQZHctq71GfDYvGk0fbrKX6GIBYhfjg==" Aug 27 07:09:38 dac go-librespot[1884]: time="2026-08-27T07:09:38+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Aug 27 07:09:38 dac go-librespot[1884]: time="2026-08-27T07:09:38+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 27 07:09:38 dac go-librespot[1884]: time="2026-08-27T07:09:38+01:00" level=debug msg="completed keyexchange" Aug 27 07:09:38 dac go-librespot[1884]: time="2026-08-27T07:09:38+01:00" level=debug msg="completed challenge" Aug 27 07:09:38 dac go-librespot[1884]: time="2026-08-27T07:09:38+01:00" level=info msg="authenticated AP" username="ja***ju" Aug 27 07:09:38 dac volumio[1267]: info: camilladsp service started and running in background, instance 1 Aug 27 07:09:38 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:38 dac go-librespot[1884]: time="2026-08-27T07:09:38+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 27 07:09:38 dac systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 07:09:38 dac systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 07:09:38 dac volumio[1267]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA Aug 27 07:09:38 dac volumio[1267]: info: FusionDsp loaded Aug 27 07:09:38 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 07:09:38 dac volumio[1267]: info: FusionDsp - --[object Object] Aug 27 07:09:38 dac volumio[1267]: error: FusionDsp - Socket connection not established Aug 27 07:09:38 dac volumio[1267]: info: FusionDsp - Reporting Fusion DSP Enabled Aug 27 07:09:38 dac volumio[1267]: info: Adding Signal Path Element [object Object] Aug 27 07:09:38 dac volumio[1267]: info: Adding fusiondspeq DSP Signal Path Element Aug 27 07:09:38 dac volumio[1267]: info: FusionDsp - ---- installed callbackRead (debounced 200ms) Aug 27 07:09:38 dac sudo[1923]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Aug 27 07:09:38 dac sudo[1923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:38 dac volumio[1267]: info: FusionDsp - PEQ graph server listening on port 10015 Aug 27 07:09:38 dac volumio[1267]: info: Starting Shairport Sync Aug 27 07:09:38 dac volumio[1267]: info: Starting Shairport Sync Aug 27 07:09:38 dac volumio[1267]: info: Starting Shairport Sync Aug 27 07:09:38 dac systemd[1]: Starting fusiondsp.service - FusionDsp Daemon... Aug 27 07:09:38 dac sudo[1927]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 27 07:09:38 dac sudo[1927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:38 dac sudo[1931]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 27 07:09:38 dac sudo[1931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:38 dac volumio[1267]: info: CoreCommandRouter::volumioGetState Aug 27 07:09:38 dac volumio[1267]: info: CorePlayQueue::getTrack 0 Aug 27 07:09:38 dac systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 27 07:09:38 dac systemd[1]: shairport-sync.service: Deactivated successfully. Aug 27 07:09:38 dac systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 27 07:09:38 dac systemd[1]: shairport-sync.service: Consumed 1.606s CPU time. Aug 27 07:09:38 dac systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 27 07:09:38 dac volumio[1267]: error: updateQueue error: null Aug 27 07:09:38 dac sudo[1931]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:38 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 27 07:09:38 dac systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 27 07:09:38 dac volumio[1267]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Aug 27 07:09:38 dac volumio[1267]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Aug 27 07:09:38 dac volumio[1267]: info: touch_display: File permissions for backlight brightness control set. Aug 27 07:09:39 dac systemd[1]: shairport-sync.service: Deactivated successfully. Aug 27 07:09:39 dac systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 27 07:09:39 dac systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 27 07:09:39 dac sudo[1927]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:39 dac volumio[1267]: info: go-librespot daemon successfully initialized Aug 27 07:09:39 dac sudo[1935]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 27 07:09:39 dac sudo[1935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:39 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 27 07:09:39 dac systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 27 07:09:39 dac volumio[1267]: error: FusionDsp - Reload WebSocket error: [object Object] Aug 27 07:09:39 dac systemd[1]: shairport-sync.service: Deactivated successfully. Aug 27 07:09:39 dac systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 27 07:09:39 dac systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 27 07:09:39 dac volumio[1267]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Aug 27 07:09:39 dac volumio[1267]: info: Shairport-Sync Started Aug 27 07:09:39 dac sudo[1935]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:39 dac volumio[1267]: Error adding Membership: Error: addMembership EINVAL Aug 27 07:09:39 dac volumio[1267]: info: Shairport-Sync Started Aug 27 07:09:39 dac volumio[1267]: info: Asound.conf file unchanged, so no further update is needed Aug 27 07:09:39 dac volumio[1267]: info: Output device has changed, restarting MPD Aug 27 07:09:39 dac volumio[1267]: info: Output device has changed, restarting Shairport Sync Aug 27 07:09:39 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:39 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 07:09:39 dac sudo[2017]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 27 07:09:39 dac sudo[2017]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:39 dac sudo[2007]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 27 07:09:39 dac volumio[1267]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 07:09:39 dac systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 27 07:09:39 dac sudo[2007]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:39 dac sudo[2007]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:40 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 27 07:09:40 dac systemd[1]: mpd.service: Deactivated successfully. Aug 27 07:09:40 dac systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 27 07:09:40 dac systemd[1]: mpd.service: Consumed 2.909s CPU time. Aug 27 07:09:40 dac systemd[1]: mpd.socket: Deactivated successfully. Aug 27 07:09:40 dac systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 27 07:09:40 dac systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 27 07:09:40 dac volumio[1267]: info: touch_display: X display number found: 0 Aug 27 07:09:40 dac volumio[1267]: info: Shairport-Sync Started Aug 27 07:09:40 dac systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 27 07:09:40 dac systemd[1]: Starting mpd.service - Music Player Daemon... Aug 27 07:09:40 dac sudo[2029]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 27 07:09:40 dac sudo[2029]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 27 07:09:40 dac volumio[1267]: error: MPD error: Error: write EPIPE Aug 27 07:09:40 dac volumio[1267]: error: write EPIPE {"code":"EPIPE","errno":-32,"syscall":"write"} Aug 27 07:09:40 dac sudo[2029]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:40 dac volumio[1267]: info: Received Get System Info Aug 27 07:09:40 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 07:09:40 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 07:09:40 dac volumio[1267]: info: Discovery: Getting this device information Aug 27 07:09:40 dac volumio[1267]: info: CoreCommandRouter::volumioGetState Aug 27 07:09:40 dac volumio[1267]: info: CorePlayQueue::getTrack 0 Aug 27 07:09:40 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 07:09:40 dac volumio[1267]: info: CoreCommandRouter::volumioGetState Aug 27 07:09:40 dac volumio[1267]: info: CorePlayQueue::getTrack 0 Aug 27 07:09:40 dac volumio[1267]: info: MPD Permissions set Aug 27 07:09:40 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 27 07:09:40 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 27 07:09:40 dac volumio5-onboarding[1613]: time=2026-08-27T07:09:40.971+01:00 level=INFO msg="enabling local network discovery" Aug 27 07:09:40 dac volumio5-onboarding[1613]: time=2026-08-27T07:09:40.991+01:00 level=INFO msg="enabling BLE discovery" Aug 27 07:09:41 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:41 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:41 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:41 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:41 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:41 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:41 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:41 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:41 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 07:09:41 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 07:09:41 dac systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 27 07:09:41 dac systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 07:09:41 dac systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 07:09:41 dac go-librespot[2054]: go-librespot daemon starting... Aug 27 07:09:41 dac go-librespot[2055]: time="2026-08-27T07:09:41+01:00" level=info msg="running go-librespot 0.7.1" Aug 27 07:09:41 dac go-librespot[2055]: time="2026-08-27T07:09:41+01:00" level=debug msg="app state loaded" Aug 27 07:09:41 dac go-librespot[2055]: time="2026-08-27T07:09:41+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 07:09:41 dac volumio[1267]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Aug 27 07:09:41 dac volumio[1267]: info: touch_display: Setting screensaver timeout to 0 seconds. Aug 27 07:09:41 dac volumio5-onboarding[1613]: time=2026-08-27T07:09:41.891+01:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 27 07:09:41 dac go-librespot[2055]: time="2026-08-27T07:09:41+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 27 07:09:41 dac go-librespot[2055]: time="2026-08-27T07:09:41+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 27 07:09:41 dac go-librespot[2055]: time="2026-08-27T07:09:41+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 27 07:09:41 dac go-librespot[2055]: time="2026-08-27T07:09:41+01:00" level=info msg="zeroconf server listening on port 41505" Aug 27 07:09:41 dac volumio[1267]: info: CoreCommandRouter::volumioGetState Aug 27 07:09:41 dac volumio[1267]: info: CorePlayQueue::getTrack 0 Aug 27 07:09:41 dac volumio[1267]: info: Starting Shairport Sync Aug 27 07:09:41 dac go-librespot[2055]: time="2026-08-27T07:09:41+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 27 07:09:42 dac volumio[1267]: info: Initializing connection to go-librespot Websocket Aug 27 07:09:42 dac mpd[2031]: 2026-08-27T07:09:42 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 27 07:09:42 dac systemd[1]: Started mpd.service - Music Player Daemon. Aug 27 07:09:42 dac sudo[2017]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:42 dac sudo[2067]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 27 07:09:42 dac sudo[2067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 07:09:42 dac go-librespot[2055]: time="2026-08-27T07:09:42+01:00" level=debug msg="new websocket client" Aug 27 07:09:42 dac systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 27 07:09:42 dac systemd[1]: shairport-sync.service: Deactivated successfully. Aug 27 07:09:42 dac systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 27 07:09:42 dac systemd[1]: shairport-sync.service: Consumed 1.066s CPU time. Aug 27 07:09:42 dac systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 27 07:09:42 dac sudo[2067]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:42 dac volumio[1267]: info: Connection to go-librespot Websocket established Aug 27 07:09:42 dac volumio[1267]: error: updateQueue error: null Aug 27 07:09:42 dac volumio[1267]: info: Shairport-Sync Started Aug 27 07:09:42 dac volumio[1267]: SPOTIFY: User informations: {"account_id":"0Aw3FdTBpI","country":"GB","display_name":"jammoju","email":"julian.widdicombe@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/jammoju"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/jammoju","id":"jammoju","images":[],"product":"premium","type":"user","uri":"spotify:user:jammoju"} Aug 27 07:09:42 dac volumio[1267]: info: Spotify Successfully logged in Aug 27 07:09:42 dac volumio[1267]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 07:09:42 dac volumio[1267]: info: [1787810982581] CoreMusicLibrary::Adding element Spotify Aug 27 07:09:42 dac volumio[1267]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 07:09:42 dac volumio[1267]: Cannot find translation for source Spotify Aug 27 07:09:42 dac volumio[1267]: info: CoreCommandRouter::volumioGetState Aug 27 07:09:42 dac volumio[1267]: info: CorePlayQueue::getTrack 0 Aug 27 07:09:43 dac go-librespot[2055]: time="2026-08-27T07:09:43+01:00" level=debug msg="obtained new client token: AAEPCDGhQbqY8LX6clhZygrMNTFKT5BCYKP+1rIniPzoe8qNenadArXFLmf+SBNPV1Wu50vfAICPeWUj9Tl201fzrzV8EyWMeRUBNNSyqP5JIiiWkfrPfxS8wpcxN8iXj4zE0wPQWMoZg4iIjxvkJQYBjOFnRek1cq/fn8vPQ89LEzbgo3P+zq2+kmhsHuvjnWfCsvFiHnJR6npOn0M7yO+D+NjLJrjWprvWeOz20q/yl0AH03fIVH5dAA==" Aug 27 07:09:43 dac go-librespot[2055]: time="2026-08-27T07:09:43+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 27 07:09:43 dac go-librespot[2055]: time="2026-08-27T07:09:43+01:00" level=debug msg="completed keyexchange" Aug 27 07:09:43 dac go-librespot[2055]: time="2026-08-27T07:09:43+01:00" level=debug msg="completed challenge" Aug 27 07:09:43 dac go-librespot[2055]: time="2026-08-27T07:09:43+01:00" level=info msg="authenticated AP" username="ja***ju" Aug 27 07:09:43 dac go-librespot[2055]: time="2026-08-27T07:09:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 27 07:09:43 dac systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 07:09:43 dac systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 07:09:43 dac volumio[1267]: info: Connection to go-librespot Websocket closed Aug 27 07:09:43 dac systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Aug 27 07:09:43 dac sudo[1923]: pam_unix(sudo:session): session closed for user root Aug 27 07:09:44 dac volumio[1267]: info: CoreCommandRouter::volumioGetState Aug 27 07:09:44 dac volumio[1267]: info: CorePlayQueue::getTrack 0 Aug 27 07:09:44 dac volumio[1267]: info: Listing playlists Aug 27 07:09:44 dac volumio[1267]: info: Listing playlists Aug 27 07:09:45 dac volumio[1267]: info: Getting Spotify volume Aug 27 07:09:45 dac volumio[1267]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 07:09:45 dac volumio[1267]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 07:09:45 dac volumio[1267]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 27 07:09:45 dac volumio[1267]: errno: -111, Aug 27 07:09:45 dac volumio[1267]: code: 'ECONNREFUSED', Aug 27 07:09:45 dac volumio[1267]: syscall: 'connect', Aug 27 07:09:45 dac volumio[1267]: address: '127.0.0.1', Aug 27 07:09:45 dac volumio[1267]: port: 9879, Aug 27 07:09:45 dac volumio[1267]: response: undefined Aug 27 07:09:45 dac volumio[1267]: } Aug 27 07:09:45 dac volumio[1267]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 07:09:46 dac systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 27 07:09:46 dac systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 07:09:46 dac systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 07:09:46 dac go-librespot[2164]: go-librespot daemon starting... Aug 27 07:09:46 dac go-librespot[2165]: time="2026-08-27T07:09:46+01:00" level=info msg="running go-librespot 0.7.1" Aug 27 07:09:46 dac go-librespot[2165]: time="2026-08-27T07:09:46+01:00" level=debug msg="app state loaded" Aug 27 07:09:46 dac go-librespot[2165]: time="2026-08-27T07:09:46+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 07:09:46 dac go-librespot[2165]: time="2026-08-27T07:09:46+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 27 07:09:46 dac go-librespot[2165]: time="2026-08-27T07:09:46+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 27 07:09:46 dac go-librespot[2165]: time="2026-08-27T07:09:46+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 27 07:09:46 dac go-librespot[2165]: time="2026-08-27T07:09:46+01:00" level=info msg="zeroconf server listening on port 38187" Aug 27 07:09:46 dac go-librespot[2165]: time="2026-08-27T07:09:46+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 27 07:09:46 dac go-librespot[2165]: time="2026-08-27T07:09:46+01:00" level=debug msg="obtained new client token: AAHU6vPKBG26ivppNxkd6mxAJMF0YopNs14h6+yHxO6b9ZCsvsIIqNIuKRQNzbAty8oZFbjhwB74ikW2GyoDVTxZUjLEu5cnH2VaFa9uueyPCI4R/qm2v6HgSrPDpYHnXu1+Pt0MBiJw1Ype7R2bcRPDH2TybAUURA5MW3oba09Q60RUEeZB2chvyYQEjUw4JEReLAt/VgiaOCHw6Ag/7ckVck80tf8sZ7CbKsXzcWGU0QslohyYsjCCDA==" Aug 27 07:09:46 dac go-librespot[2165]: time="2026-08-27T07:09:46+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Aug 27 07:09:46 dac go-librespot[2165]: time="2026-08-27T07:09:46+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 27 07:09:46 dac go-librespot[2165]: time="2026-08-27T07:09:46+01:00" level=debug msg="completed keyexchange" Aug 27 07:09:46 dac go-librespot[2165]: time="2026-08-27T07:09:46+01:00" level=debug msg="completed challenge" Aug 27 07:09:46 dac go-librespot[2165]: time="2026-08-27T07:09:46+01:00" level=info msg="authenticated AP" username="ja***ju" Aug 27 07:09:46 dac go-librespot[2165]: time="2026-08-27T07:09:46+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 27 07:09:46 dac systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 07:09:46 dac systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 07:09:49 dac systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 27 07:09:49 dac systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 07:09:50 dac systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 07:09:50 dac go-librespot[2197]: go-librespot daemon starting... Aug 27 07:09:50 dac go-librespot[2198]: time="2026-08-27T07:09:50+01:00" level=info msg="running go-librespot 0.7.1" Aug 27 07:09:50 dac go-librespot[2198]: time="2026-08-27T07:09:50+01:00" level=debug msg="app state loaded" Aug 27 07:09:50 dac go-librespot[2198]: time="2026-08-27T07:09:50+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 07:09:50 dac go-librespot[2198]: time="2026-08-27T07:09:50+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 27 07:09:50 dac go-librespot[2198]: time="2026-08-27T07:09:50+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 27 07:09:50 dac go-librespot[2198]: time="2026-08-27T07:09:50+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 27 07:09:50 dac go-librespot[2198]: time="2026-08-27T07:09:50+01:00" level=info msg="zeroconf server listening on port 36679" Aug 27 07:09:50 dac go-librespot[2198]: time="2026-08-27T07:09:50+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 27 07:09:50 dac sudo[2208]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-27 07:08' Aug 27 07:09:50 dac sudo[2208]: 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"