Aug 26 22:10:00 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 22:10:00 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 22:10:00 volumio volumio[1205]: info: Creating Spotify config file Aug 26 22:10:00 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:05 volumio volumio[1367]: Starting albumart workers Aug 26 22:10:05 volumio volumio[1205]: info: Scheduling reboots with hours: 4, minutes: 0 in timezone: Europe/Prague Aug 26 22:10:05 volumio volumio[1205]: info: Scheduling job with cron expression: 0 0 4 * * 0 Aug 26 22:10:05 volumio volumio[1205]: info: Scheduling job with cron expression: 0 0 4 * * 1 Aug 26 22:10:05 volumio volumio[1205]: info: Scheduling job with cron expression: 0 0 4 * * 2 Aug 26 22:10:05 volumio volumio[1205]: info: Scheduling job with cron expression: 0 0 4 * * 3 Aug 26 22:10:05 volumio volumio[1205]: info: Scheduling job with cron expression: 0 0 4 * * 4 Aug 26 22:10:05 volumio volumio[1205]: info: Scheduling job with cron expression: 0 0 4 * * 5 Aug 26 22:10:05 volumio volumio[1205]: info: Scheduling job with cron expression: 0 0 4 * * 6 Aug 26 22:10:05 volumio volumio[1205]: info: Volumio Calling Home Aug 26 22:10:06 volumio volumio[1366]: Starting albumart workers Aug 26 22:10:06 volumio volumio[1368]: Starting albumart workers Aug 26 22:10:07 volumio mpd[1449]: 2026-08-26T22:10:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 26 22:10:07 volumio systemd[1]: Started mpd.service - Music Player Daemon. Aug 26 22:10:07 volumio sudo[1425]: pam_unix(sudo:session): session closed for user root Aug 26 22:10:07 volumio sudo[1437]: pam_unix(sudo:session): session closed for user root Aug 26 22:10:08 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 4. Aug 26 22:10:08 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 26 22:10:08 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 26 22:10:08 volumio sudo[1420]: pam_unix(sudo:session): session closed for user root Aug 26 22:10:09 volumio volumio[1205]: info: Completed starting Core Plugins Aug 26 22:10:09 volumio volumio[1205]: info: ------------------------------------------- Aug 26 22:10:09 volumio volumio[1205]: info: ----- MyVolumio plugins startup ---- Aug 26 22:10:09 volumio volumio[1205]: info: ------------------------------------------- Aug 26 22:10:09 volumio volumio[1205]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 26 22:10:09 volumio volumio[1205]: info: MPD Permissions set Aug 26 22:10:09 volumio volumio[1205]: info: MPD Permissions set Aug 26 22:10:09 volumio volumio[1205]: info: Upmpdcli Daemon Started Aug 26 22:10:10 volumio volumio[1205]: info: MPD running with PID1449 Aug 26 22:10:10 volumio volumio[1205]: ,establishing connection Aug 26 22:10:10 volumio volumio[1205]: info: Spotify config file written Aug 26 22:10:10 volumio sudo[1509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 26 22:10:10 volumio sudo[1509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:10:10 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 22:10:10 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 22:10:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:10:10 volumio go-librespot[1512]: go-librespot daemon starting... Aug 26 22:10:10 volumio sudo[1509]: pam_unix(sudo:session): session closed for user root Aug 26 22:10:11 volumio go-librespot[1513]: time="2026-08-26T22:10:11+02:00" level=info msg="running go-librespot 0.4.0" Aug 26 22:10:11 volumio go-librespot[1513]: time="2026-08-26T22:10:11+02:00" level=debug msg="app state loaded" Aug 26 22:10:11 volumio go-librespot[1513]: time="2026-08-26T22:10:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 22:10:11 volumio volumio[1205]: error: MPD error: The expression evaluated to a falsy value: Aug 26 22:10:11 volumio volumio[1205]: assert.ok(self.idling) Aug 26 22:10:11 volumio volumio[1205]: error: The expression evaluated to a falsy value: Aug 26 22:10:11 volumio volumio[1205]: assert.ok(self.idling) Aug 26 22:10:11 volumio volumio[1205]: error: MPD error: The expression evaluated to a falsy value: Aug 26 22:10:11 volumio volumio[1205]: assert.ok(self.idling) Aug 26 22:10:11 volumio volumio[1205]: error: The expression evaluated to a falsy value: Aug 26 22:10:11 volumio volumio[1205]: assert.ok(self.idling) Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:12 volumio volumio[1205]: info: No need to fix Spotify hosts Aug 26 22:10:12 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Aug 26 22:10:12 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Aug 26 22:10:12 volumio volumio[1205]: error: updateQueue error: null Aug 26 22:10:12 volumio volumio[1205]: Upnp client error: Error: This socket has been ended by the other party Aug 26 22:10:12 volumio volumio[1205]: info: Listing playlists Aug 26 22:10:12 volumio volumio[1205]: info: Listing playlists Aug 26 22:10:12 volumio volumio[1205]: info: Starting Shairport Sync Aug 26 22:10:12 volumio volumio[1205]: info: Starting Shairport Sync Aug 26 22:10:12 volumio sudo[1555]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Aug 26 22:10:12 volumio volumio[1205]: info: Starting Shairport Sync Aug 26 22:10:13 volumio sudo[1555]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:10:13 volumio sudo[1558]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 22:10:13 volumio sudo[1558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:10:13 volumio sudo[1560]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 22:10:13 volumio sudo[1563]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 22:10:13 volumio sudo[1560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:10:13 volumio sudo[1563]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:10:13 volumio sudo[1566]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Aug 26 22:10:13 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Aug 26 22:10:13 volumio mpd_monitor.sh[1567]: MPD Monitor Service: Starting MPD Monitor Service Aug 26 22:10:13 volumio sudo[1555]: pam_unix(sudo:session): session closed for user root Aug 26 22:10:13 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 26 22:10:13 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 26 22:10:13 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 22:10:13 volumio systemd[1]: shairport-sync.service: Consumed 1.667s CPU time. Aug 26 22:10:13 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 22:10:13 volumio sudo[1566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:10:13 volumio sudo[1558]: pam_unix(sudo:session): session closed for user root Aug 26 22:10:13 volumio volumio[1205]: info: Successfully started MPD Monitor Aug 26 22:10:13 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Aug 26 22:10:13 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Aug 26 22:10:13 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Aug 26 22:10:13 volumio volumio[1205]: info: Shairport-Sync Started Aug 26 22:10:13 volumio volumio[1205]: Error adding Membership: Error: addMembership EINVAL Aug 26 22:10:13 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Aug 26 22:10:13 volumio mpd_monitor.sh[1593]: MPD Monitor Service: Starting MPD Monitor Service Aug 26 22:10:13 volumio sudo[1566]: pam_unix(sudo:session): session closed for user root Aug 26 22:10:13 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 26 22:10:13 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 26 22:10:13 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 22:10:13 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 22:10:13 volumio sudo[1563]: pam_unix(sudo:session): session closed for user root Aug 26 22:10:13 volumio sudo[1560]: pam_unix(sudo:session): session closed for user root Aug 26 22:10:13 volumio volumio[1205]: info: Successfully started MPD Monitor Aug 26 22:10:13 volumio volumio[1205]: info: Shairport-Sync Started Aug 26 22:10:13 volumio volumio[1205]: info: Shairport-Sync Started Aug 26 22:10:15 volumio volumio[1205]: info: go-librespot daemon successfully initialized Aug 26 22:10:16 volumio volumio[1205]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 26 22:10:18 volumio volumio[1205]: info: Initializing connection to go-librespot Websocket Aug 26 22:10:19 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Aug 26 22:10:19 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Aug 26 22:10:21 volumio volumio[1205]: info: Discovery: adding 9c5b0d3d-b639-4619-be34-7ebe1833b03f Aug 26 22:10:21 volumio volumio[1205]: info: Discovery: Found device Volumio Aug 26 22:10:21 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Aug 26 22:10:21 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Aug 26 22:10:24 volumio go-librespot[1513]: time="2026-08-26T22:10:24+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 26 22:10:24 volumio go-librespot[1513]: time="2026-08-26T22:10:24+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 26 22:10:24 volumio go-librespot[1513]: time="2026-08-26T22:10:24+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 26 22:10:24 volumio go-librespot[1513]: time="2026-08-26T22:10:24+02:00" level=info msg="zeroconf server listening on port 43347" Aug 26 22:10:29 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Aug 26 22:10:29 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Aug 26 22:10:29 volumio volumio[1205]: info: Listing playlists Aug 26 22:10:29 volumio volumio[1205]: info: Listing playlists Aug 26 22:10:29 volumio volumio[1205]: error: MyVolumio Plugin failed to start in a timely fashion Aug 26 22:10:29 volumio volumio[1205]: [Metrics] CommandRouter: 52s 651.23ms Aug 26 22:10:29 volumio volumio[1205]: info: CoreCommandRouter::volumiosetStartupVolume Aug 26 22:10:29 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 22:10:29 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 22:10:29 volumio volumio[1205]: info: CoreCommandRouter::Close All Modals sent Aug 26 22:10:29 volumio volumio[1205]: info: CoreCommandRouter::Close All Modals sent Aug 26 22:10:30 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 26 22:10:30 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 26 22:10:31 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 26 22:10:34 volumio volumio[1205]: info: Volumio called home Aug 26 22:10:34 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 22:10:34 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 22:10:34 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 26 22:10:36 volumio volumio[1205]: info: BOOT COMPLETED Aug 26 22:10:39 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Aug 26 22:10:39 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Aug 26 22:10:39 volumio volumio[1205]: info: Discovery: this is already registered, 9c5b0d3d-b639-4619-be34-7ebe1833b03f Aug 26 22:10:39 volumio volumio[1205]: info: Discovery: Found device Volumio Aug 26 22:10:39 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Aug 26 22:10:39 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Aug 26 22:10:39 volumio volumio[1205]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Aug 26 22:10:44 volumio volumio[1205]: info: An error occurred while refreshing Spotify Token Error: Bad Request Aug 26 22:10:48 volumio go-librespot[1513]: time="2026-08-26T22:10:48+02:00" level=debug msg="new websocket client" Aug 26 22:10:48 volumio volumio[1205]: info: Connection to go-librespot Websocket established Aug 26 22:10:49 volumio volumio[1205]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Aug 26 22:10:49 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Aug 26 22:10:49 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Aug 26 22:10:49 volumio volumio[1205]: info: Listing playlists Aug 26 22:10:49 volumio volumio[1205]: info: Listing playlists Aug 26 22:10:49 volumio volumio[1205]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Aug 26 22:10:50 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Aug 26 22:10:50 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 26 22:10:51 volumio volumio[1205]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 26 22:10:51 volumio volumio[1205]: info: Adding plugin bluetooth to MyMusic Plugins Aug 26 22:10:51 volumio volumio[1205]: info: Adding plugin multiroom to MyMusic Plugins Aug 26 22:10:51 volumio volumio[1205]: info: Adding plugin metavolumio to MyMusic Plugins Aug 26 22:10:51 volumio volumio[1205]: info: Adding plugin cd_controller to MyMusic Plugins Aug 26 22:10:51 volumio volumio[1205]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 26 22:10:51 volumio volumio[1205]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 26 22:10:51 volumio volumio[1205]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 26 22:10:52 volumio volumio[1205]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 26 22:10:52 volumio upmpdcli[1670]: writing RSA key Aug 26 22:10:54 volumio go-librespot[1513]: time="2026-08-26T22:10:54+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)" Aug 26 22:10:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 22:10:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 22:10:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 26 22:10:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:10:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:10:58 volumio go-librespot[1696]: go-librespot daemon starting... Aug 26 22:10:58 volumio go-librespot[1697]: time="2026-08-26T22:10:58+02:00" level=info msg="running go-librespot 0.4.0" Aug 26 22:10:58 volumio go-librespot[1697]: time="2026-08-26T22:10:58+02:00" level=debug msg="app state loaded" Aug 26 22:10:58 volumio go-librespot[1697]: time="2026-08-26T22:10:58+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 22:10:58 volumio go-librespot[1697]: time="2026-08-26T22:10:58+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 26 22:10:58 volumio go-librespot[1697]: time="2026-08-26T22:10:58+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 26 22:10:58 volumio go-librespot[1697]: time="2026-08-26T22:10:58+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 26 22:10:58 volumio go-librespot[1697]: time="2026-08-26T22:10:58+02:00" level=info msg="zeroconf server listening on port 38375" Aug 26 22:10:58 volumio go-librespot[1697]: time="2026-08-26T22:10:58+02:00" level=debug msg="obtained new client token: AAEO+ReLsfyteHVsDtjtgxI3mu97NEXrmJCYPUD9eD0dpyYoyF5OjTtO8IhQZtKke3DHfQ1Js06nXBjFFA2Ew9CbzZM0t7XV3HYLczq6dlkQ945cxNL34ZN4cpTAXN+qoIvNcmto8wQQ8zGjx9PG8Sav/0J3RwVvsm+JreiaEgOSw1gsbnbO+ttYhCr/SE/mbuaBCxewz4QCsFv/bMG2g98QmqZicfh6EBpWpAXAi6k++5ilF4vIj74J6mo=" Aug 26 22:10:59 volumio volumio[1205]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 26 22:10:59 volumio volumio[1205]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 26 22:11:00 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 22:11:00 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 22:11:00 volumio volumio[1205]: info: Starting MyVolumio Remote Streaming Endpoints Aug 26 22:11:00 volumio volumio[1205]: info: MyVolumio login type: Token Aug 26 22:11:00 volumio volumio[1205]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 26 22:11:00 volumio volumio[1205]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 26 22:11:04 volumio go-librespot[1697]: time="2026-08-26T22:11:04+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 22:11:04 volumio go-librespot[1697]: time="2026-08-26T22:11:04+02:00" level=debug msg="completed keyexchange" Aug 26 22:11:04 volumio go-librespot[1697]: time="2026-08-26T22:11:04+02:00" level=debug msg="completed challenge" Aug 26 22:11:04 volumio go-librespot[1697]: time="2026-08-26T22:11:04+02:00" level=info msg="authenticated AP" username="mi**********cz" Aug 26 22:11:07 volumio volumio[1205]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 26 22:11:07 volumio volumio[1205]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 26 22:11:07 volumio volumio[1205]: info: Streaming services startup Aug 26 22:11:07 volumio volumio[1205]: info: Starting Streaming Daemon Aug 26 22:11:07 volumio volumio[1205]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 26 22:11:07 volumio sudo[1721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 26 22:11:07 volumio sudo[1721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:11:07 volumio sudo[1721]: pam_unix(sudo:session): session closed for user root Aug 26 22:11:07 volumio volumio[1205]: info: Getting Spotify volume Aug 26 22:11:07 volumio volumio[1205]: info: Connection to go-librespot Websocket closed Aug 26 22:11:07 volumio volumio[1205]: error: Cannot start Volumio Streaming Daemon Aug 26 22:11:07 volumio volumio[1205]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 26 22:11:07 volumio volumio[1205]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 26 22:11:08 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Aug 26 22:11:08 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Aug 26 22:11:08 volumio volumio[1205]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Aug 26 22:11:08 volumio volumio[1205]: info: Listing playlists Aug 26 22:11:08 volumio volumio[1205]: info: Listing playlists Aug 26 22:11:09 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Aug 26 22:11:09 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Aug 26 22:11:10 volumio go-librespot[1697]: time="2026-08-26T22:11:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 22:11:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 22:11:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 22:11:10 volumio volumio[1205]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 22:11:10 volumio volumio[1205]: Error: socket hang up Aug 26 22:11:10 volumio volumio[1205]: at connResetException (node:internal/errors:720:14) Aug 26 22:11:10 volumio volumio[1205]: at Socket.socketOnEnd (node:_http_client:519:23) Aug 26 22:11:10 volumio volumio[1205]: at Socket.emit (node:events:526:35) Aug 26 22:11:10 volumio volumio[1205]: at endReadableNT (node:internal/streams/readable:1376:12) Aug 26 22:11:10 volumio volumio[1205]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Aug 26 22:11:10 volumio volumio[1205]: code: 'ECONNRESET', Aug 26 22:11:10 volumio volumio[1205]: response: undefined Aug 26 22:11:10 volumio volumio[1205]: } Aug 26 22:11:10 volumio volumio[1205]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 22:11:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 26 22:11:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:11:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 22:11:13 volumio go-librespot[1746]: go-librespot daemon starting... Aug 26 22:11:14 volumio go-librespot[1747]: time="2026-08-26T22:11:14+02:00" level=info msg="running go-librespot 0.4.0" Aug 26 22:11:14 volumio go-librespot[1747]: time="2026-08-26T22:11:14+02:00" level=debug msg="app state loaded" Aug 26 22:11:14 volumio go-librespot[1747]: time="2026-08-26T22:11:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 22:11:17 volumio sudo[1769]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-26 22:10' Aug 26 22:11:17 volumio sudo[1769]: 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"