Jan 25 16:53:00 garage kernel: vc4-drm soc:gpu: [drm] *ERROR* flip_done timed out Jan 25 16:53:00 garage kernel: vc4-drm soc:gpu: [drm] *ERROR* [CONNECTOR:154:DSI-1] commit wait timed out Jan 25 16:53:01 garage wpa_supplicant[1146]: RRM: Ignoring radio measurement request: Not RRM network Jan 25 16:53:04 garage volumio[1185]: info: CoreCommandRouter::volumioGetState Jan 25 16:53:04 garage volumio[1185]: info: CorePlayQueue::getTrack 0 Jan 25 16:53:04 garage volumio[1185]: info: Listing playlists Jan 25 16:53:04 garage volumio[1185]: info: Listing playlists Jan 25 16:53:07 garage wpa_supplicant[1146]: RRM: Ignoring radio measurement request: Not RRM network Jan 25 16:53:11 garage kernel: vc4-drm soc:gpu: [drm] *ERROR* flip_done timed out Jan 25 16:53:11 garage kernel: vc4-drm soc:gpu: [drm] *ERROR* [PLANE:96:plane-4] commit wait timed out Jan 25 16:53:13 garage wpa_supplicant[1146]: RRM: Ignoring radio measurement request: Not RRM network Jan 25 16:53:14 garage volumio[1185]: info: CoreCommandRouter::volumioGetState Jan 25 16:53:14 garage volumio[1185]: info: CorePlayQueue::getTrack 0 Jan 25 16:53:14 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 16:53:14 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 16:53:14 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 25 16:53:15 garage volumio[1185]: error: Plugin system_controller volumio5onboarding failed to complete 'onStart' in a timely fashion Jan 25 16:53:15 garage volumio[1185]: error: Plugin music_service mpd failed to complete 'onStart' in a timely fashion Jan 25 16:53:15 garage volumio[1185]: error: Plugin user_interface touch_display failed to complete 'onStart' in a timely fashion Jan 25 16:53:15 garage volumio[1185]: info: ------------------------------------------- Jan 25 16:53:15 garage volumio[1185]: info: ----- MyVolumio plugins startup ---- Jan 25 16:53:15 garage volumio[1185]: info: ------------------------------------------- Jan 25 16:53:15 garage volumio[1185]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 25 16:53:21 garage kernel: vc4-drm soc:gpu: [drm] *ERROR* [CRTC:152:crtc-4] flip_done timed out Jan 25 16:53:21 garage wpa_supplicant[1146]: RRM: Ignoring radio measurement request: Not RRM network Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 25 16:53:24 garage volumio[1185]: info: Adding plugin bluetooth to MyMusic Plugins Jan 25 16:53:24 garage volumio[1185]: info: Adding plugin multiroom to MyMusic Plugins Jan 25 16:53:24 garage volumio[1185]: info: Adding plugin metavolumio to MyMusic Plugins Jan 25 16:53:24 garage volumio[1185]: info: Adding plugin cd_controller to MyMusic Plugins Jan 25 16:53:24 garage volumio[1185]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 25 16:53:24 garage volumio[1185]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 25 16:53:24 garage volumio[1185]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 25 16:53:24 garage volumio[1185]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 25 16:53:27 garage wpa_supplicant[1146]: RRM: Ignoring radio measurement request: Not RRM network Jan 25 16:53:31 garage volumio[1185]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 25 16:53:31 garage volumio[1185]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 25 16:53:31 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 16:53:31 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 16:53:31 garage volumio[1185]: info: Starting MyVolumio Remote Streaming Endpoints Jan 25 16:53:31 garage kernel: vc4-drm soc:gpu: [drm] *ERROR* flip_done timed out Jan 25 16:53:31 garage kernel: vc4-drm soc:gpu: [drm] *ERROR* [CRTC:152:crtc-4] commit wait timed out Jan 25 16:53:31 garage volumio[1185]: info: MyVolumio login type: Token Jan 25 16:53:32 garage volumio[1185]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 25 16:53:32 garage volumio[1185]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 25 16:53:33 garage wpa_supplicant[1146]: RRM: Ignoring radio measurement request: Not RRM network Jan 25 16:53:36 garage volumio[1185]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 25 16:53:36 garage volumio[1185]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 25 16:53:36 garage volumio[1185]: info: Streaming services startup Jan 25 16:53:36 garage volumio[1185]: info: Starting Streaming Daemon Jan 25 16:53:36 garage volumio[1185]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 25 16:53:36 garage sudo[1810]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 25 16:53:36 garage sudo[1810]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 16:53:36 garage volumio[1185]: info: CoreCommandRouter::volumioGetState Jan 25 16:53:36 garage volumio[1185]: info: CorePlayQueue::getTrack 0 Jan 25 16:53:37 garage volumio[1185]: info: Listing playlists Jan 25 16:53:37 garage volumio[1185]: info: Listing playlists Jan 25 16:53:38 garage volumio[1185]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 25 16:53:39 garage wpa_supplicant[1146]: RRM: Ignoring radio measurement request: Not RRM network Jan 25 16:53:39 garage volumio[1185]: info: MyVolumio token set successfully Jan 25 16:53:39 garage volumio[1185]: info: MYVOLUMIO: Adding device Jan 25 16:53:39 garage volumio[1185]: info: MYVOLUMIO: Evaluating Server Jan 25 16:53:40 garage volumio[1185]: info: MyVolumio status changed Jan 25 16:53:40 garage volumio[1185]: info: Streaming services startup Jan 25 16:53:40 garage volumio[1185]: info: Starting Streaming Daemon Jan 25 16:53:41 garage volumio[1185]: info: Removing browser output: myVolumio user plan is not superstar Jan 25 16:53:41 garage volumio[1185]: info: Removing audio output: Jan 25 16:53:41 garage volumio[1185]: info: Stoppping Tunnel 1 Jan 25 16:53:41 garage sudo[1843]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 25 16:53:41 garage sudo[1843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 16:53:41 garage sudo[1854]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 25 16:53:41 garage sudo[1854]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 16:53:41 garage volumio[1185]: info: Setting Geolocation for MyVolumio to eu4 Jan 25 16:53:41 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 16:53:41 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 16:53:41 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 16:53:41 garage kernel: vc4-drm soc:gpu: [drm] *ERROR* flip_done timed out Jan 25 16:53:41 garage kernel: vc4-drm soc:gpu: [drm] *ERROR* [CONNECTOR:154:DSI-1] commit wait timed out Jan 25 16:53:42 garage volumio[1185]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 25 16:53:42 garage volumio[1185]: info: Updating MyVolumio device info Jan 25 16:53:42 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 16:53:42 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 16:53:42 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 16:53:43 garage volumio[1185]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 25 16:53:43 garage volumio[1185]: info: VolumeController::SetAlsaVolume+ Jan 25 16:53:43 garage volumio[1185]: info: CoreStateMachine::pushState Jan 25 16:53:43 garage volumio[1185]: info: CorePlayQueue::getTrack 0 Jan 25 16:53:43 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 16:53:43 garage volumio[1185]: info: CoreCommandRouter::volumioPushState Jan 25 16:53:43 garage volumio[1185]: info: VolumeController::SetAlsaVolume+ Jan 25 16:53:43 garage volumio[1185]: info: CoreStateMachine::pushState Jan 25 16:53:43 garage volumio[1185]: info: CorePlayQueue::getTrack 0 Jan 25 16:53:43 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 16:53:43 garage volumio[1185]: info: CoreCommandRouter::volumioPushState Jan 25 16:53:44 garage volumio[1185]: info: CoreCommandRouter::volumioGetState Jan 25 16:53:44 garage volumio[1185]: info: CorePlayQueue::getTrack 0 Jan 25 16:53:45 garage wpa_supplicant[1146]: RRM: Ignoring radio measurement request: Not RRM network Jan 25 16:53:46 garage volumio[1185]: info: MYVOLUMIO: Adding device Jan 25 16:53:46 garage volumio[1185]: info: MYVOLUMIO: Evaluating Server Jan 25 16:53:46 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 25 16:53:46 garage volumio[1185]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jan 25 16:53:47 garage volumio[1185]: info: Setting Geolocation for MyVolumio to eu7 Jan 25 16:53:47 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 16:53:47 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 16:53:47 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 16:53:47 garage volumio[1185]: info: CoreCommandRouter::volumioGetState Jan 25 16:53:47 garage volumio[1185]: info: CorePlayQueue::getTrack 0 Jan 25 16:53:48 garage volumio[1185]: info: Updating MyVolumio device info Jan 25 16:53:48 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 16:53:48 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 16:53:48 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 16:53:49 garage volumio[1185]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 25 16:53:49 garage volumio[1185]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 25 16:53:51 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 16:53:51 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 16:53:51 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jan 25 16:53:51 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jan 25 16:53:51 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 25 16:53:51 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jan 25 16:53:51 garage volumio[1185]: info: CoreCommandRouter::volumioGetBrowseSources Jan 25 16:53:51 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 16:53:51 garage wpa_supplicant[1146]: RRM: Ignoring radio measurement request: Not RRM network Jan 25 16:53:52 garage kernel: vc4-drm soc:gpu: [drm] *ERROR* flip_done timed out Jan 25 16:53:52 garage kernel: vc4-drm soc:gpu: [drm] *ERROR* [PLANE:96:plane-4] commit wait timed out Jan 25 16:53:54 garage volumio[1185]: info: CoreCommandRouter::volumioGetState Jan 25 16:53:54 garage volumio[1185]: info: CorePlayQueue::getTrack 0 Jan 25 16:53:54 garage volumio[1185]: info: Listing playlists Jan 25 16:53:54 garage volumio[1185]: info: Listing playlists Jan 25 16:53:56 garage volumio[1185]: error: MyVolumio Plugin failed to authenticate in a timely fashion Jan 25 16:53:56 garage volumio[1185]: info: Completed starting MyVolumio Plugin Jan 25 16:53:56 garage volumio[1185]: [Metrics] CommandRouter: 110s 355.38ms Jan 25 16:53:56 garage volumio[1185]: info: CoreCommandRouter::volumiosetStartupVolume Jan 25 16:53:56 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 16:53:56 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 16:53:56 garage volumio[1185]: info: CoreCommandRouter::Close All Modals sent Jan 25 16:53:56 garage volumio[1185]: info: CoreCommandRouter::Close All Modals sent Jan 25 16:53:57 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jan 25 16:53:57 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 25 16:53:57 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jan 25 16:53:57 garage wpa_supplicant[1146]: RRM: Ignoring radio measurement request: Not RRM network Jan 25 16:54:02 garage systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. Jan 25 16:54:02 garage kernel: vc4-drm soc:gpu: [drm] *ERROR* [CRTC:152:crtc-4] flip_done timed out Jan 25 16:54:02 garage systemd[1]: Received SIGRTMIN+21 from PID 290 (plymouthd). Jan 25 16:54:02 garage systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Jan 25 16:54:02 garage systemd[1]: Reloading. Jan 25 16:54:03 garage volumio[1185]: info: BOOT COMPLETED Jan 25 16:54:03 garage wpa_supplicant[1146]: RRM: Ignoring radio measurement request: Not RRM network Jan 25 16:54:04 garage volumio[1185]: info: CoreCommandRouter::volumioGetState Jan 25 16:54:04 garage volumio[1185]: info: CorePlayQueue::getTrack 0 Jan 25 16:54:04 garage systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 4. Jan 25 16:54:04 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 25 16:54:04 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 25 16:54:04 garage sudo[1586]: pam_unix(sudo:session): session closed for user root Jan 25 16:54:04 garage systemd[1]: Reloading. Jan 25 16:54:04 garage volumio[1185]: info: touch_display: systemctl daemon-reload succeeded. Jan 25 16:54:04 garage sudo[1961]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Jan 25 16:54:04 garage sudo[1961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 16:54:06 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 25 16:54:06 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 25 16:54:06 garage sudo[1584]: pam_unix(sudo:session): session closed for user root Jan 25 16:54:06 garage volumio[1185]: info: touch_display: systemctl disable getty@tty1.service succeeded. Jan 25 16:54:06 garage systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5. Jan 25 16:54:06 garage sudo[1810]: pam_unix(sudo:session): session closed for user root Jan 25 16:54:06 garage sudo[1843]: pam_unix(sudo:session): session closed for user root Jan 25 16:54:06 garage volumio[1185]: error: Cannot start Volumio Streaming Daemon Jan 25 16:54:06 garage volumio[1185]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 25 16:54:06 garage volumio[1185]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 25 16:54:06 garage volumio[1185]: error: Cannot start Volumio Streaming Daemon Jan 25 16:54:06 garage volumio[1185]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 25 16:54:06 garage volumio[1185]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 25 16:54:06 garage systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 16:54:06 garage systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 16:54:06 garage go-librespot[1986]: go-librespot daemon starting... Jan 25 16:54:06 garage systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 16:54:06 garage sudo[1610]: pam_unix(sudo:session): session closed for user root Jan 25 16:54:06 garage systemd[1]: Starting lircd-setup.service - lircd(8) initialization helper tool... Jan 25 16:54:06 garage systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 16:54:06 garage systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 16:54:06 garage systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 25 16:54:06 garage systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 25 16:54:06 garage systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 25 16:54:06 garage sudo[1523]: pam_unix(sudo:session): session closed for user root Jan 25 16:54:06 garage systemd[1]: Started volumio-kiosk.service - Volumio Kiosk. Jan 25 16:54:06 garage volumio[1185]: info: Upmpdcli Daemon Started Jan 25 16:54:06 garage sudo[1961]: pam_unix(sudo:session): session closed for user root Jan 25 16:54:06 garage volumio[1185]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Jan 25 16:54:06 garage volumio[1185]: info: touch_display: Volumio Kiosk started. Jan 25 16:54:06 garage systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Jan 25 16:54:06 garage sudo[1536]: pam_unix(sudo:session): session closed for user root Jan 25 16:54:06 garage volumio[1185]: info: CoreCommandRouter::volumioGetState Jan 25 16:54:06 garage volumio[1185]: info: CorePlayQueue::getTrack 0 Jan 25 16:54:06 garage volumio[1185]: info: CoreCommandRouter::volumioGetState Jan 25 16:54:06 garage volumio[1185]: info: CorePlayQueue::getTrack 0 Jan 25 16:54:06 garage systemd[1]: shairport-sync.service: Deactivated successfully. Jan 25 16:54:06 garage systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 16:54:06 garage systemd[1]: shairport-sync.service: Consumed 1.970s CPU time. Jan 25 16:54:07 garage sudo[1990]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 25 16:54:07 garage sudo[1990]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 25 16:54:07 garage sudo[2024]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jan 25 16:54:07 garage sudo[1990]: pam_unix(sudo:session): session closed for user root Jan 25 16:54:07 garage lircd-setup[1988]: /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 25 16:54:07 garage lircd-setup[1988]: parser = configparser.SafeConfigParser() Jan 25 16:54:07 garage systemd[1]: lircd-setup.service: Deactivated successfully. Jan 25 16:54:07 garage systemd[1]: Finished lircd-setup.service - lircd(8) initialization helper tool. Jan 25 16:54:07 garage systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 16:54:07 garage systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 16:54:07 garage sudo[1583]: pam_unix(sudo:session): session closed for user root Jan 25 16:54:07 garage volumio[1185]: info: touch_display: systemctl stop getty@tty1.service succeeded. Jan 25 16:54:07 garage systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 16:54:07 garage systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 16:54:07 garage sudo[1854]: pam_unix(sudo:session): session closed for user root Jan 25 16:54:07 garage volumio[1185]: info: Remote SSH Stopped Jan 25 16:54:07 garage volumio[1185]: info: touch_display: X display number found: 0 Jan 25 16:54:07 garage volumio[1185]: info: touch_display: X display number found: 0 Jan 25 16:54:07 garage volumio[1185]: info: touch_display: X display number found: 0 Jan 25 16:54:07 garage volumio[1185]: info: touch_display: X display number found: 0 Jan 25 16:54:07 garage volumio[1185]: info: touch_display: X display number found: 0 Jan 25 16:54:07 garage systemd[1]: Starting lircd.service - Flexible IR remote input/output application support... Jan 25 16:54:07 garage systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 16:54:07 garage sudo[1663]: pam_unix(sudo:session): session closed for user root Jan 25 16:54:07 garage systemd[1]: Reached target multi-user.target - Multi-User System. Jan 25 16:54:07 garage systemd[1]: Reached target graphical.target - Graphical Interface. Jan 25 16:54:07 garage sudo[1665]: pam_unix(sudo:session): session closed for user root Jan 25 16:54:07 garage sudo[1668]: pam_unix(sudo:session): session closed for user root Jan 25 16:54:07 garage systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Jan 25 16:54:07 garage lircd-0.10.1[2051]: Info: lircd: Opening log, level: Info Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Version: lircd 0.10.1 Jan 25 16:54:07 garage volumio[1185]: info: Shairport-Sync Started Jan 25 16:54:07 garage volumio[1185]: Error adding Membership: Error: addMembership EINVAL Jan 25 16:54:07 garage go-librespot[1987]: time="2026-01-25T16:54:07+01:00" level=info msg="running go-librespot 0.4.0" Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: System info: Linux garage 6.12.47-v7+ #1904 SMP Mon Sep 15 13:05:52 BST 2025 armv7l GNU/Linux Jan 25 16:54:07 garage volumio[1185]: info: Shairport-Sync Started Jan 25 16:54:07 garage go-librespot[1987]: time="2026-01-25T16:54:07+01:00" level=debug msg="app state loaded" Jan 25 16:54:07 garage volumio[1185]: info: Shairport-Sync Started Jan 25 16:54:07 garage go-librespot[1987]: time="2026-01-25T16:54:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 16:54:07 garage volumio[1185]: info: touch_display: X display number found: 0 Jan 25 16:54:07 garage systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Jan 25 16:54:07 garage systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Jan 25 16:54:07 garage volumio[1185]: info: touch_display: X display number found: 0 Jan 25 16:54:07 garage volumio[1185]: info: touch_display: X display number found: 0 Jan 25 16:54:07 garage startx[2045]: X.Org X Server 1.21.1.7 Jan 25 16:54:07 garage startx[2045]: X Protocol Version 11, Revision 0 Jan 25 16:54:07 garage startx[2045]: Current Operating System: Linux garage 6.12.47-v7+ #1904 SMP Mon Sep 15 13:05:52 BST 2025 armv7l Jan 25 16:54:07 garage startx[2045]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 cgroup_disable=memory snd_bcm2835.enable_hdmi=0 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 25 16:54:07 garage startx[2045]: xorg-server 2:21.1.7-3+rpt3+deb12u11 (https://www.debian.org/support) Jan 25 16:54:07 garage startx[2045]: Current version of pixman: 0.44.0 Jan 25 16:54:07 garage startx[2045]: Before reporting problems, check http://wiki.x.org Jan 25 16:54:07 garage startx[2045]: to make sure that you have the latest version. Jan 25 16:54:07 garage startx[2045]: Markers: (--) probed, (**) from config file, (==) default setting, Jan 25 16:54:07 garage startx[2045]: (++) from command line, (!!) notice, (II) informational, Jan 25 16:54:07 garage startx[2045]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Jan 25 16:54:07 garage startx[2045]: (==) Log file: "/var/log/Xorg.0.log", Time: Sun Jan 25 16:54:07 2026 Jan 25 16:54:07 garage lircd-0.10.1[2051]: Info: Initial device: /dev/lirc0 Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: 'lirc' written to protocols file /sys/class/rc/rc1/protocols Jan 25 16:54:07 garage lircd-0.10.1[2051]: Info: Initial device: /dev/lirc0 Jan 25 16:54:07 garage lircd-0.10.1[2051]: Info: [lirc] protocol is enabled Jan 25 16:54:07 garage lircd[2051]: lircd-0.10.1[2051]: Info: lircd: Opening log, level: Info Jan 25 16:54:07 garage lircd[2051]: lircd-0.10.1[2051]: Notice: Using systemd fd Jan 25 16:54:07 garage lircd[2051]: lircd-0.10.1[2051]: Warning: Running as root Jan 25 16:54:07 garage lircd[2051]: lircd-0.10.1[2051]: Info: Using remote: lircd.conf. Jan 25 16:54:07 garage lircd[2051]: lircd-0.10.1[2051]: Notice: lircd(default) ready, using /var/run/lirc/lircd Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Options: driver: default Jan 25 16:54:07 garage systemd[1]: Started lircd.service - Flexible IR remote input/output application support. Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Options: output: /var/run/lirc/lircd Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Options: nodaemon: 1 Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Options: plugindir: /usr/lib/arm-linux-gnueabihf/lirc/plugins Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Options: logfile: syslog Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Options: immediate-init: 0 Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Options: permission: 666 Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Options: driver-options: Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Options: pidfile: /var/run/lirc/lircd.pid Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Options: listen: 0 Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Options: connect: (null) Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Options: userelease: 0 Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Options: effective_user: (null) Jan 25 16:54:07 garage volumio[1185]: info: touch_display: X display number found: 0 Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Options: release_suffix: _EVUP Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Options: allow_simulate: 0 Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Options: repeat_max: 600 Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Options: configfile: /etc/lirc/lircd.conf Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Options: dynamic_codes: (null) Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Current driver: default Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Driver API version: 3 Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Driver version: 0.10.0 Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Driver info: See file:///usr/share/doc/lirc/plugindocs/default.html Jan 25 16:54:07 garage lircd-0.10.1[2051]: Info: lircd: Opening log, level: Info Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: Using systemd fd Jan 25 16:54:07 garage lircd-0.10.1[2051]: Warning: Running as root Jan 25 16:54:07 garage lircd-0.10.1[2051]: Info: Using remote: lircd.conf. Jan 25 16:54:07 garage lircd-0.10.1[2051]: Notice: lircd(default) ready, using /var/run/lirc/lircd Jan 25 16:54:07 garage sudo[1712]: pam_unix(sudo:session): session closed for user root Jan 25 16:54:07 garage volumio[1185]: info: ir_controller: systemctl restart lircd.service succeeded. Jan 25 16:54:07 garage startx[2045]: (==) Using config directory: "/etc/X11/xorg.conf.d" Jan 25 16:54:07 garage startx[2045]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Jan 25 16:54:08 garage sudo[2077]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart irexec.service Jan 25 16:54:08 garage sudo[2077]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 16:54:08 garage volumio[1185]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Jan 25 16:54:08 garage volumio[1185]: info: touch_display: X display number found: 0 Jan 25 16:54:08 garage volumio5-onboarding[1994]: time=2026-01-25T16:54:08.167+01:00 level=INFO msg="running volumio5-device-gateway" version=9838fecf+CHANGES buildDate=2026-01-16T16:06:14Z Jan 25 16:54:08 garage systemd[1]: Started irexec.service - Handle events from IR remotes decoded by lircd(8). Jan 25 16:54:08 garage sudo[2077]: pam_unix(sudo:session): session closed for user root Jan 25 16:54:08 garage lircd[2051]: lircd-0.10.1[2051]: Notice: accepted new client on /var/run/lirc/lircd Jan 25 16:54:08 garage lircd[2051]: lircd-0.10.1[2051]: Info: [lirc] protocol is enabled Jan 25 16:54:08 garage lircd-0.10.1[2051]: Notice: accepted new client on /var/run/lirc/lircd Jan 25 16:54:08 garage lircd-0.10.1[2051]: Info: [lirc] protocol is enabled Jan 25 16:54:08 garage volumio[1185]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 8 Jan 25 16:54:08 garage volumio[1185]: info: ir_controller: systemctl restart irexec.service succeeded. Jan 25 16:54:08 garage volumio5-onboarding[1994]: time=2026-01-25T16:54:08.302+01:00 level=INFO msg="listening for BLE messages" address=B8:27:EB:BB:E1:A0%00 Jan 25 16:54:08 garage volumio5-onboarding[1994]: time=2026-01-25T16:54:08.330+01:00 level=INFO msg="listening for WebSocket messages" address=[::]:7331 Jan 25 16:54:08 garage volumio[1185]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 8 Jan 25 16:54:08 garage volumio[1185]: info: Received Get System Info Jan 25 16:54:08 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 16:54:08 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 16:54:08 garage volumio[1185]: info: Discovery: Getting this device information Jan 25 16:54:08 garage volumio[1185]: info: CoreCommandRouter::volumioGetState Jan 25 16:54:08 garage volumio[1185]: info: CorePlayQueue::getTrack 0 Jan 25 16:54:08 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 16:54:08 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 25 16:54:08 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 25 16:54:08 garage volumio5-onboarding[1994]: time=2026-01-25T16:54:08.378+01:00 level=INFO msg="BLE descriptor updated" deviceId=5a89c0b414d469f5376fed7f40079643 deviceName=Garage deviceModel= Jan 25 16:54:08 garage volumio5-onboarding[1994]: time=2026-01-25T16:54:08.378+01:00 level=INFO msg="mDNS descriptor updated" deviceId=5a89c0b414d469f5376fed7f40079643 deviceName=Garage deviceModel= Jan 25 16:54:08 garage volumio5-onboarding[1994]: time=2026-01-25T16:54:08.432+01:00 level=INFO msg="bootstrapping state" hasInternet=true Jan 25 16:54:08 garage volumio[1185]: info: Received Get System Info Jan 25 16:54:08 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 16:54:08 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 16:54:08 garage volumio[1185]: info: Discovery: Getting this device information Jan 25 16:54:08 garage volumio[1185]: info: CoreCommandRouter::volumioGetState Jan 25 16:54:08 garage volumio[1185]: info: CorePlayQueue::getTrack 0 Jan 25 16:54:08 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 16:54:08 garage volumio-remote-updater[650]: Test mode enabled Jan 25 16:54:08 garage volumio-remote-updater[650]: Alpha mode disabled Jan 25 16:54:08 garage volumio-remote-updater[650]: Alpha legacy test mode disabled Jan 25 16:54:08 garage volumio[1185]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jan 25 16:54:08 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jan 25 16:54:08 garage go-librespot[1987]: time="2026-01-25T16:54:08+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]" Jan 25 16:54:08 garage go-librespot[1987]: time="2026-01-25T16:54:08+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]" Jan 25 16:54:08 garage go-librespot[1987]: time="2026-01-25T16:54:08+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]" Jan 25 16:54:08 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 25 16:54:08 garage go-librespot[1987]: time="2026-01-25T16:54:08+01:00" level=info msg="zeroconf server listening on port 34663" Jan 25 16:54:08 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 25 16:54:08 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 25 16:54:08 garage go-librespot[1987]: time="2026-01-25T16:54:08+01:00" level=debug msg="obtained new client token: AADxE8uAEnKV3Dob20S47nHX2Lg1l32RYsCqWU5D8C0aoSXMpcB6BhacKUvtHHLOJeayaJI5Izdst9F7o0MZJVutF7SbsDMcFjfmAonACXHuAspTG+aOBg5mwyrYGdBqHwtNWeQbSP7gDcMtR/+E/gbW3Hiccp89mwsTQ7+EiDei+aOz+1ZDAqfEi2tf8KbpckBRCrXOp/cuygPtrEZeO0IcmRTa+a3Q4HpMFHYfQTAyLWYug/k0PHqz8AE=" Jan 25 16:54:09 garage go-librespot[1987]: time="2026-01-25T16:54:09+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 25 16:54:09 garage go-librespot[1987]: time="2026-01-25T16:54:09+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:51668->104.199.65.9:4070: read: connection reset by peer" Jan 25 16:54:09 garage systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 16:54:09 garage systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 16:54:09 garage volumio[1185]: info: go-librespot daemon successfully initialized Jan 25 16:54:09 garage wpa_supplicant[1146]: RRM: Ignoring radio measurement request: Not RRM network Jan 25 16:54:10 garage volumio5-onboarding[1994]: time=2026-01-25T16:54:10.013+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Jan 25 16:54:10 garage volumio5-onboarding[1994]: time=2026-01-25T16:54:10.015+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Jan 25 16:54:10 garage volumio5-onboarding[1994]: time=2026-01-25T16:54:10.016+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Jan 25 16:54:10 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 25 16:54:10 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 25 16:54:10 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 25 16:54:10 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 25 16:54:10 garage volumio[1185]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 25 16:54:12 garage systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 25 16:54:12 garage systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 16:54:12 garage volumio5-onboarding[1994]: time=2026-01-25T16:54:12.125+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=697d0a52NfgIiyr9XFusdwccQno1 tokenExpiry=2026-01-25T17:54:12.125+01:00 Jan 25 16:54:12 garage systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 16:54:12 garage go-librespot[2111]: go-librespot daemon starting... Jan 25 16:54:12 garage go-librespot[2112]: time="2026-01-25T16:54:12+01:00" level=info msg="running go-librespot 0.4.0" Jan 25 16:54:12 garage go-librespot[2112]: time="2026-01-25T16:54:12+01:00" level=debug msg="app state loaded" Jan 25 16:54:12 garage go-librespot[2112]: time="2026-01-25T16:54:12+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 16:54:12 garage kernel: vc4-drm soc:gpu: [drm] *ERROR* flip_done timed out Jan 25 16:54:12 garage kernel: vc4-drm soc:gpu: [drm] *ERROR* [CRTC:152:crtc-4] commit wait timed out Jan 25 16:54:12 garage go-librespot[2112]: time="2026-01-25T16:54:12+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]" Jan 25 16:54:12 garage go-librespot[2112]: time="2026-01-25T16:54:12+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]" Jan 25 16:54:12 garage go-librespot[2112]: time="2026-01-25T16:54:12+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]" Jan 25 16:54:12 garage go-librespot[2112]: time="2026-01-25T16:54:12+01:00" level=info msg="zeroconf server listening on port 40677" Jan 25 16:54:12 garage volumio[1185]: info: Initializing connection to go-librespot Websocket Jan 25 16:54:12 garage go-librespot[2112]: time="2026-01-25T16:54:12+01:00" level=debug msg="new websocket client" Jan 25 16:54:12 garage volumio[1185]: info: Connection to go-librespot Websocket established Jan 25 16:54:12 garage go-librespot[2112]: time="2026-01-25T16:54:12+01:00" level=debug msg="obtained new client token: AAAtux+d8EoMoKP2dXNKLosVZrwjqoUvrru1p64nMaFutA+MnQMeQTYkfpYORgrS5jdH1Ftr2TTBeO2ZV6nf+5rlQVVBy4JS6uO3Mhsl7kTqOX3+rWecoAtFeDh1PEx5Xj3KLu5WCPj3SS7AECS8t/fJbY3u9v6LUEUCVdPQnJ6vqi0FLiZ9o+V++kOnsQw19R9CyKHfzgUcT40/10qUnfzna5R3uD1BUGA2uHY50WETegbk0IudNaZS5pE=" Jan 25 16:54:12 garage go-librespot[2112]: time="2026-01-25T16:54:12+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 25 16:54:12 garage go-librespot[2112]: time="2026-01-25T16:54: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: read tcp 192.168.88.184:51684->104.199.65.9:4070: read: connection reset by peer" Jan 25 16:54:12 garage systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 16:54:12 garage systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 16:54:12 garage volumio[1185]: info: Connection to go-librespot Websocket closed Jan 25 16:54:14 garage volumio[1185]: info: CoreCommandRouter::volumioGetState Jan 25 16:54:14 garage volumio[1185]: info: CorePlayQueue::getTrack 0 Jan 25 16:54:14 garage volumio[1185]: info: Listing playlists Jan 25 16:54:14 garage volumio[1185]: info: Listing playlists Jan 25 16:54:14 garage mpd[2032]: 2026-01-25T16:54:14 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 25 16:54:14 garage systemd[1]: Started mpd.service - Music Player Daemon. Jan 25 16:54:14 garage sudo[1528]: pam_unix(sudo:session): session closed for user root Jan 25 16:54:14 garage systemd[1]: Startup finished in 2min 30.370s (kernel) + 2min 39.045s (userspace) = 5min 9.416s. Jan 25 16:54:14 garage sudo[1540]: pam_unix(sudo:session): session closed for user root Jan 25 16:54:15 garage volumio[1185]: error: MPD error: The expression evaluated to a falsy value: Jan 25 16:54:15 garage volumio[1185]: assert.ok(self.idling) Jan 25 16:54:15 garage volumio[1185]: error: The expression evaluated to a falsy value: Jan 25 16:54:15 garage volumio[1185]: assert.ok(self.idling) Jan 25 16:54:15 garage volumio[1185]: error: updateQueue error: null Jan 25 16:54:15 garage volumio[1185]: info: MPD running with PID2032 Jan 25 16:54:15 garage volumio[1185]: ,establishing connection Jan 25 16:54:15 garage volumio[1185]: error: updateQueue error: null Jan 25 16:54:15 garage volumio[1185]: info: Getting Spotify volume Jan 25 16:54:15 garage volumio[1185]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 16:54:15 garage volumio[1185]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 16:54:15 garage volumio[1185]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 25 16:54:15 garage volumio[1185]: errno: -111, Jan 25 16:54:15 garage volumio[1185]: code: 'ECONNREFUSED', Jan 25 16:54:15 garage volumio[1185]: syscall: 'connect', Jan 25 16:54:15 garage volumio[1185]: address: '127.0.0.1', Jan 25 16:54:15 garage volumio[1185]: port: 9879, Jan 25 16:54:15 garage volumio[1185]: response: undefined Jan 25 16:54:15 garage volumio[1185]: } Jan 25 16:54:15 garage volumio[1185]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 16:54:15 garage wpa_supplicant[1146]: RRM: Ignoring radio measurement request: Not RRM network Jan 25 16:54:16 garage systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 25 16:54:16 garage systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 16:54:16 garage systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 16:54:16 garage go-librespot[2139]: go-librespot daemon starting... Jan 25 16:54:16 garage go-librespot[2140]: time="2026-01-25T16:54:16+01:00" level=info msg="running go-librespot 0.4.0" Jan 25 16:54:16 garage go-librespot[2140]: time="2026-01-25T16:54:16+01:00" level=debug msg="app state loaded" Jan 25 16:54:16 garage go-librespot[2140]: time="2026-01-25T16:54:16+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 16:54:16 garage sudo[2150]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-25 16:53' Jan 25 16:54:16 garage sudo[2150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 16:54:16 garage go-librespot[2140]: time="2026-01-25T16:54: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 16:54:16 garage go-librespot[2140]: time="2026-01-25T16:54:16+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 25 16:54:16 garage go-librespot[2140]: time="2026-01-25T16:54:16+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 25 16:54:16 garage go-librespot[2140]: time="2026-01-25T16:54:16+01:00" level=info msg="zeroconf server listening on port 39779" 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="2d08ec68ade0b018167f2db96c3e58a38ca68229" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Jan 20 18:01:18 UTC 2026" VOLUMIO_VERSION="4.089" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="9885f1e3a558c3ea9d61decc103defba"