Jan 12 16:35:25 garage ntpd[968]: CLOCK: time stepped by 84631.457940 Jan 12 16:35:25 garage ntpd[968]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Jan 12 16:35:25 garage systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Jan 12 16:35:25 garage systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Jan 12 16:35:25 garage systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Jan 12 16:35:25 garage systemd[1]: dpkg-db-backup.service: Deactivated successfully. Jan 12 16:35:25 garage systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Jan 12 16:35:26 garage systemd[1]: systemd-fsckd.service: Deactivated successfully. Jan 12 16:35:26 garage volumio[1174]: info: Loading plugin "network"... Jan 12 16:35:26 garage volumio[1174]: info: Refreshing Cached IP Addresses Jan 12 16:35:26 garage sudo[1323]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 12 16:35:26 garage volumio[1174]: info: Loading plugin "services"... Jan 12 16:35:26 garage sudo[1323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:35:26 garage volumio[1174]: info: Loading plugin "alsa_controller"... Jan 12 16:35:26 garage sudo[1324]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 12 16:35:26 garage sudo[1324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:35:26 garage sudo[1330]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 12 16:35:26 garage sudo[1323]: pam_unix(sudo:session): session closed for user root Jan 12 16:35:26 garage sudo[1330]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:35:26 garage sudo[1324]: pam_unix(sudo:session): session closed for user root Jan 12 16:35:26 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 16:35:26 garage volumio[1174]: info: Loading plugin "wizard"... Jan 12 16:35:26 garage volumio[1174]: info: Loading plugin "networkfs"... Jan 12 16:35:27 garage volumio[1174]: info: Starting Udev Watcher for removable devices Jan 12 16:35:27 garage sudo[1357]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=carmel,password=alinco,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.88.148/Public/music /mnt/NAS/NAS Jan 12 16:35:27 garage sudo[1357]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:35:27 garage volumio[1174]: info: Ignoring mount for partition: boot Jan 12 16:35:27 garage volumio[1174]: info: Ignoring mount for partition: volumio Jan 12 16:35:27 garage volumio[1174]: info: Ignoring mount for partition: volumio_data Jan 12 16:35:27 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 12 16:35:27 garage volumio[1174]: info: Loading plugin "volumio_command_line_client"... Jan 12 16:35:27 garage kernel: netfs: FS-Cache loaded Jan 12 16:35:27 garage volumio[1174]: info: Loading plugin "upnp"... Jan 12 16:35:27 garage volumio[1174]: info: [1768232127281] Starting Upmpd Daemon Jan 12 16:35:27 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 12 16:35:27 garage volumio[1174]: info: Loading plugin "my_music"... Jan 12 16:35:27 garage volumio[1174]: info: Loading plugin "mpd"... Jan 12 16:35:27 garage kernel: Key type cifs.spnego registered Jan 12 16:35:27 garage kernel: Key type cifs.idmap registered Jan 12 16:35:27 garage 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. Jan 12 16:35:27 garage kernel: CIFS: Attempting to mount //192.168.88.148/Public/music Jan 12 16:35:27 garage dhcpcd[614]: timed out Jan 12 16:35:27 garage sh[608]: timed out Jan 12 16:35:27 garage sh[586]: ifup: failed to bring up eth0 Jan 12 16:35:27 garage systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Jan 12 16:35:27 garage systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Jan 12 16:35:28 garage volumio[1174]: info: Loading plugin "upnp_browser"... Jan 12 16:35:28 garage sudo[1357]: pam_unix(sudo:session): session closed for user root Jan 12 16:35:29 garage systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Jan 12 16:35:29 garage systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 16:35:29 garage systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 16:35:29 garage upmpdcli[1396]: Could not open config: /tmp/upmpdcli.conf Jan 12 16:35:29 garage systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 12 16:35:29 garage systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 12 16:35:29 garage volumio[1174]: info: Starting UPNP Browser Jan 12 16:35:29 garage volumio[1174]: info: Loading plugin "alarm-clock"... Jan 12 16:35:30 garage volumio[1174]: info: Loading plugin "airplay_emulation"... Jan 12 16:35:30 garage volumio[1174]: info: Starting Shairport Sync Jan 12 16:35:30 garage volumio[1174]: info: Loading plugin "last_100"... Jan 12 16:35:30 garage volumio[1174]: info: Loading plugin "webradio"... Jan 12 16:35:30 garage volumio[1174]: info: Loading plugin "i2s_dacs"... Jan 12 16:35:30 garage volumio[1174]: info: Loading plugin "volumiodiscovery"... Jan 12 16:35:30 garage sudo[1330]: pam_unix(sudo:session): session closed for user root Jan 12 16:35:30 garage volumio[1174]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 12 16:35:30 garage volumio[1174]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 16:35:30 garage volumio[1174]: *** WARNING *** For more information see Jan 12 16:35:30 garage volumio[1174]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 12 16:35:30 garage volumio[1174]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 16:35:30 garage volumio[1174]: *** WARNING *** For more information see Jan 12 16:35:30 garage node[1174]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 12 16:35:30 garage node[1174]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 16:35:30 garage node[1174]: *** WARNING *** For more information see Jan 12 16:35:30 garage node[1174]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 12 16:35:30 garage node[1174]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 16:35:30 garage node[1174]: *** WARNING *** For more information see Jan 12 16:35:30 garage volumio[1174]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 12 16:35:30 garage volumio[1174]: info: Discovery: Started advertising with name: Garage Jan 12 16:35:30 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 12 16:35:30 garage volumio[1174]: info: Loading plugin "spop"... Jan 12 16:35:30 garage systemd[1]: systemd-hostnamed.service: Deactivated successfully. Jan 12 16:35:31 garage volumio-remote-updater[639]: [2026-01-12 16:35:31] [connect] Successful connection Jan 12 16:35:33 garage volumio[1174]: info: Loading plugin "now_playing"... Jan 12 16:35:34 garage nmbd[1028]: [2026/01/12 16:35:34.358916, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Jan 12 16:35:34 garage nmbd[1028]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.88.184 for name WORKGROUP<1d>. Jan 12 16:35:34 garage nmbd[1028]: This response was from IP 192.168.88.30, reporting an IP address of 192.168.88.30. Jan 12 16:35:37 garage volumio[1174]: info: Loading plugin "outputs"... Jan 12 16:35:37 garage volumio[1174]: info: Loading plugin "albumart"... Jan 12 16:35:37 garage volumio[1174]: info: Plugin example_plugin is not enabled Jan 12 16:35:37 garage volumio[1174]: info: Loading plugin "inputs"... Jan 12 16:35:37 garage volumio[1174]: info: Loading plugin "updater_comm"... Jan 12 16:35:37 garage volumio[1174]: info: Plugin mpdemulation is not enabled Jan 12 16:35:37 garage volumio[1174]: info: Loading plugin "rest_api"... Jan 12 16:35:38 garage volumio[1174]: info: Loading plugin "websocket"... Jan 12 16:35:38 garage volumio[1174]: info: Starting Socket.io Server version 1.7.4 Jan 12 16:35:38 garage volumio[1174]: info: Loading plugin "backup_restore"... Jan 12 16:35:38 garage volumio[1417]: Forking 3 albumart workers Jan 12 16:35:38 garage systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Jan 12 16:35:39 garage volumio[1174]: info: Applying required configuration parameters for plugin backup_restore Jan 12 16:35:39 garage volumio[1174]: info: Loading plugin "gpio_control"... Jan 12 16:35:41 garage volumio[1174]: gpiox_arm32 V2.2.1 Jan 12 16:35:44 garage systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Jan 12 16:35:44 garage systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 16:35:44 garage volumio[1174]: info: Applying required configuration parameters for plugin gpio_control Jan 12 16:35:44 garage systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 16:35:44 garage upmpdcli[1478]: Could not open config: /tmp/upmpdcli.conf Jan 12 16:35:44 garage systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 12 16:35:44 garage systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 12 16:35:44 garage volumio[1174]: info: Loading plugin "ir_controller"... Jan 12 16:35:44 garage systemd[1]: setdatetime-helper.service: Deactivated successfully. Jan 12 16:35:44 garage systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Jan 12 16:35:45 garage volumio[1428]: Starting albumart workers Jan 12 16:35:45 garage volumio[1429]: Starting albumart workers Jan 12 16:35:45 garage volumio[1174]: info: Applying required configuration parameters for plugin ir_controller Jan 12 16:35:46 garage volumio-remote-updater[639]: [2026-01-12 16:35:46] [connect] Successful connection Jan 12 16:35:47 garage volumio[1174]: info: Loading plugin "rotaryencoder2"... Jan 12 16:35:48 garage volumio[1427]: Starting albumart workers Jan 12 16:35:50 garage volumio[1174]: info: Loading plugin "Systeminfo"... Jan 12 16:35:53 garage volumio[1174]: info: Loading plugin "peppymeterbasic"... Jan 12 16:35:55 garage volumio[1174]: info: Loading plugin "touch_display"... Jan 12 16:35:56 garage volumio[1174]: info: Applying required configuration parameters for plugin touch_display Jan 12 16:35:56 garage volumio[1174]: info: Loading i18n strings for locale en Jan 12 16:35:57 garage volumio[1174]: Updating browse sources language Jan 12 16:35:57 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 16:35:57 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 16:35:57 garage volumio[1174]: info: CoreCommandRouter::initPlayerControls Jan 12 16:35:57 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:35:57 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:35:57 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:35:57 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:35:57 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:35:57 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:35:57 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:35:57 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:35:57 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 16:35:57 garage volumio[1174]: Express server listening on port 3000 Jan 12 16:35:57 garage volumio[1174]: [Metrics] WebUI: 35s 905.28ms Jan 12 16:35:57 garage volumio[1174]: info: CoreStateMachine::resetVolumioState Jan 12 16:35:57 garage volumio[1174]: info: CoreStateMachine::getcurrentVolume Jan 12 16:35:57 garage volumio[1174]: info: CoreCommandRouter::volumioRetrievevolume Jan 12 16:35:57 garage sudo[1536]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 12 16:35:57 garage sudo[1536]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:35:57 garage sudo[1535]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 12 16:35:57 garage sudo[1535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:35:57 garage sudo[1535]: pam_unix(sudo:session): session closed for user root Jan 12 16:35:57 garage sudo[1536]: pam_unix(sudo:session): session closed for user root Jan 12 16:35:57 garage volumio[1174]: info: Volumio Network Manager: Network status updated: 2 Jan 12 16:35:58 garage volumio[1174]: info: VolumeController:: Volume=24 Mute =false Jan 12 16:35:58 garage volumio[1174]: info: CoreStateMachine::pushState Jan 12 16:35:58 garage volumio[1174]: info: CorePlayQueue::getTrack 0 Jan 12 16:35:58 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 16:35:58 garage volumio[1174]: info: CoreCommandRouter::volumioPushState Jan 12 16:35:58 garage volumio[1174]: info: CoreStateMachine::updateTrackBlock Jan 12 16:35:58 garage volumio[1174]: info: CorePlayQueue::getTrackBlock Jan 12 16:35:58 garage volumio[1174]: info: CoreCommandRouter::volumioRetrievevolume Jan 12 16:35:58 garage volumio[1174]: info: CoreCommandRouter::volumioGetState Jan 12 16:35:58 garage volumio[1174]: info: CorePlayQueue::getTrack 0 Jan 12 16:35:58 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 16:35:58 garage volumio[1174]: info: Reloading queue from file Jan 12 16:35:59 garage volumio[1174]: info: CoreStateMachine::setRepeat true single undefined Jan 12 16:35:59 garage volumio[1174]: info: CoreStateMachine::pushState Jan 12 16:35:59 garage volumio[1174]: info: CorePlayQueue::getTrack 0 Jan 12 16:35:59 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 16:35:59 garage volumio[1174]: info: CoreCommandRouter::volumioPushState Jan 12 16:35:59 garage volumio[1174]: info: CoreStateMachine::setRandom null Jan 12 16:35:59 garage volumio[1174]: info: CoreStateMachine::pushState Jan 12 16:35:59 garage volumio[1174]: info: CorePlayQueue::getTrack 0 Jan 12 16:35:59 garage volumio[1174]: info: CoreCommandRouter::volumioPushState Jan 12 16:35:59 garage volumio[1174]: info: Setting Device type: Raspberry PI Jan 12 16:35:59 garage volumio[1174]: info: Listing playlists Jan 12 16:35:59 garage volumio[1174]: info: Listing playlists Jan 12 16:35:59 garage volumio[1174]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jan 12 16:35:59 garage volumio[1174]: info: Completed loading Core Plugins Jan 12 16:35:59 garage volumio[1174]: info: Preparing to generate the ALSA configuration file Jan 12 16:35:59 garage volumio[1174]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 12 16:35:59 garage volumio[1174]: info: Reading ALSA contributions from plugins. Jan 12 16:35:59 garage volumio[1174]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 12 16:35:59 garage volumio[1174]: info: VolumeController:: Volume=24 Mute =false Jan 12 16:35:59 garage volumio[1174]: info: CoreStateMachine::pushState Jan 12 16:35:59 garage volumio[1174]: info: CorePlayQueue::getTrack 0 Jan 12 16:35:59 garage volumio[1174]: info: CoreCommandRouter::volumioPushState Jan 12 16:35:59 garage sudo[1550]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 12 16:35:59 garage sudo[1550]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:35:59 garage systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 4. Jan 12 16:35:59 garage systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 16:35:59 garage systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 16:36:00 garage sudo[1550]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:00 garage volumio[1174]: info: Upmpdcli Daemon Started Jan 12 16:36:00 garage volumio[1174]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Jan 12 16:36:00 garage volumio[1174]: info: Discovery: adding 8c7e1a76-7eff-4a97-8a00-0e4b4cf16710 Jan 12 16:36:00 garage volumio[1174]: info: Discovery: Found device Garage Jan 12 16:36:00 garage volumio[1174]: info: CoreCommandRouter::volumioGetState Jan 12 16:36:00 garage volumio[1174]: info: CorePlayQueue::getTrack 0 Jan 12 16:36:00 garage volumio[1174]: info: Discovery: this is already registered, 8c7e1a76-7eff-4a97-8a00-0e4b4cf16710 Jan 12 16:36:00 garage volumio[1174]: info: Discovery: Found device Garage Jan 12 16:36:00 garage volumio[1174]: info: CoreCommandRouter::volumioGetState Jan 12 16:36:00 garage volumio[1174]: info: CorePlayQueue::getTrack 0 Jan 12 16:36:00 garage volumio[1174]: info: Asound.conf file unchanged, so no further update is needed Jan 12 16:36:00 garage volumio[1174]: info: Output device has changed, restarting MPD Jan 12 16:36:00 garage volumio[1174]: info: Output device has changed, restarting Shairport Sync Jan 12 16:36:00 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:00 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 16:36:00 garage sudo[1565]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 12 16:36:00 garage sudo[1565]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:00 garage sudo[1567]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 12 16:36:00 garage sudo[1567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:00 garage sudo[1565]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:00 garage volumio[1174]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 12 16:36:00 garage volumio[1174]: info: ___________ START PLUGINS ___________ Jan 12 16:36:00 garage volumio[1174]: info: ControllerMpd::onStart: Initializing MPD Jan 12 16:36:00 garage volumio[1174]: info: Creating MPD Configuration file Jan 12 16:36:01 garage systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 12 16:36:01 garage systemd[1]: Starting mpd.service - Music Player Daemon... Jan 12 16:36:01 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 16:36:01 garage volumio[1174]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 16:36:01 garage volumio[1174]: info: [1768232161057] CoreMusicLibrary::Adding element Media Servers Jan 12 16:36:01 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 16:36:01 garage sudo[1576]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 12 16:36:01 garage sudo[1576]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:01 garage volumio[1174]: info: UPNP Browser: Client initialized successfully Jan 12 16:36:01 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:01 garage sudo[1579]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 12 16:36:01 garage sudo[1579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:01 garage sudo[1576]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:01 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 16:36:01 garage sudo[1578]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 12 16:36:01 garage sudo[1578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 12 16:36:01 garage sudo[1584]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jan 12 16:36:01 garage sudo[1578]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:01 garage volumio[1174]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 12 16:36:01 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:01 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 16:36:01 garage volumio-remote-updater[639]: [2026-01-12 16:36:01] [connect] Successful connection Jan 12 16:36:01 garage systemd[1]: mpd.service: Deactivated successfully. Jan 12 16:36:01 garage systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 12 16:36:01 garage systemd[1]: mpd.socket: Deactivated successfully. Jan 12 16:36:01 garage systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 12 16:36:01 garage systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 12 16:36:01 garage systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 12 16:36:01 garage systemd[1]: Starting mpd.service - Music Player Daemon... Jan 12 16:36:01 garage volumio[1174]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 12 16:36:01 garage volumio[1174]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 16:36:01 garage volumio[1174]: info: [1768232161548] CoreMusicLibrary::Adding element Last_100 Jan 12 16:36:01 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 16:36:01 garage volumio[1174]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 16:36:01 garage volumio[1174]: info: [1768232161577] CoreMusicLibrary::Adding element Webradio Jan 12 16:36:01 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 16:36:01 garage sudo[1593]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 12 16:36:01 garage sudo[1593]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 12 16:36:01 garage sudo[1594]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jan 12 16:36:01 garage sudo[1593]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:01 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 16:36:01 garage volumio[1174]: info: Initializing BBC Radios Jan 12 16:36:01 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 16:36:01 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 16:36:02 garage volumio[1174]: info: Creating Spotify config file Jan 12 16:36:02 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:04 garage volumio[1174]: info: [now-playing] ConfigUpdater: config is up to date. Jan 12 16:36:04 garage volumio[1174]: info: Loading i18n strings for locale en Jan 12 16:36:04 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 16:36:04 garage sudo[1610]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Jan 12 16:36:04 garage sudo[1610]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:04 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 12 16:36:05 garage volumio[1174]: info: Loading i18n strings for locale en Jan 12 16:36:05 garage sudo[1610]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:05 garage sudo[1613]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd_aloop index=7 pcm_substreams=2 Jan 12 16:36:05 garage sudo[1613]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:05 garage sudo[1613]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:05 garage sudo[1618]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge Jan 12 16:36:05 garage sudo[1618]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:05 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 16:36:05 garage sudo[1618]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:05 garage volumio[1174]: info: Volumio Calling Home Jan 12 16:36:06 garage volumio[1174]: info: Preparing to generate the ALSA configuration file Jan 12 16:36:06 garage sudo[1630]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R a+rwX /etc/lirc/irexec.lircrc /etc/lirc/lirc_options.conf /etc/lirc/lircd.conf /etc/lirc/lircd.conf.d /etc/lirc/lircmd.conf /etc/lirc/lircrc Jan 12 16:36:06 garage sudo[1630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:06 garage sudo[1630]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:06 garage sudo[1633]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Jan 12 16:36:06 garage sudo[1633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:06 garage sudo[1636]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Jan 12 16:36:06 garage sudo[1636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:06 garage sudo[1633]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:06 garage sudo[1638]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 12 16:36:06 garage sudo[1638]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:06 garage systemd[1]: Reloading. Jan 12 16:36:08 garage volumio[1174]: info: [now-playing] App is listening on port 4004. Jan 12 16:36:08 garage systemd[1]: Reloading. Jan 12 16:36:08 garage sudo[1636]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:09 garage volumio[1174]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Jan 12 16:36:09 garage volumio[1174]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 12 16:36:09 garage volumio[1174]: info: Reading ALSA contributions from plugins. Jan 12 16:36:09 garage volumio[1174]: info: touch_display: Backlight interface detected. Jan 12 16:36:09 garage mpd[1595]: 2026-01-12T16:36:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 12 16:36:10 garage systemd[1]: Started mpd.service - Music Player Daemon. Jan 12 16:36:10 garage sudo[1579]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:10 garage sudo[1638]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:10 garage sudo[1567]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:10 garage volumio[1174]: info: touch_display: systemctl disable getty@tty1.service succeeded. Jan 12 16:36:10 garage volumio[1174]: info: touch_display: systemctl stop getty@tty1.service succeeded. Jan 12 16:36:10 garage volumio[1174]: info: ir_controller: File permissions successfully set on /etc/lirc/*. Jan 12 16:36:10 garage volumio[1174]: info: snd_dummy loaded Jan 12 16:36:10 garage volumio[1174]: info: MPD Permissions set Jan 12 16:36:10 garage volumio[1174]: info: MPD Permissions set Jan 12 16:36:10 garage sudo[1704]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay rotary-encoder pin_a=23 pin_b=24 relative_axis=true steps-per-period=1 Jan 12 16:36:10 garage sudo[1704]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:10 garage sudo[1704]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:10 garage kernel: rotary-encoder rotary@17: gray Jan 12 16:36:10 garage kernel: input: rotary@17 as /devices/platform/rotary@17/input/input1 Jan 12 16:36:11 garage sudo[1702]: 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/ Jan 12 16:36:11 garage sudo[1702]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:11 garage sudo[1702]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:11 garage volumio[1174]: info: touch_display: systemctl daemon-reload succeeded. Jan 12 16:36:11 garage volumio[1174]: info: Volumio called home Jan 12 16:36:11 garage volumio[1174]: info: Spotify config file written Jan 12 16:36:11 garage sudo[1718]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Jan 12 16:36:11 garage sudo[1718]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:11 garage sudo[1722]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 12 16:36:11 garage sudo[1722]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:11 garage systemd[1]: Started volumio-kiosk.service - Volumio Kiosk. Jan 12 16:36:11 garage 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. Jan 12 16:36:11 garage 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. Jan 12 16:36:11 garage sudo[1718]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:11 garage systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 12 16:36:11 garage go-librespot[1732]: go-librespot daemon starting... Jan 12 16:36:11 garage sudo[1722]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:12 garage startx[1750]: X.Org X Server 1.21.1.7 Jan 12 16:36:12 garage startx[1750]: X Protocol Version 11, Revision 0 Jan 12 16:36:12 garage startx[1750]: Current Operating System: Linux garage 6.12.47-v7+ #1904 SMP Mon Sep 15 13:05:52 BST 2025 armv7l Jan 12 16:36:12 garage startx[1750]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 cgroup_disable=memory snd_bcm2835.enable_headphones=1 snd_bcm2835.enable_hdmi=1 clk_ignore_unused 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 Jan 12 16:36:12 garage startx[1750]: xorg-server 2:21.1.7-3+rpt3+deb12u11 (https://www.debian.org/support) Jan 12 16:36:12 garage startx[1750]: Current version of pixman: 0.44.0 Jan 12 16:36:12 garage startx[1750]: Before reporting problems, check http://wiki.x.org Jan 12 16:36:12 garage startx[1750]: to make sure that you have the latest version. Jan 12 16:36:12 garage startx[1750]: Markers: (--) probed, (**) from config file, (==) default setting, Jan 12 16:36:12 garage startx[1750]: (++) from command line, (!!) notice, (II) informational, Jan 12 16:36:12 garage startx[1750]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Jan 12 16:36:12 garage startx[1750]: (==) Log file: "/var/log/Xorg.0.log", Time: Mon Jan 12 16:36:12 2026 Jan 12 16:36:12 garage startx[1750]: (==) Using config directory: "/etc/X11/xorg.conf.d" Jan 12 16:36:12 garage startx[1750]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Jan 12 16:36:12 garage go-librespot[1738]: time="2026-01-12T16:36:12+01:00" level=info msg="running go-librespot 0.4.0" Jan 12 16:36:12 garage go-librespot[1738]: time="2026-01-12T16:36:12+01:00" level=debug msg="app state loaded" Jan 12 16:36:12 garage volumio[1174]: info: touch_display: IframeKeyboardBridge extension installed successfully Jan 12 16:36:12 garage go-librespot[1738]: time="2026-01-12T16:36:12+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:12 garage volumio[1174]: info: No need to fix Spotify hosts Jan 12 16:36:13 garage go-librespot[1738]: time="2026-01-12T16:36:13+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]" Jan 12 16:36:13 garage go-librespot[1738]: time="2026-01-12T16:36:13+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]" Jan 12 16:36:13 garage go-librespot[1738]: time="2026-01-12T16:36:13+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]" Jan 12 16:36:13 garage go-librespot[1738]: time="2026-01-12T16:36:13+01:00" level=info msg="zeroconf server listening on port 34987" Jan 12 16:36:13 garage go-librespot[1738]: time="2026-01-12T16:36:13+01:00" level=debug msg="obtained new client token: AABpVRUCdus+GuEmvxItuUWMY6wr5Yx0gf1W2WfDPC47c23DOW6CrfL325iFoeGoYa0Zxp7hcT+onxthbO2X2AqhrSY4f/VwVnO970WqUa4OGXTPxuihXpV2qyefoTZAw9QQ0Rl25F2Ldb4B4fw1w7JgvDhe+3gbJMwAELtkLhQ3qwxwqWm2MutdnhZDs7psHbAoQroB0DtXohbBkQs2T3624hqotMaVK0a4nqsH8fPgK+Qct2AWW8k=" Jan 12 16:36:13 garage go-librespot[1738]: time="2026-01-12T16:36:13+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" Jan 12 16:36:13 garage go-librespot[1738]: time="2026-01-12T16:36:13+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 12 16:36:13 garage volumio[1174]: error: MPD error: The expression evaluated to a falsy value: Jan 12 16:36:13 garage volumio[1174]: assert.ok(self.idling) Jan 12 16:36:13 garage volumio[1174]: error: The expression evaluated to a falsy value: Jan 12 16:36:13 garage volumio[1174]: assert.ok(self.idling) Jan 12 16:36:14 garage volumio[1174]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 12 16:36:14 garage volumio[1174]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Jan 12 16:36:14 garage volumio[1174]: info: touch_display: Volumio Kiosk started. Jan 12 16:36:14 garage volumio[1174]: info: CoreCommandRouter::volumioGetState Jan 12 16:36:14 garage volumio[1174]: info: CorePlayQueue::getTrack 0 Jan 12 16:36:14 garage volumio[1174]: info: MPD running with PID1595 Jan 12 16:36:14 garage volumio[1174]: ,establishing connection Jan 12 16:36:14 garage volumio[1174]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 12 16:36:14 garage volumio[1174]: SPOTIFY: BQDYFbuYrACR1P1EwGntLDEdrwj7cwn78GM6e-rfl0oxQZj2jg4-w1R0cc1zVlQBDbTqDedvO__B7xm02u_emnjwgb8bOTpgWKxAtd9M47bco-fIonAvv-YzPQ8PMVz215Cy22F0JFr1a7Vgy7YXD7fJvpWZi0sfUptJ6udfgEW68gj8ZJmIwaO7gpKZv_EUF641CEIgHxLw7NgV5ysEbu6PaNf737cJb5yON_Y1VL6_18vKGb5Xq620yTRdH0vpQFLEIZue6SjjyAEoz8LicKxEtMArSOSIecZkoHrAYCggYhJX2RckYsPy-cN6 Jan 12 16:36:14 garage volumio[1174]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 12 16:36:14 garage volumio[1174]: info: New Spotify access token = BQDYFbuYrACR1P1EwGntLDEdrwj7cwn78GM6e-rfl0oxQZj2jg4-w1R0cc1zVlQBDbTqDedvO__B7xm02u_emnjwgb8bOTpgWKxAtd9M47bco-fIonAvv-YzPQ8PMVz215Cy22F0JFr1a7Vgy7YXD7fJvpWZi0sfUptJ6udfgEW68gj8ZJmIwaO7gpKZv_EUF641CEIgHxLw7NgV5ysEbu6PaNf737cJb5yON_Y1VL6_18vKGb5Xq620yTRdH0vpQFLEIZue6SjjyAEoz8LicKxEtMArSOSIecZkoHrAYCggYhJX2RckYsPy-cN6 Jan 12 16:36:14 garage volumio[1174]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 12 16:36:14 garage sudo[1792]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/rpi_backlight/brightness Jan 12 16:36:14 garage sudo[1792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:14 garage sudo[1792]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:14 garage volumio[1174]: error: updateQueue error: null Jan 12 16:36:14 garage volumio[1174]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jan 12 16:36:14 garage sudo[1807]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay gpio-key gpio=27 active_low=true gpio_pull=up keycode=20 Jan 12 16:36:14 garage sudo[1807]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:14 garage sudo[1807]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:14 garage kernel: input: button@1b as /devices/platform/button@1b/input/input2 Jan 12 16:36:15 garage volumio[1174]: info: touch_display: Raspberry Pi Foundation touch screen detected. Jan 12 16:36:15 garage sudo[1862]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Jan 12 16:36:15 garage sudo[1862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:15 garage sudo[1862]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:15 garage sudo[1859]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Jan 12 16:36:15 garage sudo[1859]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:15 garage sudo[1859]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:15 garage volumio[1174]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jan 12 16:36:15 garage volumio[1174]: info: touch_display: File permissions for backlight brightness control set. Jan 12 16:36:15 garage volumio[1174]: info: touch_display: X display number found: 0 Jan 12 16:36:15 garage volumio[1174]: info: Starting Shairport Sync Jan 12 16:36:16 garage volumio[1174]: info: Starting Shairport Sync Jan 12 16:36:16 garage volumio[1174]: info: Starting Shairport Sync Jan 12 16:36:16 garage sudo[1881]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 12 16:36:16 garage sudo[1881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:16 garage sudo[1884]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 12 16:36:16 garage sudo[1884]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:16 garage systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 12 16:36:16 garage systemd[1]: shairport-sync.service: Deactivated successfully. Jan 12 16:36:16 garage systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 12 16:36:16 garage systemd[1]: shairport-sync.service: Consumed 1.817s CPU time. Jan 12 16:36:16 garage sudo[1893]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 12 16:36:16 garage sudo[1893]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:16 garage systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 12 16:36:16 garage volumio[1174]: error: updateQueue error: null Jan 12 16:36:16 garage sudo[1881]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:16 garage systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 12 16:36:16 garage systemd[1]: shairport-sync.service: Deactivated successfully. Jan 12 16:36:16 garage systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 12 16:36:16 garage systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 12 16:36:16 garage sudo[1893]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:16 garage sudo[1884]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:16 garage volumio-remote-updater[639]: [2026-01-12 16:36:16] [connect] Successful connection Jan 12 16:36:16 garage volumio[1174]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Jan 12 16:36:16 garage volumio[1174]: info: touch_display: X display number found: 0 Jan 12 16:36:16 garage volumio[1174]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Jan 12 16:36:16 garage volumio[1174]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Jan 12 16:36:16 garage volumio[1174]: info: Asound.conf file unchanged, so no further update is needed Jan 12 16:36:16 garage volumio[1174]: info: Output device has changed, restarting MPD Jan 12 16:36:16 garage volumio[1174]: info: Output device has changed, restarting Shairport Sync Jan 12 16:36:16 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:16 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 16:36:16 garage sudo[1913]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 12 16:36:16 garage sudo[1913]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:16 garage sudo[1913]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:16 garage sudo[1915]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 12 16:36:16 garage sudo[1915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:16 garage volumio[1174]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 12 16:36:17 garage systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 12 16:36:17 garage volumio[1174]: info: ir_controller: LIRC correctly updated. Jan 12 16:36:17 garage volumio[1174]: info: ir_controller: HAT did not load /proc/device-tree/ir_receiver! Jan 12 16:36:17 garage volumio[1174]: info: CoreCommandRouter::volumioGetState Jan 12 16:36:17 garage volumio[1174]: info: CorePlayQueue::getTrack 0 Jan 12 16:36:17 garage systemd[1]: mpd.service: Deactivated successfully. Jan 12 16:36:17 garage systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 12 16:36:17 garage systemd[1]: mpd.service: Consumed 4.806s CPU time. Jan 12 16:36:17 garage systemd[1]: mpd.socket: Deactivated successfully. Jan 12 16:36:17 garage systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 12 16:36:17 garage systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 12 16:36:17 garage systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 12 16:36:17 garage systemd[1]: Starting mpd.service - Music Player Daemon... Jan 12 16:36:17 garage sudo[1931]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay rotary-encoder pin_a=5 pin_b=6 relative_axis=true steps-per-period=1 Jan 12 16:36:17 garage sudo[1931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:17 garage kernel: rotary-encoder rotary@5: gray Jan 12 16:36:18 garage kernel: input: rotary@5 as /devices/platform/rotary@5/input/input3 Jan 12 16:36:18 garage sudo[1933]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 12 16:36:18 garage sudo[1933]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 12 16:36:18 garage sudo[1933]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:18 garage sudo[1931]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:18 garage volumio[1174]: info: Shairport-Sync Started Jan 12 16:36:18 garage volumio[1174]: Error adding Membership: Error: addMembership EINVAL Jan 12 16:36:18 garage volumio[1174]: info: Shairport-Sync Started Jan 12 16:36:18 garage volumio[1174]: info: Shairport-Sync Started Jan 12 16:36:18 garage volumio[1174]: info: go-librespot daemon successfully initialized Jan 12 16:36:18 garage volumio[1174]: info: CoreCommandRouter::volumioGetState Jan 12 16:36:18 garage volumio[1174]: info: CorePlayQueue::getTrack 0 Jan 12 16:36:18 garage volumio[1174]: info: ir_controller: Raspberry Pi revision code: a020d3 Jan 12 16:36:18 garage volumio[1174]: info: MPD Permissions set Jan 12 16:36:18 garage volumio[1174]: info: Listing playlists Jan 12 16:36:18 garage volumio[1174]: info: Listing playlists Jan 12 16:36:19 garage sudo[1969]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart lircd.service Jan 12 16:36:19 garage sudo[1969]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:19 garage systemd[1]: Starting lircd-setup.service - lircd(8) initialization helper tool... Jan 12 16:36:19 garage sudo[1978]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r -1 Jan 12 16:36:19 garage sudo[1978]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:19 garage sudo[1978]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:19 garage lircd-setup[1976]: /usr/sbin/lircd-setup:37: DeprecationWarning: The SafeConfigParser class has been renamed to ConfigParser in Python 3.2. This alias will be removed in Python 3.12. Use ConfigParser directly instead. Jan 12 16:36:19 garage lircd-setup[1976]: parser = configparser.SafeConfigParser() Jan 12 16:36:19 garage systemd[1]: lircd-setup.service: Deactivated successfully. Jan 12 16:36:19 garage sudo[1981]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Jan 12 16:36:19 garage sudo[1981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:19 garage systemd[1]: Finished lircd-setup.service - lircd(8) initialization helper tool. Jan 12 16:36:19 garage sudo[1981]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:20 garage volumio[1174]: info: touch_display: Setting screensaver timeout to 100 seconds. Jan 12 16:36:20 garage systemd[1]: Starting lircd.service - Flexible IR remote input/output application support... Jan 12 16:36:20 garage lircd-0.10.1[1984]: Info: lircd: Opening log, level: Info Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Version: lircd 0.10.1 Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: System info: Linux garage 6.12.47-v7+ #1904 SMP Mon Sep 15 13:05:52 BST 2025 armv7l GNU/Linux Jan 12 16:36:20 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:20 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:20 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:20 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:20 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:20 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:20 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:20 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:20 garage lircd-0.10.1[1984]: Info: Initial device: /dev/lirc0 Jan 12 16:36:20 garage lircd-0.10.1[1984]: Warning: Cannot access device: /dev/lirc0 Jan 12 16:36:20 garage lircd-0.10.1[1984]: Info: Initial device: /dev/lirc0 Jan 12 16:36:20 garage lircd[1984]: lircd-0.10.1[1984]: Info: lircd: Opening log, level: Info Jan 12 16:36:20 garage lircd[1984]: lircd-0.10.1[1984]: Notice: Using systemd fd Jan 12 16:36:20 garage lircd-0.10.1[1984]: Warning: Cannot access device: /dev/lirc0 Jan 12 16:36:20 garage lircd[1984]: lircd-0.10.1[1984]: Warning: Running as root Jan 12 16:36:20 garage lircd[1984]: lircd-0.10.1[1984]: Info: Using remote: rc2. Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Options: driver: default Jan 12 16:36:20 garage lircd[1984]: lircd-0.10.1[1984]: Notice: lircd(default) ready, using /var/run/lirc/lircd Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Options: output: /var/run/lirc/lircd Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Options: nodaemon: 1 Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Options: plugindir: /usr/lib/arm-linux-gnueabihf/lirc/plugins Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Options: logfile: syslog Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Options: immediate-init: 0 Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Options: permission: 666 Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Options: driver-options: Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Options: pidfile: /var/run/lirc/lircd.pid Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Options: listen: 0 Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Options: connect: (null) Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Options: userelease: 0 Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Options: effective_user: (null) Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Options: release_suffix: _EVUP Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Options: allow_simulate: 0 Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Options: repeat_max: 600 Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Options: configfile: /etc/lirc/lircd.conf Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Options: dynamic_codes: (null) Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Current driver: default Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Driver API version: 3 Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Driver version: 0.10.0 Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Driver info: See file:///usr/share/doc/lirc/plugindocs/default.html Jan 12 16:36:20 garage lircd-0.10.1[1984]: Info: lircd: Opening log, level: Info Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: Using systemd fd Jan 12 16:36:20 garage lircd-0.10.1[1984]: Warning: Running as root Jan 12 16:36:20 garage lircd-0.10.1[1984]: Info: Using remote: rc2. Jan 12 16:36:20 garage lircd-0.10.1[1984]: Notice: lircd(default) ready, using /var/run/lirc/lircd Jan 12 16:36:20 garage systemd[1]: Started lircd.service - Flexible IR remote input/output application support. Jan 12 16:36:20 garage sudo[1969]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:20 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 16:36:20 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:36:20 garage go-librespot[1738]: time="2026-01-12T16:36:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.88.184:59448->104.199.65.9:443: read: connection reset by peer" Jan 12 16:36:20 garage systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 12 16:36:20 garage systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 12 16:36:20 garage volumio[1174]: info: Completed starting Core Plugins Jan 12 16:36:20 garage volumio[1174]: info: ------------------------------------------- Jan 12 16:36:20 garage volumio[1174]: info: ----- MyVolumio plugins startup ---- Jan 12 16:36:20 garage volumio[1174]: info: ------------------------------------------- Jan 12 16:36:20 garage volumio[1174]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 12 16:36:20 garage sudo[2008]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Jan 12 16:36:20 garage sudo[2008]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:20 garage sudo[2008]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:20 garage volumio[1174]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jan 12 16:36:20 garage volumio[1174]: info: ir_controller: systemctl restart lircd.service succeeded. Jan 12 16:36:20 garage volumio-remote-updater[639]: [2026-01-12 16:36:20] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1768232176 101 Jan 12 16:36:20 garage volumio[1174]: 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: 7 Jan 12 16:36:21 garage sudo[2013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart irexec.service Jan 12 16:36:21 garage sudo[2013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:21 garage volumio[1174]: info: Initializing connection to go-librespot Websocket Jan 12 16:36:21 garage systemd[1]: Started irexec.service - Handle events from IR remotes decoded by lircd(8). Jan 12 16:36:21 garage lircd[1984]: lircd-0.10.1[1984]: Notice: accepted new client on /var/run/lirc/lircd Jan 12 16:36:21 garage lircd-0.10.1[1984]: Notice: accepted new client on /var/run/lirc/lircd Jan 12 16:36:21 garage lircd[1984]: lircd-0.10.1[1984]: Info: Cannot configure the rc device for /dev/lirc0 Jan 12 16:36:21 garage lircd[1984]: lircd-0.10.1[1984]: Error: could not get file information for /dev/lirc0 Jan 12 16:36:21 garage lircd[1984]: lircd-0.10.1[1984]: default_init(): No such file or directory Jan 12 16:36:21 garage lircd[1984]: lircd-0.10.1[1984]: Warning: Failed to initialize hardware Jan 12 16:36:21 garage lircd-0.10.1[1984]: Info: Cannot configure the rc device for /dev/lirc0 Jan 12 16:36:21 garage lircd-0.10.1[1984]: Error: could not get file information for /dev/lirc0 Jan 12 16:36:21 garage lircd-0.10.1[1984]: default_init(): No such file or directory Jan 12 16:36:21 garage lircd-0.10.1[1984]: Warning: Failed to initialize hardware Jan 12 16:36:21 garage sudo[2013]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:21 garage volumio[1174]: info: Starting Shairport Sync Jan 12 16:36:21 garage sudo[2021]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 12 16:36:21 garage sudo[2021]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:21 garage volumio[1174]: info: ir_controller: systemctl restart irexec.service succeeded. Jan 12 16:36:21 garage volumio[1174]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 12 16:36:21 garage systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 12 16:36:21 garage systemd[1]: shairport-sync.service: Deactivated successfully. Jan 12 16:36:21 garage systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 12 16:36:21 garage systemd[1]: shairport-sync.service: Consumed 1.225s CPU time. Jan 12 16:36:21 garage sudo[2024]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay gpio-ir gpio_pin=25 gpio_pull=up Jan 12 16:36:21 garage sudo[2024]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:21 garage systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 12 16:36:21 garage sudo[2021]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:21 garage mpd[1951]: 2026-01-12T16:36:21 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 12 16:36:21 garage systemd[1]: Started mpd.service - Music Player Daemon. Jan 12 16:36:21 garage sudo[1915]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:22 garage kernel: Registered IR keymap rc-rc6-mce Jan 12 16:36:22 garage kernel: IR RC6 protocol handler initialized Jan 12 16:36:22 garage sudo[2024]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:22 garage kernel: rc rc0: gpio_ir_recv as /devices/platform/ir-receiver@19/rc/rc0 Jan 12 16:36:22 garage kernel: rc rc0: lirc_dev: driver gpio_ir_recv registered at minor = 0, raw IR receiver, no transmitter Jan 12 16:36:22 garage kernel: input: gpio_ir_recv as /devices/platform/ir-receiver@19/rc/rc0/input4 Jan 12 16:36:22 garage systemd-logind[631]: Watching system buttons on /dev/input/event4 (gpio_ir_recv) Jan 12 16:36:22 garage volumio[1174]: info: CoreCommandRouter::volumioGetState Jan 12 16:36:22 garage volumio[1174]: info: CorePlayQueue::getTrack 0 Jan 12 16:36:22 garage volumio[1174]: info: Shairport-Sync Started Jan 12 16:36:22 garage volumio[1174]: info: ir_controller: Overlay gpio-ir gpio_pin=25 gpio_pull=up loaded. Jan 12 16:36:22 garage sudo[2066]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart lircd.service Jan 12 16:36:22 garage sudo[2066]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:23 garage volumio[1174]: error: updateQueue error: null Jan 12 16:36:23 garage lircd[1984]: lircd-0.10.1[1984]: Notice: caught signal Jan 12 16:36:23 garage lircd-0.10.1[1984]: Notice: caught signal Jan 12 16:36:23 garage systemd[1]: Stopping lircd.service - Flexible IR remote input/output application support... Jan 12 16:36:23 garage systemd[1]: lircd.service: Deactivated successfully. Jan 12 16:36:23 garage systemd[1]: Stopped lircd.service - Flexible IR remote input/output application support. Jan 12 16:36:23 garage systemd[1]: irexec.service: Deactivated successfully. Jan 12 16:36:23 garage systemd[1]: Starting lircd-setup.service - lircd(8) initialization helper tool... Jan 12 16:36:23 garage lircd-setup[2069]: /usr/sbin/lircd-setup:37: DeprecationWarning: The SafeConfigParser class has been renamed to ConfigParser in Python 3.2. This alias will be removed in Python 3.12. Use ConfigParser directly instead. Jan 12 16:36:23 garage lircd-setup[2069]: parser = configparser.SafeConfigParser() Jan 12 16:36:23 garage systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 12 16:36:23 garage systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 12 16:36:23 garage volumio[1174]: info: CoreCommandRouter::volumioGetState Jan 12 16:36:23 garage volumio[1174]: info: CorePlayQueue::getTrack 0 Jan 12 16:36:23 garage systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 12 16:36:23 garage systemd[1]: lircd-setup.service: Deactivated successfully. Jan 12 16:36:23 garage go-librespot[2078]: go-librespot daemon starting... Jan 12 16:36:23 garage systemd[1]: Finished lircd-setup.service - lircd(8) initialization helper tool. Jan 12 16:36:23 garage systemd[1]: Starting lircd.service - Flexible IR remote input/output application support... Jan 12 16:36:23 garage lircd-0.10.1[2080]: Info: lircd: Opening log, level: Info Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Version: lircd 0.10.1 Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: System info: Linux garage 6.12.47-v7+ #1904 SMP Mon Sep 15 13:05:52 BST 2025 armv7l GNU/Linux Jan 12 16:36:23 garage lircd-0.10.1[2080]: Info: Initial device: /dev/lirc0 Jan 12 16:36:23 garage lircd-0.10.1[2080]: Info: [lirc] protocol is enabled Jan 12 16:36:23 garage lircd-0.10.1[2080]: Info: Initial device: /dev/lirc0 Jan 12 16:36:23 garage lircd-0.10.1[2080]: Info: [lirc] protocol is enabled Jan 12 16:36:23 garage lircd[2080]: lircd-0.10.1[2080]: Info: lircd: Opening log, level: Info Jan 12 16:36:23 garage lircd[2080]: lircd-0.10.1[2080]: Notice: Using systemd fd Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Options: driver: default Jan 12 16:36:23 garage lircd[2080]: lircd-0.10.1[2080]: Warning: Running as root Jan 12 16:36:23 garage lircd[2080]: lircd-0.10.1[2080]: Info: Using remote: rc2. Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Options: output: /var/run/lirc/lircd Jan 12 16:36:23 garage lircd[2080]: lircd-0.10.1[2080]: Notice: lircd(default) ready, using /var/run/lirc/lircd Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Options: nodaemon: 1 Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Options: plugindir: /usr/lib/arm-linux-gnueabihf/lirc/plugins Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Options: logfile: syslog Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Options: immediate-init: 0 Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Options: permission: 666 Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Options: driver-options: Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Options: pidfile: /var/run/lirc/lircd.pid Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Options: listen: 0 Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Options: connect: (null) Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Options: userelease: 0 Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Options: effective_user: (null) Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Options: release_suffix: _EVUP Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Options: allow_simulate: 0 Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Options: repeat_max: 600 Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Options: configfile: /etc/lirc/lircd.conf Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Options: dynamic_codes: (null) Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Current driver: default Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Driver API version: 3 Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Driver version: 0.10.0 Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Driver info: See file:///usr/share/doc/lirc/plugindocs/default.html Jan 12 16:36:23 garage lircd-0.10.1[2080]: Info: lircd: Opening log, level: Info Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: Using systemd fd Jan 12 16:36:23 garage lircd-0.10.1[2080]: Warning: Running as root Jan 12 16:36:23 garage lircd-0.10.1[2080]: Info: Using remote: rc2. Jan 12 16:36:23 garage lircd-0.10.1[2080]: Notice: lircd(default) ready, using /var/run/lirc/lircd Jan 12 16:36:23 garage systemd[1]: Started lircd.service - Flexible IR remote input/output application support. Jan 12 16:36:23 garage sudo[2066]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:23 garage go-librespot[2079]: time="2026-01-12T16:36:23+01:00" level=info msg="running go-librespot 0.4.0" Jan 12 16:36:23 garage go-librespot[2079]: time="2026-01-12T16:36:23+01:00" level=debug msg="app state loaded" Jan 12 16:36:23 garage go-librespot[2079]: time="2026-01-12T16:36:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 12 16:36:23 garage volumio[1174]: info: ir_controller: systemctl restart lircd.service succeeded. Jan 12 16:36:24 garage sudo[2094]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart irexec.service Jan 12 16:36:24 garage sudo[2094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:24 garage volumio[1174]: info: CoreCommandRouter::volumioGetState Jan 12 16:36:24 garage volumio[1174]: info: CorePlayQueue::getTrack 0 Jan 12 16:36:24 garage volumio[1174]: SPOTIFY: User informations: {"country":"MT","display_name":"cfmt","email":"cfarr_mt@yahoo.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31wrmgdvir3k6mkgbw2lmiavhyty"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31wrmgdvir3k6mkgbw2lmiavhyty","id":"31wrmgdvir3k6mkgbw2lmiavhyty","images":[],"product":"premium","type":"user","uri":"spotify:user:31wrmgdvir3k6mkgbw2lmiavhyty"} Jan 12 16:36:24 garage volumio[1174]: info: Spotify Successfully logged in Jan 12 16:36:24 garage systemd[1]: Started irexec.service - Handle events from IR remotes decoded by lircd(8). Jan 12 16:36:24 garage lircd[2080]: lircd-0.10.1[2080]: Notice: accepted new client on /var/run/lirc/lircd Jan 12 16:36:24 garage lircd-0.10.1[2080]: Notice: accepted new client on /var/run/lirc/lircd Jan 12 16:36:24 garage lircd[2080]: lircd-0.10.1[2080]: Info: [lirc] protocol is enabled Jan 12 16:36:24 garage lircd-0.10.1[2080]: Info: [lirc] protocol is enabled Jan 12 16:36:24 garage sudo[2094]: pam_unix(sudo:session): session closed for user root Jan 12 16:36:24 garage volumio[1174]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 16:36:24 garage volumio[1174]: info: [1768232184540] CoreMusicLibrary::Adding element Spotify Jan 12 16:36:24 garage volumio[1174]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 16:36:24 garage volumio[1174]: Cannot find translation for source Spotify Jan 12 16:36:24 garage go-librespot[2079]: time="2026-01-12T16:36:24+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-gew4.spotify.com:80]" Jan 12 16:36:24 garage go-librespot[2079]: time="2026-01-12T16:36:24+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 12 16:36:24 garage go-librespot[2079]: time="2026-01-12T16:36:24+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 12 16:36:24 garage go-librespot[2079]: time="2026-01-12T16:36:24+01:00" level=info msg="zeroconf server listening on port 35501" Jan 12 16:36:24 garage volumio[1174]: info: ir_controller: systemctl restart irexec.service succeeded. Jan 12 16:36:24 garage volumio[1174]: info: Initializing connection to go-librespot Websocket Jan 12 16:36:24 garage volumio[1174]: info: Connection to go-librespot Websocket established Jan 12 16:36:24 garage go-librespot[2079]: time="2026-01-12T16:36:24+01:00" level=debug msg="new websocket client" Jan 12 16:36:24 garage go-librespot[2079]: time="2026-01-12T16:36:24+01:00" level=debug msg="obtained new client token: AAAV+wazpSJ7cvEMiNPNLEiOTrHRnZtlarpAKJyo3zy+oWsDM7ln+X23nfTmLUUWerq3CwW+2VKQy2JTb/ZKMcPxkD/2G3gRz/q0EAWaNQM4BSnn9Ed2ZCoW53hIaWooKtspSOYDkfo3nqsDhLgJ2bUaD9ZFN5OGGhEQMIQ1LAJ7m9zSeLpUOvLYUmonrrLpoiIPOrLzlisErJZF5vsEfzYBl7BA2AUwFQcjyy7BakBgnm3TLKLdKUU=" Jan 12 16:36:24 garage go-librespot[2079]: time="2026-01-12T16:36:24+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 12 16:36:24 garage go-librespot[2079]: time="2026-01-12T16:36:24+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.88.184:55316->104.199.65.9:4070: read: connection reset by peer" Jan 12 16:36:24 garage systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 12 16:36:24 garage systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 12 16:36:25 garage volumio[1174]: info: Connection to go-librespot Websocket closed Jan 12 16:36:28 garage systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 12 16:36:28 garage systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 12 16:36:28 garage systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 12 16:36:28 garage volumio[1174]: info: Getting Spotify volume Jan 12 16:36:28 garage volumio[1174]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 16:36:28 garage go-librespot[2139]: go-librespot daemon starting... Jan 12 16:36:28 garage volumio[1174]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 12 16:36:28 garage volumio[1174]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 12 16:36:28 garage volumio[1174]: errno: -111, Jan 12 16:36:28 garage volumio[1174]: code: 'ECONNREFUSED', Jan 12 16:36:28 garage volumio[1174]: syscall: 'connect', Jan 12 16:36:28 garage volumio[1174]: address: '127.0.0.1', Jan 12 16:36:28 garage volumio[1174]: port: 9879, Jan 12 16:36:28 garage volumio[1174]: response: undefined Jan 12 16:36:28 garage volumio[1174]: } Jan 12 16:36:28 garage volumio[1174]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 16:36:28 garage go-librespot[2140]: time="2026-01-12T16:36:28+01:00" level=info msg="running go-librespot 0.4.0" Jan 12 16:36:28 garage go-librespot[2140]: time="2026-01-12T16:36:28+01:00" level=debug msg="app state loaded" Jan 12 16:36:28 garage go-librespot[2140]: time="2026-01-12T16:36:28+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 12 16:36:29 garage go-librespot[2140]: time="2026-01-12T16:36:29+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]" Jan 12 16:36:29 garage go-librespot[2140]: time="2026-01-12T16:36:29+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]" Jan 12 16:36:29 garage go-librespot[2140]: time="2026-01-12T16:36:29+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]" Jan 12 16:36:29 garage go-librespot[2140]: time="2026-01-12T16:36:29+01:00" level=info msg="zeroconf server listening on port 46161" Jan 12 16:36:29 garage go-librespot[2140]: time="2026-01-12T16:36:29+01:00" level=debug msg="obtained new client token: AADNd8Pl/xj2KNlcAt7yBdrud45hnK00MUDINw9vTOwpSlgakljKVOpPEjQKXwixJ+eBK5jMu2V6wgynCW0eedqrqnBdxlTYLxuS9DAFziRe49hgi3nvkWSe/JFhtvU5DUWWCWf7YF2h57HUg013CWS2azhjt8sKYOfxmQDUUOLIwlFp5osR0aYMi2tl6VfbkDexhdECn2wzBm5x0a6pvvh9m9zYiBjIAJPxldirmEAZNEivPF3mAM4=" Jan 12 16:36:34 garage go-librespot[2140]: time="2026-01-12T16:36:34+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 12 16:36:34 garage go-librespot[2140]: time="2026-01-12T16:36:34+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.88.184:55330->104.199.65.9:4070: read: connection reset by peer" Jan 12 16:36:34 garage systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 12 16:36:34 garage systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 12 16:36:35 garage upmpdcli[2178]: writing RSA key Jan 12 16:36:37 garage sudo[2184]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-12 16:35' Jan 12 16:36:37 garage sudo[2184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 16:36:37 garage systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 12 16:36:37 garage systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 12 16:36:37 garage systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 12 16:36:37 garage go-librespot[2186]: go-librespot daemon starting... Jan 12 16:36:37 garage go-librespot[2187]: time="2026-01-12T16:36:37+01:00" level=info msg="running go-librespot 0.4.0" Jan 12 16:36:37 garage go-librespot[2187]: time="2026-01-12T16:36:37+01:00" level=debug msg="app state loaded" Jan 12 16:36:37 garage go-librespot[2187]: time="2026-01-12T16:36:37+01: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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"