Dec 29 12:22:26 garage ntpd[983]: CLOCK: time stepped by 26.705735 Dec 29 12:22:26 garage ntpd[983]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Dec 29 12:22:27 garage volumio[1224]: info: MYVOLUMIO Environment detected Dec 29 12:22:27 garage volumio[1224]: info: Plugin folders cleanup Dec 29 12:22:27 garage volumio[1224]: info: Scanning into folder /volumio/app/plugins/ Dec 29 12:22:27 garage volumio[1224]: info: Scanning category audio_interface Dec 29 12:22:27 garage volumio[1224]: info: Scanning category miscellanea Dec 29 12:22:27 garage volumio[1224]: info: Scanning category music_service Dec 29 12:22:27 garage volumio[1224]: info: Scanning category plugins.json Dec 29 12:22:27 garage volumio[1224]: info: Scanning category system_controller Dec 29 12:22:27 garage volumio[1224]: info: Scanning category user_interface Dec 29 12:22:27 garage volumio[1224]: info: Scanning into folder /data/plugins/ Dec 29 12:22:27 garage volumio[1224]: info: Scanning category music_service Dec 29 12:22:27 garage volumio[1224]: info: Scanning category system_controller Dec 29 12:22:27 garage volumio[1224]: info: Scanning category system_hardware Dec 29 12:22:27 garage volumio[1224]: info: Scanning category user_interface Dec 29 12:22:27 garage volumio[1224]: info: Plugin folders cleanup completed Dec 29 12:22:27 garage volumio[1224]: info: ------------------------------------------- Dec 29 12:22:27 garage volumio[1224]: info: ----- Core plugins startup ---- Dec 29 12:22:27 garage volumio[1224]: info: ------------------------------------------- Dec 29 12:22:27 garage volumio[1224]: info: Loading plugins from folder /volumio/app/plugins/ Dec 29 12:22:27 garage volumio[1224]: info: Adding plugin upnp to MyMusic Plugins Dec 29 12:22:27 garage volumio[1224]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 29 12:22:27 garage volumio[1224]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 29 12:22:27 garage volumio[1224]: info: Loading plugins from folder /data/plugins/ Dec 29 12:22:27 garage volumio[1224]: info: Loading plugin "system"... Dec 29 12:22:27 garage volumio[1224]: info: Loading plugin "appearance"... Dec 29 12:22:27 garage dhcpcd[618]: timed out Dec 29 12:22:27 garage sh[614]: timed out Dec 29 12:22:28 garage dhcpcd[618]: dhcpcd exited Dec 29 12:22:28 garage sh[572]: ifup: failed to bring up eth0 Dec 29 12:22:28 garage systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Dec 29 12:22:28 garage systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Dec 29 12:22:29 garage volumio[1224]: info: Loading plugin "network"... Dec 29 12:22:29 garage volumio[1224]: info: Refreshing Cached IP Addresses Dec 29 12:22:29 garage volumio[1224]: info: Loading plugin "services"... Dec 29 12:22:29 garage volumio[1224]: info: Loading plugin "alsa_controller"... Dec 29 12:22:29 garage sudo[1338]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 29 12:22:29 garage sudo[1338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:22:29 garage sudo[1340]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 29 12:22:29 garage sudo[1340]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:22:29 garage sudo[1338]: pam_unix(sudo:session): session closed for user root Dec 29 12:22:29 garage sudo[1340]: pam_unix(sudo:session): session closed for user root Dec 29 12:22:29 garage sudo[1346]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 29 12:22:29 garage sudo[1346]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:22:29 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 29 12:22:29 garage volumio[1224]: info: Loading plugin "wizard"... Dec 29 12:22:29 garage volumio[1224]: info: Loading plugin "networkfs"... Dec 29 12:22:29 garage volumio[1224]: info: Starting Udev Watcher for removable devices Dec 29 12:22:29 garage volumio[1224]: info: Ignoring mount for partition: boot Dec 29 12:22:29 garage volumio[1224]: info: Ignoring mount for partition: volumio Dec 29 12:22:29 garage volumio[1224]: info: Ignoring mount for partition: volumio_data Dec 29 12:22:29 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 29 12:22:29 garage sudo[1372]: 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 Dec 29 12:22:29 garage sudo[1372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:22:29 garage volumio[1224]: info: Loading plugin "volumio_command_line_client"... Dec 29 12:22:29 garage volumio[1224]: info: Loading plugin "upnp"... Dec 29 12:22:29 garage volumio[1224]: info: [1767007349917] Starting Upmpd Daemon Dec 29 12:22:29 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 29 12:22:29 garage volumio[1224]: info: Loading plugin "my_music"... Dec 29 12:22:29 garage volumio[1224]: info: Loading plugin "mpd"... Dec 29 12:22:30 garage kernel: netfs: FS-Cache loaded Dec 29 12:22:30 garage kernel: Key type cifs.spnego registered Dec 29 12:22:30 garage kernel: Key type cifs.idmap registered Dec 29 12:22:30 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. Dec 29 12:22:30 garage kernel: CIFS: Attempting to mount //192.168.88.148/Public/music Dec 29 12:22:30 garage systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Dec 29 12:22:30 garage systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 29 12:22:30 garage systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 29 12:22:30 garage upmpdcli[1393]: Could not open config: /tmp/upmpdcli.conf Dec 29 12:22:30 garage systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 29 12:22:30 garage systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 29 12:22:30 garage volumio[1224]: info: Loading plugin "upnp_browser"... Dec 29 12:22:31 garage sudo[1372]: pam_unix(sudo:session): session closed for user root Dec 29 12:22:32 garage systemd[1]: systemd-hostnamed.service: Deactivated successfully. Dec 29 12:22:32 garage volumio-remote-updater[647]: [2025-12-29 12:22:32] [connect] Successful connection Dec 29 12:22:33 garage sudo[1346]: pam_unix(sudo:session): session closed for user root Dec 29 12:22:33 garage volumio[1224]: info: Starting UPNP Browser Dec 29 12:22:33 garage volumio[1224]: info: Loading plugin "alarm-clock"... Dec 29 12:22:33 garage volumio[1224]: info: Loading plugin "airplay_emulation"... Dec 29 12:22:33 garage volumio[1224]: info: Starting Shairport Sync Dec 29 12:22:33 garage volumio[1224]: info: Loading plugin "last_100"... Dec 29 12:22:33 garage volumio[1224]: info: Loading plugin "webradio"... Dec 29 12:22:34 garage volumio[1224]: info: Loading plugin "i2s_dacs"... Dec 29 12:22:34 garage volumio[1224]: info: Loading plugin "volumiodiscovery"... Dec 29 12:22:34 garage volumio[1224]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 29 12:22:34 garage node[1224]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 29 12:22:34 garage volumio[1224]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 29 12:22:34 garage node[1224]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 29 12:22:34 garage volumio[1224]: *** WARNING *** For more information see Dec 29 12:22:34 garage node[1224]: *** WARNING *** For more information see Dec 29 12:22:34 garage volumio[1224]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 29 12:22:34 garage node[1224]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 29 12:22:34 garage volumio[1224]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 29 12:22:34 garage node[1224]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 29 12:22:34 garage volumio[1224]: *** WARNING *** For more information see Dec 29 12:22:34 garage node[1224]: *** WARNING *** For more information see Dec 29 12:22:34 garage volumio[1224]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 29 12:22:34 garage volumio[1224]: info: Discovery: Started advertising with name: Garage Dec 29 12:22:34 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 29 12:22:34 garage volumio[1224]: info: Loading plugin "spop"... Dec 29 12:22:36 garage volumio[1224]: info: Loading plugin "now_playing"... Dec 29 12:22:40 garage volumio[1224]: info: Loading plugin "outputs"... Dec 29 12:22:40 garage volumio[1224]: info: Loading plugin "albumart"... Dec 29 12:22:40 garage volumio[1224]: info: Plugin example_plugin is not enabled Dec 29 12:22:40 garage volumio[1224]: info: Loading plugin "inputs"... Dec 29 12:22:40 garage volumio[1224]: info: Loading plugin "updater_comm"... Dec 29 12:22:40 garage volumio[1224]: info: Plugin mpdemulation is not enabled Dec 29 12:22:40 garage volumio[1224]: info: Loading plugin "rest_api"... Dec 29 12:22:40 garage volumio[1224]: info: Loading plugin "websocket"... Dec 29 12:22:40 garage volumio[1224]: info: Starting Socket.io Server version 1.7.4 Dec 29 12:22:40 garage volumio[1224]: info: Loading plugin "backup_restore"... Dec 29 12:22:41 garage volumio[1224]: info: Applying required configuration parameters for plugin backup_restore Dec 29 12:22:41 garage volumio[1224]: info: Loading plugin "gpio_control"... Dec 29 12:22:41 garage volumio[1428]: Forking 3 albumart workers Dec 29 12:22:41 garage volumio[1224]: gpiox_arm32 V2.2.1 Dec 29 12:22:42 garage systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 29 12:22:43 garage volumio[1224]: info: Applying required configuration parameters for plugin gpio_control Dec 29 12:22:43 garage volumio[1224]: info: Loading plugin "ir_controller"... Dec 29 12:22:44 garage volumio[1224]: info: Applying required configuration parameters for plugin ir_controller Dec 29 12:22:45 garage volumio[1224]: info: Loading plugin "rotaryencoder2"... Dec 29 12:22:45 garage systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Dec 29 12:22:45 garage systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 29 12:22:45 garage systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 29 12:22:45 garage upmpdcli[1484]: Could not open config: /tmp/upmpdcli.conf Dec 29 12:22:45 garage systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 29 12:22:45 garage systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 29 12:22:46 garage volumio[1440]: Starting albumart workers Dec 29 12:22:47 garage volumio-remote-updater[647]: [2025-12-29 12:22:47] [connect] Successful connection Dec 29 12:22:47 garage volumio[1224]: info: Loading plugin "Systeminfo"... Dec 29 12:22:48 garage volumio[1438]: Starting albumart workers Dec 29 12:22:48 garage volumio[1439]: Starting albumart workers Dec 29 12:22:50 garage volumio[1224]: info: Loading plugin "peppymeterbasic"... Dec 29 12:22:52 garage volumio[1224]: info: Loading plugin "touch_display"... Dec 29 12:22:52 garage volumio[1224]: info: Applying required configuration parameters for plugin touch_display Dec 29 12:22:53 garage volumio[1224]: info: Loading i18n strings for locale en Dec 29 12:22:53 garage volumio[1224]: Updating browse sources language Dec 29 12:22:53 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 29 12:22:53 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 29 12:22:53 garage volumio[1224]: info: CoreCommandRouter::initPlayerControls Dec 29 12:22:53 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:22:53 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:22:53 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:22:53 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:22:53 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:22:53 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:22:53 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:22:53 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:22:53 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 29 12:22:53 garage volumio[1224]: Express server listening on port 3000 Dec 29 12:22:53 garage volumio[1224]: [Metrics] WebUI: 28s 721.05ms Dec 29 12:22:53 garage volumio[1224]: info: CoreStateMachine::resetVolumioState Dec 29 12:22:53 garage volumio[1224]: info: CoreStateMachine::getcurrentVolume Dec 29 12:22:53 garage volumio[1224]: info: CoreCommandRouter::volumioRetrievevolume Dec 29 12:22:53 garage sudo[1522]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 29 12:22:53 garage sudo[1522]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:22:53 garage sudo[1522]: pam_unix(sudo:session): session closed for user root Dec 29 12:22:54 garage sudo[1524]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 29 12:22:54 garage sudo[1524]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:22:54 garage sudo[1524]: pam_unix(sudo:session): session closed for user root Dec 29 12:22:54 garage volumio[1224]: info: Volumio Network Manager: Network status updated: 2 Dec 29 12:22:54 garage volumio[1224]: verbose: New Socket.io Connection to 192.168.88.184 from 192.168.88.76 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Dec 29 12:22:54 garage volumio[1224]: info: VolumeController:: Volume=22 Mute =false Dec 29 12:22:54 garage volumio[1224]: info: CoreStateMachine::pushState Dec 29 12:22:54 garage volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 29 12:22:54 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 29 12:22:54 garage volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 29 12:22:54 garage volumio[1224]: info: CoreStateMachine::updateTrackBlock Dec 29 12:22:54 garage volumio[1224]: info: CorePlayQueue::getTrackBlock Dec 29 12:22:54 garage volumio[1224]: info: CoreCommandRouter::volumioRetrievevolume Dec 29 12:22:54 garage volumio[1224]: verbose: New Socket.io Connection to 192.168.88.184 from 192.168.88.76 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Dec 29 12:22:54 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 29 12:22:54 garage volumio[1224]: info: Reloading queue from file Dec 29 12:22:55 garage volumio[1224]: info: CoreStateMachine::setRepeat null single undefined Dec 29 12:22:55 garage volumio[1224]: info: CoreStateMachine::pushState Dec 29 12:22:55 garage volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 29 12:22:55 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 29 12:22:55 garage volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 29 12:22:55 garage volumio[1224]: info: CoreStateMachine::setRandom null Dec 29 12:22:55 garage volumio[1224]: info: CoreStateMachine::pushState Dec 29 12:22:55 garage volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 29 12:22:55 garage volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 29 12:22:55 garage volumio[1224]: info: Setting Device type: Raspberry PI Dec 29 12:22:55 garage volumio[1224]: info: Completed loading Core Plugins Dec 29 12:22:55 garage volumio[1224]: info: Preparing to generate the ALSA configuration file Dec 29 12:22:55 garage volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 29 12:22:55 garage volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 29 12:22:55 garage volumio[1224]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 29 12:22:55 garage volumio[1224]: info: Reading ALSA contributions from plugins. Dec 29 12:22:55 garage volumio[1224]: verbose: New Socket.io Connection to 192.168.88.184 from 192.168.88.76 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 29 12:22:55 garage volumio[1224]: info: VolumeController:: Volume=22 Mute =false Dec 29 12:22:55 garage volumio[1224]: info: CoreStateMachine::pushState Dec 29 12:22:55 garage volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 29 12:22:55 garage volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 29 12:22:55 garage volumio[1224]: info: Discovery: adding 8c7e1a76-7eff-4a97-8a00-0e4b4cf16710 Dec 29 12:22:55 garage volumio[1224]: info: Discovery: Found device Garage Dec 29 12:22:55 garage volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 29 12:22:55 garage volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 29 12:22:55 garage sudo[1540]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 29 12:22:55 garage sudo[1540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:22:55 garage volumio[1224]: verbose: New Socket.io Connection to 192.168.88.184 from 192.168.88.76 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Dec 29 12:22:55 garage volumio[1224]: info: Listing playlists Dec 29 12:22:55 garage volumio[1224]: info: Listing playlists Dec 29 12:22:55 garage volumio[1224]: verbose: New Socket.io Connection to 192.168.88.184 from 192.168.88.76 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Dec 29 12:22:56 garage volumio[1224]: info: Discovery: this is already registered, 8c7e1a76-7eff-4a97-8a00-0e4b4cf16710 Dec 29 12:22:56 garage volumio[1224]: info: Discovery: Found device Garage Dec 29 12:22:56 garage volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 29 12:22:56 garage volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 29 12:22:56 garage volumio[1224]: verbose: New Socket.io Connection to 192.168.88.184 from 192.168.88.76 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Dec 29 12:22:56 garage volumio[1224]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 29 12:22:56 garage volumio[1224]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 29 12:22:56 garage volumio[1224]: info: Asound.conf file unchanged, so no further update is needed Dec 29 12:22:56 garage volumio[1224]: info: Output device has changed, restarting MPD Dec 29 12:22:56 garage sudo[1543]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 29 12:22:56 garage sudo[1543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:22:56 garage volumio[1224]: info: Output device has changed, restarting Shairport Sync Dec 29 12:22:56 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:22:56 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 29 12:22:56 garage sudo[1543]: pam_unix(sudo:session): session closed for user root Dec 29 12:22:56 garage sudo[1546]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 29 12:22:56 garage sudo[1546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:22:56 garage volumio[1224]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 29 12:22:56 garage volumio[1224]: info: ___________ START PLUGINS ___________ Dec 29 12:22:56 garage volumio[1224]: info: ControllerMpd::onStart: Initializing MPD Dec 29 12:22:56 garage volumio[1224]: info: Creating MPD Configuration file Dec 29 12:22:56 garage systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 29 12:22:56 garage systemd[1]: Starting mpd.service - Music Player Daemon... Dec 29 12:22:56 garage sudo[1554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 29 12:22:56 garage sudo[1554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:22:56 garage sudo[1554]: pam_unix(sudo:session): session closed for user root Dec 29 12:22:56 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 29 12:22:56 garage volumio[1224]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 29 12:22:56 garage volumio[1224]: info: [1767007376865] CoreMusicLibrary::Adding element Media Servers Dec 29 12:22:56 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 29 12:22:56 garage volumio[1224]: info: UPNP Browser: Client initialized successfully Dec 29 12:22:56 garage sudo[1557]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 29 12:22:56 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:22:56 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 29 12:22:57 garage sudo[1557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:22:57 garage volumio[1224]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 29 12:22:57 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:22:57 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 29 12:22:57 garage systemd[1]: mpd.service: Deactivated successfully. Dec 29 12:22:57 garage systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 29 12:22:57 garage systemd[1]: mpd.socket: Deactivated successfully. Dec 29 12:22:57 garage systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 29 12:22:57 garage systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 29 12:22:57 garage volumio[1224]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 29 12:22:57 garage volumio[1224]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 29 12:22:57 garage volumio[1224]: info: [1767007377209] CoreMusicLibrary::Adding element Last_100 Dec 29 12:22:57 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 29 12:22:57 garage volumio[1224]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 29 12:22:57 garage volumio[1224]: info: [1767007377212] CoreMusicLibrary::Adding element Webradio Dec 29 12:22:57 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 29 12:22:57 garage systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 29 12:22:57 garage systemd[1]: Starting mpd.service - Music Player Daemon... Dec 29 12:22:57 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 29 12:22:57 garage volumio[1224]: info: Initializing BBC Radios Dec 29 12:22:57 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 29 12:22:57 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 29 12:22:57 garage volumio[1224]: info: Creating Spotify config file Dec 29 12:22:57 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:22:57 garage sudo[1574]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 29 12:22:57 garage sudo[1574]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 29 12:22:58 garage sudo[1589]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 29 12:22:57 garage sudo[1574]: pam_unix(sudo:session): session closed for user root Dec 29 12:22:58 garage volumio[1224]: info: [now-playing] ConfigUpdater: config is up to date. Dec 29 12:22:58 garage volumio[1224]: info: Loading i18n strings for locale en Dec 29 12:22:58 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 29 12:22:58 garage sudo[1592]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Dec 29 12:22:58 garage sudo[1592]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:22:58 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 29 12:22:58 garage sudo[1592]: pam_unix(sudo:session): session closed for user root Dec 29 12:22:58 garage volumio[1224]: info: Loading i18n strings for locale en Dec 29 12:22:58 garage sudo[1595]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd_aloop index=7 pcm_substreams=2 Dec 29 12:22:58 garage sudo[1595]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:22:58 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 29 12:22:58 garage volumio[1224]: info: Volumio Calling Home Dec 29 12:22:59 garage sudo[1595]: pam_unix(sudo:session): session closed for user root Dec 29 12:22:59 garage sudo[1599]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge Dec 29 12:22:59 garage sudo[1599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:22:59 garage sudo[1599]: pam_unix(sudo:session): session closed for user root Dec 29 12:22:59 garage systemd[1286]: Reached target sound.target - Sound Card. Dec 29 12:22:59 garage systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 29 12:22:59 garage systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 29 12:22:59 garage systemd[1]: setdatetime-helper.service: Consumed 1.118s CPU time. Dec 29 12:22:59 garage volumio[1224]: info: Preparing to generate the ALSA configuration file Dec 29 12:22:59 garage sudo[1618]: 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 Dec 29 12:22:59 garage sudo[1618]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:22:59 garage sudo[1618]: pam_unix(sudo:session): session closed for user root Dec 29 12:22:59 garage sudo[1621]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Dec 29 12:22:59 garage sudo[1621]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:22:59 garage sudo[1626]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Dec 29 12:22:59 garage sudo[1626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:22:59 garage sudo[1623]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Dec 29 12:23:00 garage sudo[1623]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:00 garage systemd[1]: Reloading. Dec 29 12:23:01 garage volumio[1224]: info: [now-playing] App is listening on port 4004. Dec 29 12:23:01 garage volumio[1224]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Dec 29 12:23:01 garage volumio[1224]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 29 12:23:01 garage volumio[1224]: info: Reading ALSA contributions from plugins. Dec 29 12:23:01 garage volumio[1224]: info: touch_display: Backlight interface detected. Dec 29 12:23:01 garage volumio[1224]: info: ir_controller: File permissions successfully set on /etc/lirc/*. Dec 29 12:23:01 garage volumio[1224]: info: snd_dummy loaded Dec 29 12:23:01 garage sudo[1664]: 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/ Dec 29 12:23:01 garage sudo[1664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:01 garage volumio[1224]: info: MPD Permissions set Dec 29 12:23:01 garage volumio[1224]: info: MPD Permissions set Dec 29 12:23:01 garage sudo[1666]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay rotary-encoder pin_a=23 pin_b=24 relative_axis=true steps-per-period=1 Dec 29 12:23:01 garage sudo[1666]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:01 garage sudo[1664]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:01 garage sudo[1666]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:01 garage kernel: rotary-encoder rotary@17: gray Dec 29 12:23:01 garage kernel: input: rotary@17 as /devices/platform/rotary@17/input/input1 Dec 29 12:23:02 garage systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 4. Dec 29 12:23:02 garage sudo[1626]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:02 garage systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 29 12:23:02 garage sudo[1621]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:02 garage systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 29 12:23:02 garage sudo[1540]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:02 garage systemd[1]: Reloading. Dec 29 12:23:02 garage volumio-remote-updater[647]: [2025-12-29 12:23:02] [connect] Successful connection Dec 29 12:23:02 garage volumio[1224]: info: Volumio called home Dec 29 12:23:02 garage volumio[1224]: info: Spotify config file written Dec 29 12:23:02 garage sudo[1683]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 29 12:23:02 garage sudo[1683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:02 garage volumio[1224]: info: Upmpdcli Daemon Started Dec 29 12:23:02 garage volumio[1224]: info: touch_display: systemctl stop getty@tty1.service succeeded. Dec 29 12:23:02 garage volumio[1224]: info: touch_display: systemctl daemon-reload succeeded. Dec 29 12:23:02 garage volumio[1224]: info: touch_display: IframeKeyboardBridge extension installed successfully Dec 29 12:23:02 garage volumio[1224]: info: No need to fix Spotify hosts Dec 29 12:23:02 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:02 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:03 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:03 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:03 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:03 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:03 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:03 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:03 garage sudo[1703]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Dec 29 12:23:03 garage sudo[1703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:03 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 29 12:23:03 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:03 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:03 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:03 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:03 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:03 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:03 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:03 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:03 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:03 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 29 12:23:03 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:03 garage sudo[1732]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/rpi_backlight/brightness Dec 29 12:23:03 garage sudo[1732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:03 garage sudo[1732]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:03 garage volumio[1224]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 29 12:23:03 garage volumio[1224]: SPOTIFY: BQDFvKHmRaPGPGMSkVf1kyZtycNToqjdsEJy-eJJEqG-LYbpgQRWV3OmgRUSjwtrjY5TQ5F6RYQOVvUVQpvD4IU8U_EJxAliKX-XfYgCvduHsUuTmh2pw1rEdsmEInHZjJHlblS-mMUO3bruMWoRDU2btVp2gyTw7qVsJVXcV0iR8qDMVSQaXz7KftTjUqupS1cMFpFTieaqYSmCLJobLdJ5b3iXo1OBq3c45Lh3COiW0NFT1KddFWEYg1m30bM0r8R0vmQq0vzlsD7Y4PA1lh3Q0Gl6VRl5JlkLm44dpKtjYMmjYUWhotCvL_cL Dec 29 12:23:03 garage volumio[1224]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 29 12:23:03 garage volumio[1224]: info: New Spotify access token = BQDFvKHmRaPGPGMSkVf1kyZtycNToqjdsEJy-eJJEqG-LYbpgQRWV3OmgRUSjwtrjY5TQ5F6RYQOVvUVQpvD4IU8U_EJxAliKX-XfYgCvduHsUuTmh2pw1rEdsmEInHZjJHlblS-mMUO3bruMWoRDU2btVp2gyTw7qVsJVXcV0iR8qDMVSQaXz7KftTjUqupS1cMFpFTieaqYSmCLJobLdJ5b3iXo1OBq3c45Lh3COiW0NFT1KddFWEYg1m30bM0r8R0vmQq0vzlsD7Y4PA1lh3Q0Gl6VRl5JlkLm44dpKtjYMmjYUWhotCvL_cL Dec 29 12:23:03 garage volumio[1224]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 29 12:23:03 garage sudo[1623]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:03 garage volumio[1224]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Dec 29 12:23:03 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. Dec 29 12:23:03 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. Dec 29 12:23:04 garage systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 29 12:23:04 garage sudo[1683]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:04 garage go-librespot[1737]: go-librespot daemon starting... Dec 29 12:23:04 garage systemd[1]: Started volumio-kiosk.service - Volumio Kiosk. Dec 29 12:23:04 garage sudo[1703]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:04 garage sudo[1736]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay gpio-key gpio=27 active_low=true gpio_pull=up keycode=20 Dec 29 12:23:04 garage sudo[1736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:04 garage volumio[1224]: info: touch_display: Raspberry Pi Foundation touch screen detected. Dec 29 12:23:04 garage sudo[1736]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:04 garage sudo[1746]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Dec 29 12:23:04 garage sudo[1746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:04 garage sudo[1746]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:04 garage sudo[1742]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Dec 29 12:23:04 garage sudo[1742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:04 garage sudo[1742]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:04 garage kernel: input: button@1b as /devices/platform/button@1b/input/input2 Dec 29 12:23:04 garage volumio[1224]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Dec 29 12:23:04 garage volumio[1224]: info: touch_display: File permissions for backlight brightness control set. Dec 29 12:23:04 garage volumio[1224]: info: touch_display: systemctl disable getty@tty1.service succeeded. Dec 29 12:23:04 garage volumio[1224]: info: Starting Shairport Sync Dec 29 12:23:04 garage volumio[1224]: info: Starting Shairport Sync Dec 29 12:23:04 garage volumio[1224]: info: Starting Shairport Sync Dec 29 12:23:04 garage sudo[1781]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 29 12:23:04 garage sudo[1781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:04 garage sudo[1783]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 29 12:23:04 garage sudo[1783]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:04 garage sudo[1771]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 29 12:23:04 garage sudo[1771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:04 garage volumio[1224]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Dec 29 12:23:04 garage volumio[1224]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Dec 29 12:23:04 garage systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 29 12:23:04 garage volumio[1224]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Dec 29 12:23:04 garage systemd[1]: shairport-sync.service: Deactivated successfully. Dec 29 12:23:04 garage systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 29 12:23:04 garage systemd[1]: shairport-sync.service: Consumed 1.438s CPU time. Dec 29 12:23:04 garage volumio[1224]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Dec 29 12:23:04 garage volumio[1224]: info: touch_display: Volumio Kiosk started. Dec 29 12:23:04 garage systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 29 12:23:04 garage sudo[1781]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:04 garage volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 29 12:23:04 garage volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 29 12:23:04 garage sudo[1771]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:04 garage sudo[1783]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:05 garage volumio[1224]: info: Asound.conf file unchanged, so no further update is needed Dec 29 12:23:05 garage volumio[1224]: info: Output device has changed, restarting MPD Dec 29 12:23:05 garage volumio[1224]: info: Output device has changed, restarting Shairport Sync Dec 29 12:23:05 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:05 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 29 12:23:05 garage startx[1787]: X.Org X Server 1.21.1.7 Dec 29 12:23:05 garage startx[1787]: X Protocol Version 11, Revision 0 Dec 29 12:23:05 garage startx[1787]: Current Operating System: Linux garage 6.12.47-v7+ #1904 SMP Mon Sep 15 13:05:52 BST 2025 armv7l Dec 29 12:23:05 garage startx[1787]: 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 pcie_aspm=off pci=pcie_bus_safe rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Dec 29 12:23:05 garage startx[1787]: xorg-server 2:21.1.7-3+rpt3+deb12u11 (https://www.debian.org/support) Dec 29 12:23:05 garage startx[1787]: Current version of pixman: 0.44.0 Dec 29 12:23:05 garage startx[1787]: Before reporting problems, check http://wiki.x.org Dec 29 12:23:05 garage startx[1787]: to make sure that you have the latest version. Dec 29 12:23:05 garage startx[1787]: Markers: (--) probed, (**) from config file, (==) default setting, Dec 29 12:23:05 garage startx[1787]: (++) from command line, (!!) notice, (II) informational, Dec 29 12:23:05 garage startx[1787]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Dec 29 12:23:05 garage startx[1787]: (==) Log file: "/var/log/Xorg.0.log", Time: Mon Dec 29 12:23:05 2025 Dec 29 12:23:05 garage sudo[1795]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 29 12:23:05 garage sudo[1795]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:05 garage sudo[1795]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:05 garage sudo[1797]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 29 12:23:05 garage sudo[1797]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:05 garage startx[1787]: (==) Using config directory: "/etc/X11/xorg.conf.d" Dec 29 12:23:05 garage startx[1787]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Dec 29 12:23:05 garage go-librespot[1740]: time="2025-12-29T12:23:05+01:00" level=info msg="running go-librespot 0.4.0" Dec 29 12:23:05 garage go-librespot[1740]: time="2025-12-29T12:23:05+01:00" level=debug msg="app state loaded" Dec 29 12:23:05 garage go-librespot[1740]: time="2025-12-29T12:23:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 29 12:23:05 garage volumio[1224]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 29 12:23:05 garage systemd[1]: mpd.service: Deactivated successfully. Dec 29 12:23:05 garage systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 29 12:23:05 garage systemd[1]: mpd.service: Consumed 1.413s CPU time. Dec 29 12:23:05 garage systemd[1]: mpd.socket: Deactivated successfully. Dec 29 12:23:05 garage systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 29 12:23:05 garage systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 29 12:23:05 garage volumio[1224]: error: ir_controller: Error copying configurations: Error: ENOENT: no such file or directory, scandir '/data/plugins/system_hardware/ir_controller/configurations/TCL RC3000E02' Dec 29 12:23:05 garage volumio[1224]: info: ir_controller: HAT did not load /proc/device-tree/ir_receiver! Dec 29 12:23:05 garage systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 29 12:23:05 garage systemd[1]: Starting mpd.service - Music Player Daemon... Dec 29 12:23:05 garage volumio[1224]: verbose: New Socket.io Connection to 192.168.88.184 from 192.168.88.76 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Dec 29 12:23:05 garage volumio[1224]: info: Shairport-Sync Started Dec 29 12:23:05 garage volumio[1224]: Error adding Membership: Error: addMembership EINVAL Dec 29 12:23:05 garage volumio[1224]: info: Shairport-Sync Started Dec 29 12:23:05 garage volumio[1224]: info: Shairport-Sync Started Dec 29 12:23:05 garage volumio[1224]: error: Upnp client error: Error: read ECONNRESET Dec 29 12:23:05 garage volumio-remote-updater[647]: [2025-12-29 12:23:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1767007382 101 Dec 29 12:23:05 garage sudo[1827]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Dec 29 12:23:05 garage sudo[1827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:06 garage sudo[1827]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:06 garage volumio[1224]: 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: 13 Dec 29 12:23:06 garage volumio[1224]: info: ir_controller: Raspberry Pi revision code: a020d3 Dec 29 12:23:06 garage volumio[1224]: info: MPD Permissions set Dec 29 12:23:06 garage volumio[1224]: info: touch_display: X display number found: 0 Dec 29 12:23:06 garage volumio[1224]: verbose: New Socket.io Connection to 192.168.88.184 from 192.168.88.76 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 14 Dec 29 12:23:06 garage volumio[1224]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Dec 29 12:23:06 garage sudo[1822]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 29 12:23:06 garage sudo[1822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 29 12:23:06 garage sudo[1834]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 29 12:23:06 garage sudo[1822]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:06 garage sudo[1837]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r -1 Dec 29 12:23:06 garage sudo[1837]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:06 garage sudo[1837]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:06 garage sudo[1840]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Dec 29 12:23:06 garage sudo[1840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:06 garage sudo[1840]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:06 garage volumio[1224]: info: touch_display: X display number found: 0 Dec 29 12:23:06 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:06 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:06 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:06 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:06 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:06 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:06 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:06 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:06 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 29 12:23:06 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 12:23:06 garage volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 29 12:23:06 garage volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 29 12:23:06 garage volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 29 12:23:06 garage volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 29 12:23:07 garage go-librespot[1740]: time="2025-12-29T12:23:07+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]" Dec 29 12:23:07 garage go-librespot[1740]: time="2025-12-29T12:23:07+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]" Dec 29 12:23:07 garage go-librespot[1740]: time="2025-12-29T12:23:07+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]" Dec 29 12:23:07 garage go-librespot[1740]: time="2025-12-29T12:23:07+01:00" level=info msg="zeroconf server listening on port 44077" Dec 29 12:23:07 garage volumio[1224]: 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"} Dec 29 12:23:07 garage volumio[1224]: info: Spotify Successfully logged in Dec 29 12:23:07 garage volumio[1224]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 29 12:23:07 garage volumio[1224]: info: [1767007387180] CoreMusicLibrary::Adding element Spotify Dec 29 12:23:07 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 29 12:23:07 garage volumio[1224]: Cannot find translation for source Spotify Dec 29 12:23:07 garage go-librespot[1740]: time="2025-12-29T12:23:07+01:00" level=debug msg="obtained new client token: AABMdWZi1bwXzqVJ8xbkOUYzg2qCKMknGVfXbp59fjS8o1ijgt0BDVH+HrxmJAfoSX3fpqCx5TV8+yJeF2JWcS3bUx2BhCXg4MvikNLudT/4IYeJCvbWoM7ChyTYj54YzLdMbSXssEl+zVqR/t8Aa3DAxtB5d6NwPxWZ9x6Dv3HJRtXDPkW+V8cug3lFWRgGtu5eWcWgTkwPhgFuuLg6BVxrib2R4z/jZz574hjJw5Rn+QvGrb6PiTHC" Dec 29 12:23:07 garage go-librespot[1740]: time="2025-12-29T12:23:07+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 29 12:23:07 garage volumio[1224]: info: Starting Shairport Sync Dec 29 12:23:07 garage go-librespot[1740]: time="2025-12-29T12:23:07+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:36246->104.199.65.9:4070: read: connection reset by peer" Dec 29 12:23:07 garage sudo[1854]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay gpio-ir gpio_pin=25 gpio_pull=up Dec 29 12:23:07 garage sudo[1854]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:07 garage systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 29 12:23:07 garage systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 29 12:23:07 garage sudo[1854]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:07 garage sudo[1856]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 29 12:23:07 garage kernel: Registered IR keymap rc-rc6-mce Dec 29 12:23:07 garage sudo[1856]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:07 garage kernel: IR RC6 protocol handler initialized Dec 29 12:23:07 garage kernel: rc rc0: gpio_ir_recv as /devices/platform/ir-receiver@19/rc/rc0 Dec 29 12:23:07 garage kernel: rc rc0: lirc_dev: driver gpio_ir_recv registered at minor = 0, raw IR receiver, no transmitter Dec 29 12:23:07 garage kernel: input: gpio_ir_recv as /devices/platform/ir-receiver@19/rc/rc0/input3 Dec 29 12:23:07 garage volumio[1224]: info: ir_controller: Overlay gpio-ir gpio_pin=25 gpio_pull=up loaded. Dec 29 12:23:07 garage volumio[1224]: info: go-librespot daemon successfully initialized Dec 29 12:23:07 garage volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 29 12:23:07 garage volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 29 12:23:08 garage sudo[1870]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart lircd.service Dec 29 12:23:08 garage sudo[1870]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:08 garage systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 29 12:23:08 garage systemd[1]: shairport-sync.service: Deactivated successfully. Dec 29 12:23:08 garage systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 29 12:23:08 garage systemd-logind[643]: Watching system buttons on /dev/input/event3 (gpio_ir_recv) Dec 29 12:23:08 garage systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 29 12:23:08 garage sudo[1856]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:08 garage systemd[1]: Starting lircd-setup.service - lircd(8) initialization helper tool... Dec 29 12:23:08 garage volumio[1224]: info: Shairport-Sync Started Dec 29 12:23:08 garage volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 29 12:23:08 garage volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 29 12:23:08 garage volumio[1224]: verbose: New Socket.io Connection to 192.168.88.184 from 192.168.88.76 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 15 Dec 29 12:23:09 garage volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 29 12:23:09 garage volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 29 12:23:09 garage volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 29 12:23:09 garage volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 29 12:23:09 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 29 12:23:09 garage volumio[1224]: info: Listing playlists Dec 29 12:23:09 garage volumio[1224]: info: CoreCommandRouter::volumioGetQueue Dec 29 12:23:09 garage volumio[1224]: info: CoreStateMachine::getQueue Dec 29 12:23:09 garage volumio[1224]: info: CorePlayQueue::getQueue Dec 29 12:23:09 garage volumio[1224]: info: CoreCommandRouter::volumioGetVisibleSources Dec 29 12:23:09 garage volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 29 12:23:09 garage lircd-setup[1874]: /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. Dec 29 12:23:09 garage lircd-setup[1874]: parser = configparser.SafeConfigParser() Dec 29 12:23:09 garage systemd[1]: lircd-setup.service: Deactivated successfully. Dec 29 12:23:09 garage systemd[1]: Finished lircd-setup.service - lircd(8) initialization helper tool. Dec 29 12:23:09 garage systemd[1]: Starting lircd.service - Flexible IR remote input/output application support... Dec 29 12:23:09 garage lircd-0.10.1[1897]: Info: lircd: Opening log, level: Info Dec 29 12:23:09 garage lircd-0.10.1[1897]: Notice: Version: lircd 0.10.1 Dec 29 12:23:09 garage lircd-0.10.1[1897]: Notice: System info: Linux garage 6.12.47-v7+ #1904 SMP Mon Sep 15 13:05:52 BST 2025 armv7l GNU/Linux Dec 29 12:23:10 garage lircd-0.10.1[1897]: Info: Initial device: /dev/lirc0 Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: 'lirc' written to protocols file /sys/class/rc/rc0/protocols Dec 29 12:23:10 garage lircd-0.10.1[1897]: Info: Initial device: /dev/lirc0 Dec 29 12:23:10 garage lircd[1897]: lircd-0.10.1[1897]: Info: lircd: Opening log, level: Info Dec 29 12:23:10 garage lircd-0.10.1[1897]: Info: [lirc] protocol is enabled Dec 29 12:23:10 garage lircd[1897]: lircd-0.10.1[1897]: Notice: Using systemd fd Dec 29 12:23:10 garage lircd[1897]: lircd-0.10.1[1897]: Warning: Running as root Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Options: driver: default Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Options: output: /var/run/lirc/lircd Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Options: nodaemon: 1 Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Options: plugindir: /usr/lib/arm-linux-gnueabihf/lirc/plugins Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Options: logfile: syslog Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Options: immediate-init: 0 Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Options: permission: 666 Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Options: driver-options: Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Options: pidfile: /var/run/lirc/lircd.pid Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Options: listen: 0 Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Options: connect: (null) Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Options: userelease: 0 Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Options: effective_user: (null) Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Options: release_suffix: _EVUP Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Options: allow_simulate: 0 Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Options: repeat_max: 600 Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Options: configfile: /etc/lirc/lircd.conf Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Options: dynamic_codes: (null) Dec 29 12:23:10 garage lircd[1897]: lircd-0.10.1[1897]: Info: Using remote: lircd.conf. Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Current driver: default Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Driver API version: 3 Dec 29 12:23:10 garage lircd[1897]: lircd-0.10.1[1897]: Notice: lircd(default) ready, using /var/run/lirc/lircd Dec 29 12:23:10 garage systemd[1]: Started lircd.service - Flexible IR remote input/output application support. Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Driver version: 0.10.0 Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Driver info: See file:///usr/share/doc/lirc/plugindocs/default.html Dec 29 12:23:10 garage lircd-0.10.1[1897]: Info: lircd: Opening log, level: Info Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: Using systemd fd Dec 29 12:23:10 garage lircd-0.10.1[1897]: Warning: Running as root Dec 29 12:23:10 garage lircd-0.10.1[1897]: Info: Using remote: lircd.conf. Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: lircd(default) ready, using /var/run/lirc/lircd Dec 29 12:23:10 garage sudo[1870]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:10 garage volumio[1224]: info: ir_controller: systemctl restart lircd.service succeeded. Dec 29 12:23:10 garage sudo[1911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart irexec.service Dec 29 12:23:10 garage sudo[1911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 12:23:10 garage systemd[1]: Started irexec.service - Handle events from IR remotes decoded by lircd(8). Dec 29 12:23:10 garage sudo[1911]: pam_unix(sudo:session): session closed for user root Dec 29 12:23:10 garage volumio[1224]: info: ir_controller: systemctl restart irexec.service succeeded. Dec 29 12:23:10 garage lircd[1897]: lircd-0.10.1[1897]: Notice: accepted new client on /var/run/lirc/lircd Dec 29 12:23:10 garage lircd[1897]: lircd-0.10.1[1897]: Info: [lirc] protocol is enabled Dec 29 12:23:10 garage lircd-0.10.1[1897]: Notice: accepted new client on /var/run/lirc/lircd Dec 29 12:23:10 garage lircd-0.10.1[1897]: Info: [lirc] protocol is enabled Dec 29 12:23:10 garage systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 29 12:23:10 garage systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 29 12:23:10 garage systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 29 12:23:10 garage go-librespot[1918]: go-librespot daemon starting... Dec 29 12:23:10 garage go-librespot[1919]: time="2025-12-29T12:23:10+01:00" level=info msg="running go-librespot 0.4.0" Dec 29 12:23:10 garage go-librespot[1919]: time="2025-12-29T12:23:10+01:00" level=debug msg="app state loaded" Dec 29 12:23:10 garage go-librespot[1919]: time="2025-12-29T12:23:10+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 29 12:23:10 garage volumio[1224]: info: Initializing connection to go-librespot Websocket Dec 29 12:23:11 garage go-librespot[1919]: time="2025-12-29T12:23:11+01:00" level=debug msg="new websocket client" Dec 29 12:23:11 garage volumio[1224]: info: Connection to go-librespot Websocket established Dec 29 12:23:11 garage go-librespot[1919]: time="2025-12-29T12:23:11+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]" Dec 29 12:23:11 garage go-librespot[1919]: time="2025-12-29T12:23:11+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]" Dec 29 12:23:11 garage go-librespot[1919]: time="2025-12-29T12:23:11+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]" Dec 29 12:23:11 garage go-librespot[1919]: time="2025-12-29T12:23:11+01:00" level=info msg="zeroconf server listening on port 34467" Dec 29 12:23:12 garage go-librespot[1919]: time="2025-12-29T12:23:12+01:00" level=debug msg="obtained new client token: AAD7PRDpURRpvAwkQKgppFAkeC/bIloea8vC8r221kPO1zOrxzdWwJxdUXQvwXcwqM14l/RDU2DW9tz1yuYgTAwBhPB5gwSWpWlQ5jakVaAIBn54jiJF40QjWSFcBFUjFFTDVNWqipXEVhLxPOz7G3s8lEus0jzQgqnVblA3MVKqADZSHcFOPJul4yaZKHTZJnbdBexT+HqFCWseg/bZ81pwT94pC+qnNdlg8Lv/arwwGq15ojkASsIJ" Dec 29 12:23:12 garage go-librespot[1919]: time="2025-12-29T12:23:12+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 29 12:23:12 garage go-librespot[1919]: time="2025-12-29T12:23:12+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: EOF" Dec 29 12:23:12 garage systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 29 12:23:12 garage systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 29 12:23:12 garage volumio[1224]: info: Connection to go-librespot Websocket closed Dec 29 12:23:13 garage volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 29 12:23:13 garage volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 29 12:23:13 garage volumio[1224]: info: Listing playlists Dec 29 12:23:13 garage volumio[1224]: info: Listing playlists Dec 29 12:23:13 garage volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 29 12:23:13 garage volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 29 12:23:14 garage volumio[1224]: info: touch_display: Setting screensaver timeout to 100 seconds. Dec 29 12:23:14 garage volumio[1224]: info: Getting Spotify volume Dec 29 12:23:14 garage volumio[1224]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 29 12:23:14 garage volumio[1224]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 29 12:23:14 garage volumio[1224]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 29 12:23:14 garage volumio[1224]: errno: -111, Dec 29 12:23:14 garage volumio[1224]: code: 'ECONNREFUSED', Dec 29 12:23:14 garage volumio[1224]: syscall: 'connect', Dec 29 12:23:14 garage volumio[1224]: address: '127.0.0.1', Dec 29 12:23:14 garage volumio[1224]: port: 9879, Dec 29 12:23:14 garage volumio[1224]: response: undefined Dec 29 12:23:14 garage volumio[1224]: } Dec 29 12:23:14 garage volumio[1224]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 29 12:23:15 garage systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 29 12:23:15 garage systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 29 12:23:15 garage systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 29 12:23:15 garage go-librespot[1986]: go-librespot daemon starting... Dec 29 12:23:15 garage go-librespot[1989]: time="2025-12-29T12:23:15+01:00" level=info msg="running go-librespot 0.4.0" Dec 29 12:23:15 garage go-librespot[1989]: time="2025-12-29T12:23:15+01:00" level=debug msg="app state loaded" Dec 29 12:23:15 garage go-librespot[1989]: time="2025-12-29T12:23:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 29 12:23:16 garage go-librespot[1989]: time="2025-12-29T12:23:16+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]" Dec 29 12:23:16 garage go-librespot[1989]: time="2025-12-29T12:23:16+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]" Dec 29 12:23:16 garage go-librespot[1989]: time="2025-12-29T12:23:16+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]" Dec 29 12:23:16 garage go-librespot[1989]: time="2025-12-29T12:23:16+01:00" level=info msg="zeroconf server listening on port 43093" Dec 29 12:23:17 garage go-librespot[1989]: time="2025-12-29T12:23:17+01:00" level=debug msg="obtained new client token: AADD3SmrlyeZGs3N4wuZqC7ewX6hmsJ5tIau7FOsEQN8NeReMTX5XonfO+2ZLyVLfsbaysCs3/KqbF1nmyYAXu4INlMWCUMNTASZFIpBY3gr3hlt27oJIMFEmc8cjeSN7qaeaZnVoxpGWUJeaMeTxij8kR/zoXbI8NNf4MJc0fNesp0Qu4yakDdzcRd0TFXrqj9C93pJyjzydEdJSr7F2+rnhxo2qEq9rS7mm5YZlRWoGlycnMrprQ==" Dec 29 12:23:17 garage go-librespot[1989]: time="2025-12-29T12:23:17+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 29 12:23:17 garage go-librespot[1989]: time="2025-12-29T12:23:17+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: EOF" Dec 29 12:23:17 garage systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 29 12:23:17 garage systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 29 12:23:19 garage sudo[2038]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-29 12:22' Dec 29 12:23:19 garage sudo[2038]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"