Aug 31 15:56:00 bcik volumio[26776]: info: Plugin mpdemulation is not enabled Aug 31 15:56:00 bcik volumio[26776]: info: Loading plugin "rest_api"... Aug 31 15:56:00 bcik volumio[26776]: info: Loading plugin "websocket"... Aug 31 15:56:00 bcik volumio[26776]: info: Starting Socket.io Server version 1.7.4 Aug 31 15:56:00 bcik volumio[26776]: info: Loading plugin "radio_browser"... Aug 31 15:56:00 bcik volumio[26837]: Forking 3 albumart workers Aug 31 15:56:00 bcik volumio[26776]: info: Loading i18n strings for locale pl Aug 31 15:56:00 bcik volumio[26776]: Updating browse sources language Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::initPlayerControls Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: Express server listening on port 3000 Aug 31 15:56:00 bcik volumio[26776]: [Metrics] WebUI: 1s 323.34ms Aug 31 15:56:00 bcik volumio[26776]: info: CoreStateMachine::resetVolumioState Aug 31 15:56:00 bcik volumio[26776]: info: CoreStateMachine::getcurrentVolume Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 15:56:00 bcik volumio[26776]: info: Volumio Network Manager: Network status updated: 1 Aug 31 15:56:00 bcik volumio[26776]: 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: 1 Aug 31 15:56:00 bcik volumio[26776]: 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: 1 Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: Reloading queue from file Aug 31 15:56:00 bcik volumio[26776]: info: VolumeController:: Volume=53 Mute =false Aug 31 15:56:00 bcik volumio[26776]: info: CoreStateMachine::pushState Aug 31 15:56:00 bcik volumio[26776]: info: CorePlayQueue::getTrack 0 Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::volumioPushState Aug 31 15:56:00 bcik volumio[26776]: info: CoreStateMachine::updateTrackBlock Aug 31 15:56:00 bcik volumio[26776]: info: CorePlayQueue::getTrackBlock Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 15:56:00 bcik volumio[26776]: info: CoreStateMachine::setRepeat false single undefined Aug 31 15:56:00 bcik volumio[26776]: info: CoreStateMachine::pushState Aug 31 15:56:00 bcik volumio[26776]: info: CorePlayQueue::getTrack 0 Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::volumioPushState Aug 31 15:56:00 bcik volumio[26776]: info: CoreStateMachine::setRandom false Aug 31 15:56:00 bcik volumio[26776]: info: CoreStateMachine::pushState Aug 31 15:56:00 bcik volumio[26776]: info: CorePlayQueue::getTrack 0 Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::volumioPushState Aug 31 15:56:00 bcik volumio[26776]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 31 15:56:00 bcik volumio[26776]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Aug 31 15:56:00 bcik volumio[26776]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 31 15:56:00 bcik volumio[26776]: info: Setting Device type: Raspberry PI Aug 31 15:56:00 bcik volumio[26776]: info: Completed loading Core Plugins Aug 31 15:56:00 bcik volumio[26776]: info: Preparing to generate the ALSA configuration file Aug 31 15:56:00 bcik volumio[26776]: info: Asound.conf file unchanged, so no further update is needed Aug 31 15:56:00 bcik volumio[26776]: info: Output device has changed, restarting MPD Aug 31 15:56:00 bcik sudo[26894]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 15:56:00 bcik sudo[26894]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:00 bcik volumio[26776]: info: Output device has changed, restarting Shairport Sync Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:00 bcik sudo[26894]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:00 bcik sudo[26896]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 15:56:00 bcik sudo[26896]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:00 bcik volumio[26776]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:56:00 bcik volumio[26776]: info: ___________ START PLUGINS ___________ Aug 31 15:56:00 bcik volumio[26776]: info: ControllerMpd::onStart: Initializing MPD Aug 31 15:56:00 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 31 15:56:00 bcik volumio[26776]: info: Creating MPD Configuration file Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:56:00 bcik sudo[26904]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 31 15:56:00 bcik sudo[26904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:56:00 bcik volumio[26776]: info: [1788184560314] CoreMusicLibrary::Adding element Serwery Mediów Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:56:00 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 15:56:00 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 15:56:00 bcik volumio[26776]: info: UPNP Browser: Client initialized successfully Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 15:56:00 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 15:56:00 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 15:56:00 bcik sudo[26907]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 15:56:00 bcik sudo[26907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:00 bcik sudo[26908]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 15:56:00 bcik sudo[26908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:00 bcik sudo[26908]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:00 bcik volumio[26776]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:56:00 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:00 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 15:56:00 bcik volumio[26776]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:56:00 bcik sudo[26904]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:00 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 15:56:00 bcik volumio[26776]: info: [1788184560363] CoreMusicLibrary::Adding element Last_100 Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:56:00 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:56:00 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 15:56:00 bcik volumio[26776]: info: [1788184560367] CoreMusicLibrary::Adding element Webradio Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:56:00 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 15:56:00 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 15:56:00 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 15:56:00 bcik volumio[26776]: info: Initializing BBC Radios Aug 31 15:56:00 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 15:56:00 bcik volumio[26847]: Starting albumart workers Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:00 bcik sudo[26923]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 15:56:00 bcik sudo[26923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 31 15:56:00 bcik volumio[26849]: Starting albumart workers Aug 31 15:56:00 bcik volumio[26776]: info: Creating Spotify config file Aug 31 15:56:00 bcik sudo[26923]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26848]: Starting albumart workers Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:56:00 bcik volumio[26776]: info: [1788184560568] CoreMusicLibrary::Adding element Radio Browser Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:56:00 bcik volumio[26776]: Cannot find translation for source Radio Browser Aug 31 15:56:00 bcik volumio[26776]: info: Volumio Calling Home Aug 31 15:56:00 bcik volumio[26776]: info: VolumeController:: Volume=53 Mute =false Aug 31 15:56:00 bcik volumio[26776]: info: CoreStateMachine::pushState Aug 31 15:56:00 bcik volumio[26776]: info: CorePlayQueue::getTrack 0 Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::volumioPushState Aug 31 15:56:00 bcik volumio[26776]: info: MPD Permissions set Aug 31 15:56:00 bcik volumio[26776]: info: MPD Permissions set Aug 31 15:56:00 bcik volumio[26776]: info: Spotify config file written Aug 31 15:56:00 bcik sudo[26957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 15:56:00 bcik sudo[26957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:00 bcik volumio[26776]: 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 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:00 bcik go-librespot[26964]: go-librespot daemon starting... Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:00 bcik volumio[26776]: info: No need to fix Spotify hosts Aug 31 15:56:00 bcik sudo[26957]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:00 bcik go-librespot[26976]: time="2026-08-31T15:56:00+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:56:00 bcik go-librespot[26976]: time="2026-08-31T15:56:00+02:00" level=debug msg="app state loaded" Aug 31 15:56:00 bcik go-librespot[26976]: time="2026-08-31T15:56:00+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:56:00 bcik volumio[26776]: info: Volumio called home Aug 31 15:56:00 bcik volumio[26776]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 15:56:00 bcik volumio[26776]: info: Discovery: Found device Bącik Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::volumioGetState Aug 31 15:56:00 bcik volumio[26776]: info: CorePlayQueue::getTrack 0 Aug 31 15:56:00 bcik volumio[26776]: info: Starting Shairport Sync Aug 31 15:56:00 bcik volumio[26776]: info: Starting Shairport Sync Aug 31 15:56:00 bcik sudo[26984]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:56:00 bcik sudo[26984]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:00 bcik volumio[26776]: info: Starting Shairport Sync Aug 31 15:56:00 bcik volumio[26776]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 15:56:00 bcik volumio[26776]: info: Discovery: Found device Bącik Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::volumioGetState Aug 31 15:56:00 bcik volumio[26776]: info: CorePlayQueue::getTrack 0 Aug 31 15:56:00 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 31 15:56:00 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Aug 31 15:56:00 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:56:00 bcik systemd[1]: shairport-sync.service: Consumed 1.542s CPU time. Aug 31 15:56:00 bcik sudo[26989]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:56:00 bcik sudo[26987]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:56:00 bcik sudo[26989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:00 bcik sudo[26987]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:00 bcik volumio[26776]: info: An error occurred while refreshing Spotify Token Error: Bad Request Aug 31 15:56:00 bcik volumio[26776]: info: CoreCommandRouter::volumioGetState Aug 31 15:56:00 bcik volumio[26776]: info: CorePlayQueue::getTrack 0 Aug 31 15:56:00 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:56:00 bcik sudo[26984]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:00 bcik go-librespot[26976]: time="2026-08-31T15:56:00+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:56:00 bcik go-librespot[26976]: time="2026-08-31T15:56:00+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:56:00 bcik go-librespot[26976]: time="2026-08-31T15:56:00+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:56:00 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 31 15:56:00 bcik volumio[26776]: info: Shairport-Sync Started Aug 31 15:56:00 bcik volumio[26776]: Error adding Membership: Error: addMembership EINVAL Aug 31 15:56:00 bcik go-librespot[26976]: time="2026-08-31T15:56:00+02:00" level=info msg="zeroconf server listening on port 39283" Aug 31 15:56:00 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Aug 31 15:56:00 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:56:00 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:56:00 bcik sudo[26989]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:00 bcik volumio[26776]: info: Shairport-Sync Started Aug 31 15:56:00 bcik sudo[26987]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:00 bcik volumio[26776]: info: Shairport-Sync Started Aug 31 15:56:00 bcik go-librespot[26976]: time="2026-08-31T15:56:00+02:00" level=debug msg="obtained new client token: AAEkS3qLk+fLEyFori3vhCHkfQIo42klM5YIjFFc+PwpdOkMjg4XT4A6FpkSfLbtv3zToHJ41hTE6H2ZATOiXlGHwjeJwwN3cFrNK1U9ta3u9eo/z/1nmVvd2SKTzwiHfvE9uaXwpIxCiLI4jwOtfdfo/Yt6bRS3bNcswzy3/LesslsOwBatEH5786cdkOdo2R2I+CMz+HHmeJabFimIlOu5O11rp7JVVS0mT0mhyShuoyoeH+B5WIM=" Aug 31 15:56:00 bcik go-librespot[26976]: time="2026-08-31T15:56:00+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:56:00 bcik go-librespot[26976]: time="2026-08-31T15:56:00+02:00" level=debug msg="completed keyexchange" Aug 31 15:56:00 bcik go-librespot[26976]: time="2026-08-31T15:56:00+02:00" level=debug msg="completed challenge" Aug 31 15:56:00 bcik mpd[26938]: 2026-08-31T15:56:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 15:56:00 bcik systemd[1]: Started mpd.service - Music Player Daemon. Aug 31 15:56:00 bcik sudo[26907]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:00 bcik sudo[26896]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:00 bcik volumio[26776]: info: Completed starting Core Plugins Aug 31 15:56:00 bcik volumio[26776]: info: ------------------------------------------- Aug 31 15:56:00 bcik volumio[26776]: info: ----- MyVolumio plugins startup ---- Aug 31 15:56:00 bcik volumio[26776]: info: ------------------------------------------- Aug 31 15:56:00 bcik volumio[26776]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 31 15:56:00 bcik go-librespot[26976]: time="2026-08-31T15:56:00+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:56:00 bcik volumio[26776]: error: MPD error: The expression evaluated to a falsy value: Aug 31 15:56:00 bcik volumio[26776]: assert.ok(self.idling) Aug 31 15:56:00 bcik volumio[26776]: error: The expression evaluated to a falsy value: Aug 31 15:56:00 bcik volumio[26776]: assert.ok(self.idling) Aug 31 15:56:00 bcik volumio[26776]: info: MPD running with PID26938 Aug 31 15:56:00 bcik volumio[26776]: ,establishing connection Aug 31 15:56:00 bcik volumio[26776]: error: updateQueue error: null Aug 31 15:56:00 bcik volumio[26776]: error: updateQueue error: null Aug 31 15:56:01 bcik go-librespot[26976]: time="2026-08-31T15:56:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:56:01 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:56:01 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:56:03 bcik volumio-remote-updater[962]: [2026-08-31 15:56:03] [connect] Successful connection Aug 31 15:56:03 bcik volumio-remote-updater[962]: [2026-08-31 15:56:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788184563 101 Aug 31 15:56:03 bcik volumio[26776]: 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: 3 Aug 31 15:56:03 bcik volumio[26776]: info: go-librespot daemon successfully initialized Aug 31 15:56:04 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Aug 31 15:56:04 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:04 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:04 bcik go-librespot[27014]: go-librespot daemon starting... Aug 31 15:56:04 bcik go-librespot[27015]: time="2026-08-31T15:56:04+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:56:04 bcik go-librespot[27015]: time="2026-08-31T15:56:04+02:00" level=debug msg="app state loaded" Aug 31 15:56:04 bcik go-librespot[27015]: time="2026-08-31T15:56:04+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:56:04 bcik go-librespot[27015]: time="2026-08-31T15:56:04+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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 15:56:04 bcik go-librespot[27015]: time="2026-08-31T15:56:04+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:56:04 bcik go-librespot[27015]: time="2026-08-31T15:56:04+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:56:04 bcik go-librespot[27015]: time="2026-08-31T15:56:04+02:00" level=info msg="zeroconf server listening on port 36245" Aug 31 15:56:04 bcik go-librespot[27015]: time="2026-08-31T15:56:04+02:00" level=debug msg="obtained new client token: AAFY698Mr15qibORrd4/ou4chODc2HJJBKJvDcVDWXQmHvq9rpbjf6qKoq87eaFvGfogBt7rF/hWnG2bbPz9+yMUuov08bLiTDobIJJdGyUXGjpDSa7Y+zygVO5LCXrjA6OauGeIhNuZ5HOYmTVRTc1K7lvPw0e8ICA4uqJpCCE7Iz0db2qFiHAjrn5CMo0cVFMBv+poB/Is28F5oHHqUS4jlucybulIGS9zXDNSOtMCTN+/K82InwA=" Aug 31 15:56:04 bcik go-librespot[27015]: time="2026-08-31T15:56:04+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:56:04 bcik go-librespot[27015]: time="2026-08-31T15:56:04+02:00" level=debug msg="completed keyexchange" Aug 31 15:56:04 bcik go-librespot[27015]: time="2026-08-31T15:56:04+02:00" level=debug msg="completed challenge" Aug 31 15:56:04 bcik go-librespot[27015]: time="2026-08-31T15:56:04+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:56:04 bcik go-librespot[27015]: time="2026-08-31T15:56:04+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:56:04 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:56:04 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:56:05 bcik volumio[26776]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 31 15:56:06 bcik volumio[26776]: info: Initializing connection to go-librespot Websocket Aug 31 15:56:06 bcik volumio[26776]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:56:07 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Aug 31 15:56:07 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:07 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:07 bcik go-librespot[27025]: go-librespot daemon starting... Aug 31 15:56:07 bcik go-librespot[27026]: time="2026-08-31T15:56:07+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:56:07 bcik go-librespot[27026]: time="2026-08-31T15:56:07+02:00" level=debug msg="app state loaded" Aug 31 15:56:07 bcik go-librespot[27026]: time="2026-08-31T15:56:07+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:56:07 bcik go-librespot[27026]: time="2026-08-31T15:56:07+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:56:07 bcik go-librespot[27026]: time="2026-08-31T15:56:07+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:56:07 bcik go-librespot[27026]: time="2026-08-31T15:56:07+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:56:07 bcik go-librespot[27026]: time="2026-08-31T15:56:07+02:00" level=info msg="zeroconf server listening on port 34271" Aug 31 15:56:07 bcik go-librespot[27026]: time="2026-08-31T15:56:07+02:00" level=debug msg="obtained new client token: AAEYH3toMb4av6noNZV7rEc6NcebaVqNg8/sQEiOAXR0E5Yh8QJXaDf4WmwJ8gQftVTnRGD3L2gW6BzyYTK84z1D7Tt3oW5ac1ygOiSo5wrHYGd6PXowcg/m0f84MlAG6gfOHTFTFdTha/V6m/w6DscahDTKQjk7v6pq9/opIQqd7FHc06kR7iulCIGXtYbyLGkH3p4ONMGXd2q2SFcGPGpkYz8eOSTUMKpmOyK//UqPp93j9AGzQdo=" Aug 31 15:56:07 bcik go-librespot[27026]: time="2026-08-31T15:56:07+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:56:08 bcik go-librespot[27026]: time="2026-08-31T15:56:08+02:00" level=debug msg="completed keyexchange" Aug 31 15:56:08 bcik go-librespot[27026]: time="2026-08-31T15:56:08+02:00" level=debug msg="completed challenge" Aug 31 15:56:08 bcik go-librespot[27026]: time="2026-08-31T15:56:08+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:56:08 bcik go-librespot[27026]: time="2026-08-31T15:56:08+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:56:08 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:56:08 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 31 15:56:09 bcik volumio[26776]: info: Adding plugin bluetooth to MyMusic Plugins Aug 31 15:56:09 bcik volumio[26776]: info: Adding plugin multiroom to MyMusic Plugins Aug 31 15:56:09 bcik volumio[26776]: info: Adding plugin metavolumio to MyMusic Plugins Aug 31 15:56:09 bcik volumio[26776]: info: Adding plugin cd_controller to MyMusic Plugins Aug 31 15:56:09 bcik volumio[26776]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 31 15:56:09 bcik volumio[26776]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 31 15:56:09 bcik volumio[26776]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 31 15:56:09 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:09 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:09 bcik volumio[26776]: info: Starting MyVolumio Remote Streaming Endpoints Aug 31 15:56:09 bcik volumio[26776]: info: MyVolumio login type: Token Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 31 15:56:09 bcik volumio[26776]: info: Streaming services startup Aug 31 15:56:09 bcik volumio[26776]: info: Starting Streaming Daemon Aug 31 15:56:09 bcik sudo[27050]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 15:56:09 bcik sudo[27050]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:09 bcik volumio[26776]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 31 15:56:09 bcik sudo[27050]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:09 bcik sudo[27057]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 15:56:09 bcik sudo[27057]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:09 bcik sudo[27059]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 15:56:09 bcik sudo[27059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:09 bcik volumio[26776]: error: Cannot start Volumio Streaming Daemon Aug 31 15:56:09 bcik volumio[26776]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 15:56:09 bcik volumio[26776]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 15:56:09 bcik sudo[27059]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:09 bcik sudo[27057]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:09 bcik sudo[27063]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 31 15:56:09 bcik sudo[27063]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:09 bcik sudo[27063]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:09 bcik volumio[26776]: info: Upmpdcli Daemon Started Aug 31 15:56:09 bcik volumio[26776]: info: Initializing connection to go-librespot Websocket Aug 31 15:56:09 bcik volumio[26776]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:56:10 bcik volumio[26776]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 31 15:56:10 bcik volumio[26776]: info: MyVolumio token set successfully Aug 31 15:56:10 bcik volumio[26776]: info: MYVOLUMIO: Adding device Aug 31 15:56:10 bcik volumio[26776]: info: MYVOLUMIO: Evaluating Server Aug 31 15:56:10 bcik volumio[26776]: info: MyVolumio status changed Aug 31 15:56:10 bcik volumio[26776]: info: Streaming services startup Aug 31 15:56:10 bcik volumio[26776]: info: Starting Streaming Daemon Aug 31 15:56:10 bcik volumio[26776]: info: Removing browser output: myVolumio user plan is not superstar Aug 31 15:56:10 bcik volumio[26776]: info: Removing audio output: Aug 31 15:56:10 bcik volumio[26776]: info: Stoppping Tunnel 1 Aug 31 15:56:10 bcik sudo[27086]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 15:56:10 bcik sudo[27086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:10 bcik sudo[27088]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 31 15:56:10 bcik sudo[27088]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:10 bcik 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. Aug 31 15:56:10 bcik 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. Aug 31 15:56:10 bcik sudo[27086]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:10 bcik 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. Aug 31 15:56:10 bcik 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. Aug 31 15:56:10 bcik volumio[26776]: error: Cannot start Volumio Streaming Daemon Aug 31 15:56:10 bcik volumio[26776]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 15:56:10 bcik volumio[26776]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 15:56:10 bcik 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. Aug 31 15:56:10 bcik 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. Aug 31 15:56:10 bcik sudo[27088]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:10 bcik volumio[26776]: info: Remote SSH Stopped Aug 31 15:56:10 bcik volumio[26776]: info: Setting Geolocation for MyVolumio to eu7 Aug 31 15:56:10 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:10 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:10 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:11 bcik volumio[26776]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 15:56:11 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Aug 31 15:56:11 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:11 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:11 bcik go-librespot[27091]: go-librespot daemon starting... Aug 31 15:56:11 bcik go-librespot[27092]: time="2026-08-31T15:56:11+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:56:11 bcik go-librespot[27092]: time="2026-08-31T15:56:11+02:00" level=debug msg="app state loaded" Aug 31 15:56:11 bcik go-librespot[27092]: time="2026-08-31T15:56:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:56:11 bcik go-librespot[27092]: time="2026-08-31T15:56:11+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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 15:56:11 bcik go-librespot[27092]: time="2026-08-31T15:56:11+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:56:11 bcik go-librespot[27092]: time="2026-08-31T15:56:11+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:56:11 bcik go-librespot[27092]: time="2026-08-31T15:56:11+02:00" level=info msg="zeroconf server listening on port 33519" Aug 31 15:56:11 bcik go-librespot[27092]: time="2026-08-31T15:56:11+02:00" level=debug msg="obtained new client token: AAHxoQgkX4KCiVZ4wL9tZOL0g7avrK3VMaqY2g5OiOiil5IRNCTgNSVrTPgjOtvMnU9hU32yjBLCjme7LyPK0y0Di5jbdhOglNM0O2ofo901VKkd1nCpHwioCRBMh8Nw5pBy7V2jYO6phgim9P1XK60fC+SF2BNAsw7V2XEw751GOK6OgyJDpiJkYgfd+m8yu0mHbkzsr29e+y0XPXOtdkYbooqxS4/Yuwov1VrFM55ag3Czc70lRPo=" Aug 31 15:56:11 bcik go-librespot[27092]: time="2026-08-31T15:56:11+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:56:11 bcik go-librespot[27092]: time="2026-08-31T15:56:11+02:00" level=debug msg="completed keyexchange" Aug 31 15:56:11 bcik go-librespot[27092]: time="2026-08-31T15:56:11+02:00" level=debug msg="completed challenge" Aug 31 15:56:11 bcik go-librespot[27092]: time="2026-08-31T15:56:11+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:56:11 bcik go-librespot[27092]: time="2026-08-31T15:56:11+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:56:11 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:56:11 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:56:11 bcik volumio[26776]: info: Updating MyVolumio device info Aug 31 15:56:11 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:11 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:11 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:12 bcik volumio[26776]: info: Initializing connection to go-librespot Websocket Aug 31 15:56:12 bcik volumio[26776]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:56:12 bcik volumio[26776]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 15:56:15 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Aug 31 15:56:15 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:15 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:15 bcik go-librespot[27103]: go-librespot daemon starting... Aug 31 15:56:15 bcik go-librespot[27104]: time="2026-08-31T15:56:15+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:56:15 bcik go-librespot[27104]: time="2026-08-31T15:56:15+02:00" level=debug msg="app state loaded" Aug 31 15:56:15 bcik go-librespot[27104]: time="2026-08-31T15:56:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:56:15 bcik volumio[26776]: info: MYVOLUMIO: Adding device Aug 31 15:56:15 bcik volumio[26776]: info: MYVOLUMIO: Evaluating Server Aug 31 15:56:15 bcik go-librespot[27104]: time="2026-08-31T15:56:15+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:56:15 bcik go-librespot[27104]: time="2026-08-31T15:56:15+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:56:15 bcik go-librespot[27104]: time="2026-08-31T15:56:15+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:56:15 bcik go-librespot[27104]: time="2026-08-31T15:56:15+02:00" level=info msg="zeroconf server listening on port 33921" Aug 31 15:56:15 bcik go-librespot[27104]: time="2026-08-31T15:56:15+02:00" level=debug msg="obtained new client token: AAFVDXtySXuQgPA7xF8m9XW8j5ZJeVsPTKSDPVT2+i7KJxFF5X396q5NRO0EENCNkvJLFkkLIC2EBHhMqOUNvV2urS+zALSMGktTeHGnYLTdiHi0S+bu1/YThij5zfv2RHJuiJdkEekLg30B/040zVbgkfEF8Ull0fyFzonYd1tlN6lLqK09oSAngLag5tYFwnNi8p/G7U1jTtoh5RCH0OhF0GjlftOPGMjgihDQE9WV0+pA3rUCeWs=" Aug 31 15:56:15 bcik go-librespot[27104]: time="2026-08-31T15:56:15+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:56:15 bcik go-librespot[27104]: time="2026-08-31T15:56:15+02:00" level=debug msg="completed keyexchange" Aug 31 15:56:15 bcik go-librespot[27104]: time="2026-08-31T15:56:15+02:00" level=debug msg="completed challenge" Aug 31 15:56:15 bcik go-librespot[27104]: time="2026-08-31T15:56:15+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:56:15 bcik go-librespot[27104]: time="2026-08-31T15:56:15+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:56:15 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:56:15 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:56:15 bcik volumio[26776]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 15:56:15 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:15 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:15 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:15 bcik volumio[26776]: info: Initializing connection to go-librespot Websocket Aug 31 15:56:15 bcik volumio[26776]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:56:15 bcik volumio[26776]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 15:56:16 bcik volumio[26776]: info: Updating MyVolumio device info Aug 31 15:56:16 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:16 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:16 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:17 bcik volumio[26776]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 15:56:18 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Aug 31 15:56:18 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:18 bcik volumio[26776]: info: Initializing connection to go-librespot Websocket Aug 31 15:56:18 bcik volumio[26776]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:56:18 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:18 bcik go-librespot[27131]: go-librespot daemon starting... Aug 31 15:56:18 bcik go-librespot[27132]: time="2026-08-31T15:56:18+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:56:18 bcik go-librespot[27132]: time="2026-08-31T15:56:18+02:00" level=debug msg="app state loaded" Aug 31 15:56:18 bcik go-librespot[27132]: time="2026-08-31T15:56:18+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:56:18 bcik go-librespot[27132]: time="2026-08-31T15:56:18+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 31 15:56:18 bcik go-librespot[27132]: time="2026-08-31T15:56:18+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 31 15:56:18 bcik go-librespot[27132]: time="2026-08-31T15:56:18+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 31 15:56:18 bcik go-librespot[27132]: time="2026-08-31T15:56:18+02:00" level=info msg="zeroconf server listening on port 42943" Aug 31 15:56:18 bcik go-librespot[27132]: time="2026-08-31T15:56:18+02:00" level=debug msg="obtained new client token: AAF27swUb1thBdTRuBkGYtjJYq+YUjVpJigFjC4B7fTd6SItB5mWJkJm2+wPg2gv0YscRlpIihy2MzxQfO0EthYlOTnVonjcRGKUlNID7YPipG5sngmf7IyO9qdfR1GLpt0ECuc7EEot7N1M9CWuZSOmBU6+S4SWPcYYIukEQD/05hTfTs6d62S+CFmhCnw3cfxCA5pHdKF2HNqdWedx+DSqNs3aSOeeEobpJL+DZ9KztEJBtcFBldc=" Aug 31 15:56:18 bcik go-librespot[27132]: time="2026-08-31T15:56:18+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:56:19 bcik go-librespot[27132]: time="2026-08-31T15:56:19+02:00" level=debug msg="completed keyexchange" Aug 31 15:56:19 bcik go-librespot[27132]: time="2026-08-31T15:56:19+02:00" level=debug msg="completed challenge" Aug 31 15:56:19 bcik go-librespot[27132]: time="2026-08-31T15:56:19+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:56:19 bcik go-librespot[27132]: time="2026-08-31T15:56:19+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:56:19 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:56:19 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:56:21 bcik volumio[26776]: info: Initializing connection to go-librespot Websocket Aug 31 15:56:21 bcik volumio[26776]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:56:22 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Aug 31 15:56:22 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:22 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:22 bcik go-librespot[27155]: go-librespot daemon starting... Aug 31 15:56:22 bcik go-librespot[27156]: time="2026-08-31T15:56:22+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:56:22 bcik go-librespot[27156]: time="2026-08-31T15:56:22+02:00" level=debug msg="app state loaded" Aug 31 15:56:22 bcik go-librespot[27156]: time="2026-08-31T15:56:22+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:56:22 bcik go-librespot[27156]: time="2026-08-31T15:56:22+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 31 15:56:22 bcik go-librespot[27156]: time="2026-08-31T15:56:22+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 31 15:56:22 bcik go-librespot[27156]: time="2026-08-31T15:56:22+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 31 15:56:22 bcik go-librespot[27156]: time="2026-08-31T15:56:22+02:00" level=info msg="zeroconf server listening on port 36553" Aug 31 15:56:22 bcik go-librespot[27156]: time="2026-08-31T15:56:22+02:00" level=debug msg="obtained new client token: AAEpvxivYkrMWl9cn41yCUx+QVW0cqgZGVZMgHQzyfAFnz8eFmHQl/ho8PC7jXX+TE/tTmrTASEaI4PEOKSwlL51XSe/PMXkHNyU3xQv03RwH5RW/mjqdh5wJBmbKkvmTNH7ezQiYvuDyLQyC5s7biwF2IDu38jGkot5zJLhliEhH4ZV2GlepfUfkgC3wNMWveQ0qgcKXVt/LHrfCChx4m2oaptRiz8+a6OGvCjQ1ssYGzm6dKlP8kY=" Aug 31 15:56:22 bcik go-librespot[27156]: time="2026-08-31T15:56:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:56:22 bcik go-librespot[27156]: time="2026-08-31T15:56:22+02:00" level=debug msg="completed keyexchange" Aug 31 15:56:22 bcik go-librespot[27156]: time="2026-08-31T15:56:22+02:00" level=debug msg="completed challenge" Aug 31 15:56:22 bcik go-librespot[27156]: time="2026-08-31T15:56:22+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:56:22 bcik go-librespot[27156]: time="2026-08-31T15:56:22+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:56:22 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:56:22 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:56:24 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 31 15:56:24 bcik volumio[26776]: 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 31 15:56:24 bcik volumio[26776]: info: CoreCommandRouter::volumioGetState Aug 31 15:56:24 bcik volumio[26776]: info: CorePlayQueue::getTrack 0 Aug 31 15:56:24 bcik volumio[26776]: info: Initializing connection to go-librespot Websocket Aug 31 15:56:24 bcik volumio[26776]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:56:25 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Aug 31 15:56:25 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:25 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:25 bcik go-librespot[27166]: go-librespot daemon starting... Aug 31 15:56:25 bcik go-librespot[27167]: time="2026-08-31T15:56:25+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:56:25 bcik go-librespot[27167]: time="2026-08-31T15:56:25+02:00" level=debug msg="app state loaded" Aug 31 15:56:25 bcik go-librespot[27167]: time="2026-08-31T15:56:25+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:56:25 bcik go-librespot[27167]: time="2026-08-31T15:56:25+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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 15:56:25 bcik go-librespot[27167]: time="2026-08-31T15:56:25+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:56:25 bcik go-librespot[27167]: time="2026-08-31T15:56:25+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:56:25 bcik go-librespot[27167]: time="2026-08-31T15:56:25+02:00" level=info msg="zeroconf server listening on port 39029" Aug 31 15:56:25 bcik go-librespot[27167]: time="2026-08-31T15:56:25+02:00" level=debug msg="obtained new client token: AAHqGkBtaZJDSABQ8LJUe+hdI+25FBGFU9DtJnrBTWos6cKDebMujDLJv1nON/qaOT+p9kX7i5OflBLiXlpZZO/MfLjpPr4LaRFdq/ZiZ/LIG9rlYhuGwIcoGjCVWe68kp61/swk4ieEkxtVz5vrx93P5Mub8V+DNPnc+8XnDoIhhrESWUws2l9a3UW7zStNDgdAbB0CEMeGFlO6ds+OBgHvdM6CgBQueTF0X9y8bnxE+G1NtxeNl/k=" Aug 31 15:56:25 bcik go-librespot[27167]: time="2026-08-31T15:56:25+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:56:26 bcik go-librespot[27167]: time="2026-08-31T15:56:26+02:00" level=debug msg="completed keyexchange" Aug 31 15:56:26 bcik go-librespot[27167]: time="2026-08-31T15:56:26+02:00" level=debug msg="completed challenge" Aug 31 15:56:26 bcik go-librespot[27167]: time="2026-08-31T15:56:26+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:56:26 bcik go-librespot[27167]: time="2026-08-31T15:56:26+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:56:26 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:56:26 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:56:27 bcik volumio[26776]: info: Initializing connection to go-librespot Websocket Aug 31 15:56:27 bcik volumio[26776]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:56:29 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Aug 31 15:56:29 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:29 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:29 bcik go-librespot[27176]: go-librespot daemon starting... Aug 31 15:56:29 bcik go-librespot[27177]: time="2026-08-31T15:56:29+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:56:29 bcik go-librespot[27177]: time="2026-08-31T15:56:29+02:00" level=debug msg="app state loaded" Aug 31 15:56:29 bcik go-librespot[27177]: time="2026-08-31T15:56:29+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:56:29 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:29 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:29 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 31 15:56:29 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 31 15:56:29 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 31 15:56:29 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 31 15:56:29 bcik volumio[26776]: info: CoreCommandRouter::volumioGetBrowseSources Aug 31 15:56:29 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:56:29 bcik go-librespot[27177]: time="2026-08-31T15:56:29+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:56:29 bcik go-librespot[27177]: time="2026-08-31T15:56:29+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:56:29 bcik go-librespot[27177]: time="2026-08-31T15:56:29+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:56:29 bcik go-librespot[27177]: time="2026-08-31T15:56:29+02:00" level=info msg="zeroconf server listening on port 37609" Aug 31 15:56:29 bcik go-librespot[27177]: time="2026-08-31T15:56:29+02:00" level=debug msg="obtained new client token: AAEM6KyKvp/oukvvLaQO6IJ1NNSP3rEbgAZMxIeWTfLPyFxXFZfkIK4IHbXQ0fhyESegHiK5FMb9i+ned7kCM3V3zkhokJnCnJ83iKtn0FbI/ydx9r6mnpmeYIxOJgWvGMQZWMkZRmouY5q45eKTRriO7OgNSQ7K7OKWAFjy8z8pBssvG16KIZzdeVUjjljhSOluH6floEVgTeZeKoAzzEkJ/b5qRAJS08ZtddbLV9qQRW9IwiNQHvQ=" Aug 31 15:56:29 bcik go-librespot[27177]: time="2026-08-31T15:56:29+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:56:29 bcik go-librespot[27177]: time="2026-08-31T15:56:29+02:00" level=debug msg="completed keyexchange" Aug 31 15:56:29 bcik go-librespot[27177]: time="2026-08-31T15:56:29+02:00" level=debug msg="completed challenge" Aug 31 15:56:29 bcik volumio[26776]: error: MyVolumio Plugin failed to authenticate in a timely fashion Aug 31 15:56:29 bcik volumio[26776]: info: Completed starting MyVolumio Plugin Aug 31 15:56:29 bcik volumio[26776]: [Metrics] CommandRouter: 30s 638.08ms Aug 31 15:56:29 bcik volumio[26776]: info: CoreCommandRouter::volumiosetStartupVolume Aug 31 15:56:29 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:29 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:29 bcik go-librespot[27177]: time="2026-08-31T15:56:29+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:56:29 bcik volumio[26776]: info: CoreCommandRouter::Close All Modals sent Aug 31 15:56:29 bcik volumio[26776]: info: CoreCommandRouter::Close All Modals sent Aug 31 15:56:29 bcik go-librespot[27177]: time="2026-08-31T15:56:29+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:56:29 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:56:29 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:56:30 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 31 15:56:30 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 31 15:56:30 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 31 15:56:30 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:56:30 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:30 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 31 15:56:30 bcik volumio-remote-updater[962]: Test mode disabled Aug 31 15:56:30 bcik volumio-remote-updater[962]: Alpha mode disabled Aug 31 15:56:30 bcik volumio-remote-updater[962]: Alpha legacy test mode disabled Aug 31 15:56:30 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 31 15:56:30 bcik volumio[26776]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 31 15:56:30 bcik volumio[26776]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 31 15:56:30 bcik volumio[26776]: info: Initializing connection to go-librespot Websocket Aug 31 15:56:30 bcik volumio[26776]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:56:32 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Aug 31 15:56:32 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:32 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:32 bcik go-librespot[27207]: go-librespot daemon starting... Aug 31 15:56:32 bcik go-librespot[27208]: time="2026-08-31T15:56:32+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:56:32 bcik go-librespot[27208]: time="2026-08-31T15:56:32+02:00" level=debug msg="app state loaded" Aug 31 15:56:32 bcik go-librespot[27208]: time="2026-08-31T15:56:32+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:56:32 bcik go-librespot[27208]: time="2026-08-31T15:56:32+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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:56:32 bcik go-librespot[27208]: time="2026-08-31T15:56:32+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:56:32 bcik go-librespot[27208]: time="2026-08-31T15:56:32+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:56:32 bcik go-librespot[27208]: time="2026-08-31T15:56:32+02:00" level=info msg="zeroconf server listening on port 34777" Aug 31 15:56:32 bcik go-librespot[27208]: time="2026-08-31T15:56:32+02:00" level=debug msg="obtained new client token: AAFHqTH4ZNbCbH0Wv9otVLx/SinRBw67wvBUojIzkOjbq4Xm0BPp1ePTYx7S7E7+FTUVAwFar72h43dCvp1e0o36Lze3l09JmyZ8MpAKyFJ9TMEvZdaxLGQc4hEWKl0BERuaZKRNd4Vmo4Zvkk5CBqSbuI5yb38Myt/LrTiIHfe+yu6DrGz/oxD/VbjSs8jodwh5ifCHOuFSoNUClrzV1k1SN4jAbXLkWqjuFJrp87MMKjh1cLEknYk=" Aug 31 15:56:32 bcik go-librespot[27208]: time="2026-08-31T15:56:32+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:56:32 bcik go-librespot[27208]: time="2026-08-31T15:56:32+02:00" level=debug msg="completed keyexchange" Aug 31 15:56:32 bcik go-librespot[27208]: time="2026-08-31T15:56:32+02:00" level=debug msg="completed challenge" Aug 31 15:56:33 bcik go-librespot[27208]: time="2026-08-31T15:56:33+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:56:33 bcik go-librespot[27208]: time="2026-08-31T15:56:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:56:33 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:56:33 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:56:33 bcik volumio[26776]: info: Initializing connection to go-librespot Websocket Aug 31 15:56:33 bcik volumio[26776]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:56:36 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Aug 31 15:56:36 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:36 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:36 bcik go-librespot[27217]: go-librespot daemon starting... Aug 31 15:56:36 bcik go-librespot[27218]: time="2026-08-31T15:56:36+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:56:36 bcik go-librespot[27218]: time="2026-08-31T15:56:36+02:00" level=debug msg="app state loaded" Aug 31 15:56:36 bcik go-librespot[27218]: time="2026-08-31T15:56:36+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:56:36 bcik go-librespot[27218]: time="2026-08-31T15:56:36+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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:56:36 bcik go-librespot[27218]: time="2026-08-31T15:56:36+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:56:36 bcik go-librespot[27218]: time="2026-08-31T15:56:36+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:56:36 bcik go-librespot[27218]: time="2026-08-31T15:56:36+02:00" level=info msg="zeroconf server listening on port 44725" Aug 31 15:56:36 bcik go-librespot[27218]: time="2026-08-31T15:56:36+02:00" level=debug msg="obtained new client token: AAEwAlQQ2p+ibV2B3/YrJGODynO38RNKS/nhBt/av0aMc89hkU6Mmeob78U9sBrWjDzM4kTrtlNSltouQ5kIQDvGegd1zaptR3D3SMM//90gHDGMki29fyqojTqZsVZPjOjgMxb2ECvnejoVvzfWfaaDhJbSU3XfGt2cBlWC0p+IHceW86XIXPykXul/6k/g8OYXs2eKyKu5SxskEtDMKG5hrPG855JouCUtnLS5vtKb4ijFez7/LQo=" Aug 31 15:56:36 bcik go-librespot[27218]: time="2026-08-31T15:56:36+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:56:36 bcik go-librespot[27218]: time="2026-08-31T15:56:36+02:00" level=debug msg="completed keyexchange" Aug 31 15:56:36 bcik go-librespot[27218]: time="2026-08-31T15:56:36+02:00" level=debug msg="completed challenge" Aug 31 15:56:36 bcik go-librespot[27218]: time="2026-08-31T15:56:36+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:56:36 bcik volumio[26776]: info: BOOT COMPLETED Aug 31 15:56:36 bcik go-librespot[27218]: time="2026-08-31T15:56:36+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:56:36 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:56:36 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:56:36 bcik volumio[26776]: info: Initializing connection to go-librespot Websocket Aug 31 15:56:36 bcik volumio[26776]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:56:39 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Aug 31 15:56:39 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:39 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:39 bcik go-librespot[27243]: go-librespot daemon starting... Aug 31 15:56:39 bcik go-librespot[27244]: time="2026-08-31T15:56:39+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:56:39 bcik go-librespot[27244]: time="2026-08-31T15:56:39+02:00" level=debug msg="app state loaded" Aug 31 15:56:39 bcik go-librespot[27244]: time="2026-08-31T15:56:39+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:56:39 bcik volumio[26776]: info: Initializing connection to go-librespot Websocket Aug 31 15:56:39 bcik go-librespot[27244]: time="2026-08-31T15:56:39+02:00" level=debug msg="new websocket client" Aug 31 15:56:39 bcik volumio[26776]: info: Connection to go-librespot Websocket established Aug 31 15:56:39 bcik go-librespot[27244]: time="2026-08-31T15:56:39+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 31 15:56:39 bcik go-librespot[27244]: time="2026-08-31T15:56:39+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 31 15:56:39 bcik go-librespot[27244]: time="2026-08-31T15:56:39+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 31 15:56:39 bcik go-librespot[27244]: time="2026-08-31T15:56:39+02:00" level=info msg="zeroconf server listening on port 36555" Aug 31 15:56:39 bcik go-librespot[27244]: time="2026-08-31T15:56:39+02:00" level=debug msg="obtained new client token: AAFbEHvVJfKsE8ztYW+fxaXjecxIYoF7gkvRaL8/SfMsGBbaNebJI/u9/SyQ4S87pl23q8GKmjsWfJ6ZeGyD8/8PpEvzrNlq02Ikdx+b0Ou12UHEGyPQtmFu8lj+foMWDecYQBEUro/4Ikdz0FxlHIHKOlFuhWlPYzp8oLQFFtkS5fd2ctXeAAB+8rmUU4VvuC+3+vIWfMcp7pNCvHxshZL5CoFWyhsGenwAcesG0EUCaHFjvnK5rQY=" Aug 31 15:56:39 bcik go-librespot[27244]: time="2026-08-31T15:56:39+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:56:39 bcik go-librespot[27244]: time="2026-08-31T15:56:39+02:00" level=debug msg="completed keyexchange" Aug 31 15:56:39 bcik go-librespot[27244]: time="2026-08-31T15:56:39+02:00" level=debug msg="completed challenge" Aug 31 15:56:40 bcik go-librespot[27244]: time="2026-08-31T15:56:40+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:56:40 bcik go-librespot[27244]: time="2026-08-31T15:56:40+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:56:40 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:56:40 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:56:40 bcik volumio[26776]: info: Connection to go-librespot Websocket closed Aug 31 15:56:42 bcik volumio[26776]: info: Getting Spotify volume Aug 31 15:56:42 bcik volumio[26776]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 15:56:42 bcik volumio[26776]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:56:42 bcik volumio[26776]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 31 15:56:42 bcik volumio[26776]: errno: -111, Aug 31 15:56:42 bcik volumio[26776]: code: 'ECONNREFUSED', Aug 31 15:56:42 bcik volumio[26776]: syscall: 'connect', Aug 31 15:56:42 bcik volumio[26776]: address: '127.0.0.1', Aug 31 15:56:42 bcik volumio[26776]: port: 9879, Aug 31 15:56:42 bcik volumio[26776]: response: undefined Aug 31 15:56:42 bcik volumio[26776]: } Aug 31 15:56:42 bcik volumio[26776]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 15:56:43 bcik sudo[27267]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 15:55' Aug 31 15:56:43 bcik sudo[27267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:43 bcik sudo[27267]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:43 bcik volumio-remote-updater[962]: [2026-08-31 15:56:43] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 31 15:56:43 bcik volumio-remote-updater[962]: [2026-08-31 15:56:43] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 31 15:56:43 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:56:43 bcik volumio5-onboarding[1666]: time=2026-08-31T15:56:43.086+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Aug 31 15:56:43 bcik volumio5-onboarding[1666]: time=2026-08-31T15:56:43.087+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 31 15:56:43 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 31 15:56:43 bcik systemd[1]: volumio.service: Consumed 6.654s CPU time. Aug 31 15:56:43 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 31 15:56:43 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Aug 31 15:56:43 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Aug 31 15:56:43 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 241. Aug 31 15:56:43 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 31 15:56:43 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:43 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Aug 31 15:56:43 bcik systemd[1]: volumio.service: Consumed 6.654s CPU time. Aug 31 15:56:43 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Aug 31 15:56:43 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:43 bcik go-librespot[27286]: go-librespot daemon starting... Aug 31 15:56:43 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Aug 31 15:56:43 bcik go-librespot[27288]: time="2026-08-31T15:56:43+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:56:43 bcik go-librespot[27288]: time="2026-08-31T15:56:43+02:00" level=debug msg="app state loaded" Aug 31 15:56:43 bcik go-librespot[27288]: time="2026-08-31T15:56:43+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:56:43 bcik go-librespot[27288]: time="2026-08-31T15:56:43+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:56:43 bcik go-librespot[27288]: time="2026-08-31T15:56:43+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:56:43 bcik go-librespot[27288]: time="2026-08-31T15:56:43+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:56:43 bcik go-librespot[27288]: time="2026-08-31T15:56:43+02:00" level=info msg="zeroconf server listening on port 42749" Aug 31 15:56:43 bcik go-librespot[27288]: time="2026-08-31T15:56:43+02:00" level=debug msg="obtained new client token: AAHggQQcRY2qich/yr21ELJXgvTEzlDLHdTj4Vh7EGJrm37rd4PlWlcY4A6AmW+/N0prUIgrOCMsiWszM89o7Irs+tUmsO2vG86EJ2EO+9J1QBZPNeFhy2kSLPcxBaTMXQziGbpJ0FdblT85lp3dnvbisWpZ0glXmIZgjXthoFsgosXZkKECwQw49Jm++REtgVCgtpRz4zOqzEfjDm4XVuVXMd+fM+uA8/nJpS/F7OkseIrIjD5OCvo=" Aug 31 15:56:43 bcik go-librespot[27288]: time="2026-08-31T15:56:43+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:56:43 bcik go-librespot[27288]: time="2026-08-31T15:56:43+02:00" level=debug msg="completed keyexchange" Aug 31 15:56:43 bcik go-librespot[27288]: time="2026-08-31T15:56:43+02:00" level=debug msg="completed challenge" Aug 31 15:56:43 bcik volumio[27282]: info: ------------------------------------------- Aug 31 15:56:43 bcik volumio[27282]: info: ----- Volumio3 ---- Aug 31 15:56:43 bcik volumio[27282]: info: ------------------------------------------- Aug 31 15:56:43 bcik volumio[27282]: info: ----- System startup ---- Aug 31 15:56:43 bcik volumio[27282]: info: ------------------------------------------- Aug 31 15:56:43 bcik go-librespot[27288]: time="2026-08-31T15:56:43+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:56:43 bcik go-librespot[27288]: time="2026-08-31T15:56:43+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:56:43 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:56:43 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:56:43 bcik volumio[27282]: info: MYVOLUMIO Environment detected Aug 31 15:56:43 bcik volumio[27282]: info: Plugin folders cleanup Aug 31 15:56:43 bcik volumio[27282]: info: Scanning into folder /volumio/app/plugins/ Aug 31 15:56:43 bcik volumio[27282]: info: Scanning category audio_interface Aug 31 15:56:43 bcik volumio[27282]: info: Scanning category miscellanea Aug 31 15:56:43 bcik volumio[27282]: info: Scanning category music_service Aug 31 15:56:43 bcik volumio[27282]: info: Scanning category plugins.json Aug 31 15:56:43 bcik volumio[27282]: info: Scanning category system_controller Aug 31 15:56:43 bcik volumio[27282]: info: Scanning category user_interface Aug 31 15:56:43 bcik volumio[27282]: info: Scanning into folder /data/plugins/ Aug 31 15:56:43 bcik volumio[27282]: info: Scanning category music_service Aug 31 15:56:43 bcik volumio[27282]: info: Plugin folders cleanup completed Aug 31 15:56:43 bcik volumio[27282]: info: ------------------------------------------- Aug 31 15:56:43 bcik volumio[27282]: info: ----- Core plugins startup ---- Aug 31 15:56:43 bcik volumio[27282]: info: ------------------------------------------- Aug 31 15:56:43 bcik volumio[27282]: info: Loading plugins from folder /volumio/app/plugins/ Aug 31 15:56:43 bcik volumio[27282]: info: Adding plugin upnp to MyMusic Plugins Aug 31 15:56:43 bcik volumio[27282]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 31 15:56:43 bcik volumio[27282]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 31 15:56:43 bcik volumio[27282]: info: Loading plugins from folder /data/plugins/ Aug 31 15:56:43 bcik volumio[27282]: info: Loading plugin "system"... Aug 31 15:56:43 bcik volumio[27282]: info: Loading plugin "appearance"... Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "network"... Aug 31 15:56:44 bcik volumio[27282]: info: Refreshing Cached IP Addresses Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "services"... Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "volumio5onboarding"... Aug 31 15:56:44 bcik sudo[27322]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 15:56:44 bcik sudo[27322]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:44 bcik sudo[27320]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 15:56:44 bcik sudo[27322]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:44 bcik sudo[27320]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "alsa_controller"... Aug 31 15:56:44 bcik sudo[27320]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "wizard"... Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "networkfs"... Aug 31 15:56:44 bcik volumio[27282]: info: Starting Udev Watcher for removable devices Aug 31 15:56:44 bcik volumio[27282]: info: Ignoring mount for partition: boot Aug 31 15:56:44 bcik volumio[27282]: info: Ignoring mount for partition: volumio Aug 31 15:56:44 bcik volumio[27282]: info: Ignoring mount for partition: volumio_data Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "volumio_command_line_client"... Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "upnp"... Aug 31 15:56:44 bcik volumio[27282]: info: [1788184604078] Starting Upmpd Daemon Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "my_music"... Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "mpd"... Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "upnp_browser"... Aug 31 15:56:44 bcik volumio[27282]: info: Starting UPNP Browser Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "alarm-clock"... Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "airplay_emulation"... Aug 31 15:56:44 bcik volumio[27282]: info: Starting Shairport Sync Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "last_100"... Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "webradio"... Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "i2s_dacs"... Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "volumiodiscovery"... Aug 31 15:56:44 bcik volumio[27282]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 15:56:44 bcik volumio[27282]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:56:44 bcik volumio[27282]: *** WARNING *** For more information see Aug 31 15:56:44 bcik volumio[27282]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 15:56:44 bcik volumio[27282]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:56:44 bcik volumio[27282]: *** WARNING *** For more information see Aug 31 15:56:44 bcik volumio[27282]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 31 15:56:44 bcik volumio[27282]: info: Discovery: Started advertising with name: Bącik Aug 31 15:56:44 bcik node[27282]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 15:56:44 bcik node[27282]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:56:44 bcik node[27282]: *** WARNING *** For more information see Aug 31 15:56:44 bcik node[27282]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 15:56:44 bcik node[27282]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:56:44 bcik node[27282]: *** WARNING *** For more information see Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "spop"... Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "outputs"... Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "albumart"... Aug 31 15:56:44 bcik volumio[27282]: info: Plugin example_plugin is not enabled Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "inputs"... Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "updater_comm"... Aug 31 15:56:44 bcik volumio[27282]: info: Plugin mpdemulation is not enabled Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "rest_api"... Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "websocket"... Aug 31 15:56:44 bcik volumio[27282]: info: Starting Socket.io Server version 1.7.4 Aug 31 15:56:44 bcik volumio[27282]: info: Loading plugin "radio_browser"... Aug 31 15:56:44 bcik volumio[27354]: Forking 3 albumart workers Aug 31 15:56:44 bcik volumio[27282]: info: Loading i18n strings for locale pl Aug 31 15:56:44 bcik volumio[27282]: Updating browse sources language Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::initPlayerControls Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:56:44 bcik volumio[27282]: Express server listening on port 3000 Aug 31 15:56:44 bcik volumio[27282]: [Metrics] WebUI: 1s 299.27ms Aug 31 15:56:44 bcik volumio[27282]: info: CoreStateMachine::resetVolumioState Aug 31 15:56:44 bcik volumio[27282]: info: CoreStateMachine::getcurrentVolume Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 15:56:44 bcik volumio[27282]: info: Volumio Network Manager: Network status updated: 1 Aug 31 15:56:44 bcik volumio[27282]: 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: 1 Aug 31 15:56:44 bcik volumio[27282]: 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: 1 Aug 31 15:56:44 bcik volumio[27282]: info: VolumeController:: Volume=53 Mute =false Aug 31 15:56:44 bcik volumio[27282]: info: CoreStateMachine::pushState Aug 31 15:56:44 bcik volumio[27282]: info: CorePlayQueue::getTrack 0 Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::volumioPushState Aug 31 15:56:44 bcik volumio[27282]: info: CoreStateMachine::updateTrackBlock Aug 31 15:56:44 bcik volumio[27282]: info: CorePlayQueue::getTrackBlock Aug 31 15:56:44 bcik volumio[27282]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: Reloading queue from file Aug 31 15:56:45 bcik volumio[27282]: info: CoreStateMachine::setRepeat false single undefined Aug 31 15:56:45 bcik volumio[27282]: info: CoreStateMachine::pushState Aug 31 15:56:45 bcik volumio[27282]: info: CorePlayQueue::getTrack 0 Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::volumioPushState Aug 31 15:56:45 bcik volumio[27282]: info: CoreStateMachine::setRandom false Aug 31 15:56:45 bcik volumio[27282]: info: CoreStateMachine::pushState Aug 31 15:56:45 bcik volumio[27282]: info: CorePlayQueue::getTrack 0 Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::volumioPushState Aug 31 15:56:45 bcik volumio[27282]: 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: 1 Aug 31 15:56:45 bcik volumio[27282]: info: Setting Device type: Raspberry PI Aug 31 15:56:45 bcik volumio[27282]: info: Completed loading Core Plugins Aug 31 15:56:45 bcik volumio[27282]: info: Preparing to generate the ALSA configuration file Aug 31 15:56:45 bcik volumio[27282]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 31 15:56:45 bcik volumio[27282]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Aug 31 15:56:45 bcik volumio[27282]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 31 15:56:45 bcik volumio[27282]: 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: 1 Aug 31 15:56:45 bcik volumio[27282]: info: VolumeController:: Volume=53 Mute =false Aug 31 15:56:45 bcik volumio[27282]: info: CoreStateMachine::pushState Aug 31 15:56:45 bcik volumio[27282]: info: CorePlayQueue::getTrack 0 Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::volumioPushState Aug 31 15:56:45 bcik volumio[27282]: 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: 1 Aug 31 15:56:45 bcik volumio[27282]: 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: 1 Aug 31 15:56:45 bcik volumio[27282]: info: Asound.conf file unchanged, so no further update is needed Aug 31 15:56:45 bcik volumio[27282]: info: Output device has changed, restarting MPD Aug 31 15:56:45 bcik volumio[27282]: info: Output device has changed, restarting Shairport Sync Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:45 bcik sudo[27410]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 15:56:45 bcik volumio[27365]: Starting albumart workers Aug 31 15:56:45 bcik sudo[27410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:45 bcik volumio[27364]: Starting albumart workers Aug 31 15:56:45 bcik sudo[27410]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:45 bcik sudo[27412]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 15:56:45 bcik sudo[27412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:45 bcik volumio[27366]: Starting albumart workers Aug 31 15:56:45 bcik volumio[27282]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:56:45 bcik volumio[27282]: info: ___________ START PLUGINS ___________ Aug 31 15:56:45 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 31 15:56:45 bcik volumio[27282]: info: ControllerMpd::onStart: Initializing MPD Aug 31 15:56:45 bcik volumio[27282]: info: Creating MPD Configuration file Aug 31 15:56:45 bcik sudo[27420]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 31 15:56:45 bcik sudo[27420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:45 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:56:45 bcik volumio[27282]: info: [1788184605126] CoreMusicLibrary::Adding element Serwery Mediów Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:56:45 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 15:56:45 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 15:56:45 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 15:56:45 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 15:56:45 bcik sudo[27422]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 15:56:45 bcik sudo[27422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:45 bcik volumio[27282]: info: UPNP Browser: Client initialized successfully Aug 31 15:56:45 bcik sudo[27425]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 15:56:45 bcik sudo[27425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:45 bcik sudo[27422]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:45 bcik volumio[27282]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:56:45 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 15:56:45 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:56:45 bcik volumio[27282]: info: [1788184605186] CoreMusicLibrary::Adding element Last_100 Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:56:45 bcik sudo[27420]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:56:45 bcik volumio[27282]: info: [1788184605187] CoreMusicLibrary::Adding element Webradio Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:56:45 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:56:45 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 15:56:45 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 15:56:45 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 15:56:45 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 15:56:45 bcik volumio[27282]: info: Initializing BBC Radios Aug 31 15:56:45 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 15:56:45 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: Creating Spotify config file Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik sudo[27440]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 15:56:45 bcik sudo[27440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 31 15:56:45 bcik sudo[27440]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:56:45 bcik volumio[27282]: info: [1788184605358] CoreMusicLibrary::Adding element Radio Browser Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:56:45 bcik volumio[27282]: Cannot find translation for source Radio Browser Aug 31 15:56:45 bcik volumio[27282]: info: Volumio Calling Home Aug 31 15:56:45 bcik volumio[27282]: 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: 1 Aug 31 15:56:45 bcik volumio[27282]: info: MPD Permissions set Aug 31 15:56:45 bcik volumio[27282]: info: MPD Permissions set Aug 31 15:56:45 bcik volumio[27282]: info: Spotify config file written Aug 31 15:56:45 bcik volumio[27282]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 31 15:56:45 bcik sudo[27477]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 15:56:45 bcik sudo[27477]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:56:45 bcik volumio[27282]: info: No need to fix Spotify hosts Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: info: Volumio called home Aug 31 15:56:45 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik go-librespot[27484]: go-librespot daemon starting... Aug 31 15:56:45 bcik sudo[27477]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:45 bcik volumio[27282]: info: Starting Shairport Sync Aug 31 15:56:45 bcik volumio[27282]: info: Starting Shairport Sync Aug 31 15:56:45 bcik volumio[27282]: info: Starting Shairport Sync Aug 31 15:56:45 bcik go-librespot[27490]: time="2026-08-31T15:56:45+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:56:45 bcik go-librespot[27490]: time="2026-08-31T15:56:45+02:00" level=debug msg="app state loaded" Aug 31 15:56:45 bcik go-librespot[27490]: time="2026-08-31T15:56:45+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:56:45 bcik sudo[27493]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:56:45 bcik sudo[27493]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:45 bcik sudo[27501]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:56:45 bcik sudo[27501]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:45 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 31 15:56:45 bcik sudo[27499]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:56:45 bcik sudo[27499]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:45 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Aug 31 15:56:45 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:56:45 bcik systemd[1]: shairport-sync.service: Consumed 1.557s CPU time. Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:56:45 bcik sudo[27493]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:45 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Aug 31 15:56:45 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::volumioGetState Aug 31 15:56:45 bcik volumio[27282]: info: CorePlayQueue::getTrack 0 Aug 31 15:56:45 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:56:45 bcik volumio[27282]: info: Shairport-Sync Started Aug 31 15:56:45 bcik sudo[27501]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:45 bcik sudo[27499]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:45 bcik volumio[27282]: Error adding Membership: Error: addMembership EINVAL Aug 31 15:56:45 bcik volumio[27282]: info: Shairport-Sync Started Aug 31 15:56:45 bcik go-librespot[27490]: time="2026-08-31T15:56:45+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 31 15:56:45 bcik go-librespot[27490]: time="2026-08-31T15:56:45+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 31 15:56:45 bcik go-librespot[27490]: time="2026-08-31T15:56:45+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 31 15:56:45 bcik go-librespot[27490]: time="2026-08-31T15:56:45+02:00" level=info msg="zeroconf server listening on port 45441" Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: info: Shairport-Sync Started Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: info: An error occurred while refreshing Spotify Token Error: Bad Request Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 15:56:45 bcik volumio[27282]: info: Discovery: Found device Bącik Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::volumioGetState Aug 31 15:56:45 bcik volumio[27282]: info: CorePlayQueue::getTrack 0 Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 15:56:45 bcik volumio[27282]: info: Discovery: Found device Bącik Aug 31 15:56:45 bcik volumio[27282]: info: CoreCommandRouter::volumioGetState Aug 31 15:56:45 bcik volumio[27282]: info: CorePlayQueue::getTrack 0 Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik go-librespot[27490]: time="2026-08-31T15:56:45+02:00" level=debug msg="obtained new client token: AAFQXZqRXpP54IMMqzug/EdnL+KQwhdY5ABKwlKepg+NNIsbzj5yQxZ44xcLiOatkt99aDMSTLgaecWQjifWRUHboMyZFMYvfYRzQNGZ9RbKiOBMPpe8HXiPxULToXVAENlC8WdK6UeiTbiR+jy8e0wBtlooHRW0hGQ93BN4wks1k9do+cuKM7s8PWcpDwQ19rAcfAZcM124ql123mZNJSo6gj5nSVSOuJMNQBoCmfvL1UEH14yVZaI=" Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik volumio[27282]: 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: 2 Aug 31 15:56:45 bcik go-librespot[27490]: time="2026-08-31T15:56:45+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:56:45 bcik go-librespot[27490]: time="2026-08-31T15:56:45+02:00" level=debug msg="completed keyexchange" Aug 31 15:56:45 bcik go-librespot[27490]: time="2026-08-31T15:56:45+02:00" level=debug msg="completed challenge" Aug 31 15:56:45 bcik go-librespot[27490]: time="2026-08-31T15:56:45+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:56:45 bcik mpd[27454]: 2026-08-31T15:56:45 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 15:56:45 bcik systemd[1]: Started mpd.service - Music Player Daemon. Aug 31 15:56:45 bcik sudo[27412]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:45 bcik sudo[27425]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:45 bcik volumio[27282]: info: Completed starting Core Plugins Aug 31 15:56:45 bcik volumio[27282]: info: ------------------------------------------- Aug 31 15:56:45 bcik volumio[27282]: info: ----- MyVolumio plugins startup ---- Aug 31 15:56:45 bcik volumio[27282]: info: ------------------------------------------- Aug 31 15:56:45 bcik volumio[27282]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 31 15:56:45 bcik volumio[27282]: error: MPD error: The expression evaluated to a falsy value: Aug 31 15:56:45 bcik volumio[27282]: assert.ok(self.idling) Aug 31 15:56:45 bcik volumio[27282]: error: The expression evaluated to a falsy value: Aug 31 15:56:45 bcik volumio[27282]: assert.ok(self.idling) Aug 31 15:56:45 bcik volumio[27282]: info: MPD running with PID27454 Aug 31 15:56:45 bcik volumio[27282]: ,establishing connection Aug 31 15:56:45 bcik go-librespot[27490]: time="2026-08-31T15:56:45+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:56:45 bcik volumio[27282]: error: updateQueue error: null Aug 31 15:56:45 bcik volumio[27282]: error: updateQueue error: null Aug 31 15:56:45 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:56:45 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:56:48 bcik volumio-remote-updater[962]: [2026-08-31 15:56:48] [connect] Successful connection Aug 31 15:56:48 bcik volumio-remote-updater[962]: [2026-08-31 15:56:48] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788184608 101 Aug 31 15:56:48 bcik volumio[27282]: 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: 3 Aug 31 15:56:48 bcik volumio[27282]: info: go-librespot daemon successfully initialized Aug 31 15:56:49 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Aug 31 15:56:49 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:49 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:49 bcik go-librespot[27532]: go-librespot daemon starting... Aug 31 15:56:49 bcik go-librespot[27533]: time="2026-08-31T15:56:49+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:56:49 bcik go-librespot[27533]: time="2026-08-31T15:56:49+02:00" level=debug msg="app state loaded" Aug 31 15:56:49 bcik go-librespot[27533]: time="2026-08-31T15:56:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:56:49 bcik go-librespot[27533]: time="2026-08-31T15:56:49+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 31 15:56:49 bcik go-librespot[27533]: time="2026-08-31T15:56:49+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 31 15:56:49 bcik go-librespot[27533]: time="2026-08-31T15:56:49+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 31 15:56:49 bcik go-librespot[27533]: time="2026-08-31T15:56:49+02:00" level=info msg="zeroconf server listening on port 40587" Aug 31 15:56:49 bcik go-librespot[27533]: time="2026-08-31T15:56:49+02:00" level=debug msg="obtained new client token: AAH4ySLDOtLJz7gJhTP3jY42RnkZ3NlaeGTGeN72KnfGpEaXPn2CLSvYyOSEkTZmJ7keEb9U1Hyhbb6N3E7ck+yOBssBlGfYCdjrEdQk8jl5GM2+c5lZ5ZgTZxbV+FLYSmitSYHIxHuiS8BZSblXtX1kBjrt7edi9lLcNf79GYMrF7KCxZdCkhrvj+AJzzKwkMnUMfNa7KwA9yrtsQwfq1CF509/lZ5A8CRvnHBnb1bJiPv3lnhm6HI=" Aug 31 15:56:49 bcik go-librespot[27533]: time="2026-08-31T15:56:49+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:56:49 bcik go-librespot[27533]: time="2026-08-31T15:56:49+02:00" level=debug msg="completed keyexchange" Aug 31 15:56:49 bcik go-librespot[27533]: time="2026-08-31T15:56:49+02:00" level=debug msg="completed challenge" Aug 31 15:56:49 bcik go-librespot[27533]: time="2026-08-31T15:56:49+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:56:49 bcik go-librespot[27533]: time="2026-08-31T15:56:49+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:56:49 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:56:49 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:56:50 bcik volumio[27282]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 31 15:56:51 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:56:51 bcik volumio[27282]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:56:53 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Aug 31 15:56:53 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:53 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:53 bcik go-librespot[27542]: go-librespot daemon starting... Aug 31 15:56:53 bcik go-librespot[27543]: time="2026-08-31T15:56:53+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:56:53 bcik go-librespot[27543]: time="2026-08-31T15:56:53+02:00" level=debug msg="app state loaded" Aug 31 15:56:53 bcik go-librespot[27543]: time="2026-08-31T15:56:53+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:56:53 bcik go-librespot[27543]: time="2026-08-31T15:56:53+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:56:53 bcik go-librespot[27543]: time="2026-08-31T15:56:53+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:56:53 bcik go-librespot[27543]: time="2026-08-31T15:56:53+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:56:53 bcik go-librespot[27543]: time="2026-08-31T15:56:53+02:00" level=info msg="zeroconf server listening on port 35309" Aug 31 15:56:53 bcik go-librespot[27543]: time="2026-08-31T15:56:53+02:00" level=debug msg="obtained new client token: AAFRLfXmZcflJpt/88/PobabGohUc9U4pOzKotOAnUtd10xogoZ1l2kQpmwz/kQvTFEmWyPw9ls/bCFwFoWRUN1yuAb6nnA3hDrS/rrlOPXsVbt9lFjWIPTASUmwAo+ic1xvNzZ8tIfcuDS5tIOH90K2AcAxWBmJE4eM3x4aJ2i2fVS3OfwfEA6yvX6NkRkiPIXaynYfyrcNWTRp0XGKyPrJO11pZwxrMa+NiJVM/ow20zoejh8w" Aug 31 15:56:53 bcik go-librespot[27543]: time="2026-08-31T15:56:53+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:56:53 bcik go-librespot[27543]: time="2026-08-31T15:56:53+02:00" level=debug msg="completed keyexchange" Aug 31 15:56:53 bcik go-librespot[27543]: time="2026-08-31T15:56:53+02:00" level=debug msg="completed challenge" Aug 31 15:56:53 bcik go-librespot[27543]: time="2026-08-31T15:56:53+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:56:53 bcik go-librespot[27543]: time="2026-08-31T15:56:53+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:56:53 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:56:53 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 31 15:56:53 bcik volumio[27282]: info: Adding plugin bluetooth to MyMusic Plugins Aug 31 15:56:53 bcik volumio[27282]: info: Adding plugin multiroom to MyMusic Plugins Aug 31 15:56:53 bcik volumio[27282]: info: Adding plugin metavolumio to MyMusic Plugins Aug 31 15:56:53 bcik volumio[27282]: info: Adding plugin cd_controller to MyMusic Plugins Aug 31 15:56:53 bcik volumio[27282]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 31 15:56:53 bcik volumio[27282]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 31 15:56:53 bcik volumio[27282]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 31 15:56:53 bcik volumio[27282]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 31 15:56:54 bcik volumio[27282]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 31 15:56:54 bcik volumio[27282]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 31 15:56:54 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:54 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:54 bcik volumio[27282]: info: Starting MyVolumio Remote Streaming Endpoints Aug 31 15:56:54 bcik volumio[27282]: info: MyVolumio login type: Token Aug 31 15:56:54 bcik volumio[27282]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 31 15:56:54 bcik volumio[27282]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 31 15:56:54 bcik volumio[27282]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 31 15:56:54 bcik volumio[27282]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 31 15:56:54 bcik volumio[27282]: info: Streaming services startup Aug 31 15:56:54 bcik volumio[27282]: info: Starting Streaming Daemon Aug 31 15:56:54 bcik sudo[27567]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 15:56:54 bcik sudo[27567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:54 bcik volumio[27282]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 31 15:56:54 bcik sudo[27567]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:54 bcik sudo[27574]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 15:56:54 bcik sudo[27574]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:54 bcik sudo[27574]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:54 bcik sudo[27576]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 15:56:54 bcik sudo[27576]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:54 bcik volumio[27282]: error: Cannot start Volumio Streaming Daemon Aug 31 15:56:54 bcik sudo[27576]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:54 bcik volumio[27282]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 15:56:54 bcik volumio[27282]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 15:56:54 bcik sudo[27581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 31 15:56:54 bcik sudo[27581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:54 bcik sudo[27581]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:54 bcik volumio[27282]: info: Upmpdcli Daemon Started Aug 31 15:56:54 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:56:54 bcik volumio[27282]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:56:54 bcik volumio[27282]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 31 15:56:56 bcik volumio[27282]: info: MyVolumio token set successfully Aug 31 15:56:56 bcik volumio[27282]: info: MYVOLUMIO: Adding device Aug 31 15:56:56 bcik volumio[27282]: info: MYVOLUMIO: Evaluating Server Aug 31 15:56:56 bcik volumio[27282]: info: MyVolumio status changed Aug 31 15:56:56 bcik volumio[27282]: info: Streaming services startup Aug 31 15:56:56 bcik volumio[27282]: info: Starting Streaming Daemon Aug 31 15:56:56 bcik volumio[27282]: info: Removing browser output: myVolumio user plan is not superstar Aug 31 15:56:56 bcik volumio[27282]: info: Removing audio output: Aug 31 15:56:56 bcik volumio[27282]: info: Stoppping Tunnel 1 Aug 31 15:56:56 bcik sudo[27604]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 15:56:56 bcik sudo[27604]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:56 bcik sudo[27604]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:56 bcik volumio[27282]: error: Cannot start Volumio Streaming Daemon Aug 31 15:56:56 bcik volumio[27282]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 15:56:56 bcik volumio[27282]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 15:56:56 bcik sudo[27607]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 31 15:56:56 bcik sudo[27607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:56:56 bcik 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. Aug 31 15:56:56 bcik 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. Aug 31 15:56:56 bcik 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. Aug 31 15:56:56 bcik 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. Aug 31 15:56:56 bcik 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. Aug 31 15:56:56 bcik 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. Aug 31 15:56:56 bcik 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. Aug 31 15:56:56 bcik 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. Aug 31 15:56:56 bcik sudo[27607]: pam_unix(sudo:session): session closed for user root Aug 31 15:56:56 bcik volumio[27282]: info: Remote SSH Stopped Aug 31 15:56:56 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Aug 31 15:56:56 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:56 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:56:56 bcik go-librespot[27609]: go-librespot daemon starting... Aug 31 15:56:56 bcik go-librespot[27610]: time="2026-08-31T15:56:56+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:56:56 bcik go-librespot[27610]: time="2026-08-31T15:56:56+02:00" level=debug msg="app state loaded" Aug 31 15:56:56 bcik go-librespot[27610]: time="2026-08-31T15:56:56+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:56:56 bcik volumio[27282]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 15:56:56 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:56 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:56 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:56 bcik go-librespot[27610]: time="2026-08-31T15:56:56+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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 15:56:56 bcik go-librespot[27610]: time="2026-08-31T15:56:56+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:56:56 bcik go-librespot[27610]: time="2026-08-31T15:56:56+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:56:56 bcik go-librespot[27610]: time="2026-08-31T15:56:56+02:00" level=info msg="zeroconf server listening on port 39967" Aug 31 15:56:56 bcik go-librespot[27610]: time="2026-08-31T15:56:56+02:00" level=debug msg="obtained new client token: AAGRcRCRBrrNfiTQfkSHo/KA76d+Ljsd7+4Uex0dvmTq+MMtR4sJSWRfMKXgn5cGrzBwWe5PH6hGQORDT8Z4tLwX4X0dZEmXh1vDZrqDio4X2Lqxir40BzHjkBeV1xLCNsCuh+QEEn/rsInW8x2axUTidkwUo71Nl59hahsp4LSyURC9v7WTjxtJoPKzqXFJBXYyF08csf219NwmIWhX3C0Up+ToQ5ctW523EcWNyMuobdq3mhULZ9g=" Aug 31 15:56:56 bcik go-librespot[27610]: time="2026-08-31T15:56:56+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Aug 31 15:56:56 bcik go-librespot[27610]: time="2026-08-31T15:56:56+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 31 15:56:56 bcik go-librespot[27610]: time="2026-08-31T15:56:56+02:00" level=debug msg="completed keyexchange" Aug 31 15:56:56 bcik go-librespot[27610]: time="2026-08-31T15:56:56+02:00" level=debug msg="completed challenge" Aug 31 15:56:56 bcik go-librespot[27610]: time="2026-08-31T15:56:56+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:56:56 bcik go-librespot[27610]: time="2026-08-31T15:56:56+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:56:56 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:56:56 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:56:57 bcik volumio[27282]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 15:56:57 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:56:57 bcik volumio[27282]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:56:57 bcik volumio[27282]: info: Updating MyVolumio device info Aug 31 15:56:57 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:57 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:57 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:56:58 bcik volumio[27282]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 15:57:00 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Aug 31 15:57:00 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:00 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:00 bcik go-librespot[27620]: go-librespot daemon starting... Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=debug msg="app state loaded" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=info msg="zeroconf server listening on port 35253" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=debug msg="obtained new client token: AAEcdmLBeXc3aSlyGxaoHhTqdKTYbypjv9oOyKwkMlqlAbwpAtSk3RPBwz2+bxVXbyI+Uwq0y2O0MpeQjMIrUQJxuYPqKGwriPgBdakvTr2+koko+8G7rT1gdeHDKl6G9O7yICCdDPfcauKrsY/j0HM8+uRUMj3uepSsA2FAXifHSXdh94+Yks5N4PidaPgeJcTdwnnDd/WhvHRhFKjfd3l8F+G1nOGBrLNXJlfkgLbE+HCpUzmX" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=debug msg="completed challenge" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:00 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:00 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:00 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:00 bcik volumio[27282]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:01 bcik volumio[27282]: info: MYVOLUMIO: Adding device Aug 31 15:57:01 bcik volumio[27282]: info: MYVOLUMIO: Evaluating Server Aug 31 15:57:01 bcik volumio[27282]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 15:57:01 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:01 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:01 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:02 bcik volumio[27282]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 15:57:02 bcik volumio[27282]: info: Updating MyVolumio device info Aug 31 15:57:02 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:02 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:02 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:03 bcik volumio[27282]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 15:57:03 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Aug 31 15:57:03 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:03 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:03 bcik volumio[27282]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:03 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:03 bcik go-librespot[27650]: go-librespot daemon starting... Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=debug msg="app state loaded" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=info msg="zeroconf server listening on port 41717" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=debug msg="obtained new client token: AAGrkTnwPySp82PhTbynBiOaTx+OgJky+k+SDuNhfB5InLxJMktcpZk8/1Sl7ViZNC3nNWxoW+vLI4sYjppijsrYf9stOR/+3ridkqGbuT+kCa1fhqng4dffoOIwZ1HfvGA+ZY01gcLILjnWHjAFhoHNF5d+1iQ20ftHXBuEh7IyRrUwIGrithVFVX+M8SA1M45pst/DzgRIilDCSQGaFE1qe8fUNVzvu8pdu6QevtV0HqU3sDAqUfM=" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=debug msg="completed challenge" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:03 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:03 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:06 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:06 bcik volumio[27282]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:07 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Aug 31 15:57:07 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:07 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:07 bcik go-librespot[27676]: go-librespot daemon starting... Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=debug msg="app state loaded" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=info msg="zeroconf server listening on port 46227" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=debug msg="obtained new client token: AAE+AiIEssasqjSws3AY6rOdux7Mr19Nq/P78ehBx0NTKe8GN1bfB/hTEhKxU4dBHQvKyVw/kJ/AOUNAXjVRpS7divUSAWGude8Gyprd/nC7zO7sB6kMfh50D3r+0V6xowcFDa4lAPOZlnpxzeZ95atQPII4HF8L9Tw8DweqiJbJpK4dE7LtYGS8FR/i21ESQqiRMNvztm/OdYL4buCo7z9Xqv7Tj1U2CSqZ+/wuZRNqauffRP5M" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=debug msg="completed challenge" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:07 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:07 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:09 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 31 15:57:09 bcik volumio[27282]: 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 31 15:57:09 bcik volumio[27282]: info: CoreCommandRouter::volumioGetState Aug 31 15:57:09 bcik volumio[27282]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:09 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:09 bcik volumio[27282]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:10 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Aug 31 15:57:10 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:10 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:10 bcik go-librespot[27686]: go-librespot daemon starting... Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=debug msg="app state loaded" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+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 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+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 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+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 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=info msg="zeroconf server listening on port 41911" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=debug msg="obtained new client token: AAEFGW/elGDVuivcGamINdmA0nIdMUqgfwfpFEgvOaW4npUPxvEWKKA4WDem7ltPiNnEkQ39ORRC5EgvH1zmyi1sQhefeGD2avFKgTS6JeXu+DkOyv5Klde59ifkn9eeoyydKoHzT+5u3nJejE/U/5aWTF6OZHnyYZf/Qeni2W87U5U8vfYZ4GnE0OkDEpxFep6p5tSaZ2v42klX2LK7f7RZrFh+Z+ASEtVprCkROmFC3IiXL5FLq1M=" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=debug msg="completed challenge" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57: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 31 15:57:10 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:10 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:12 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:12 bcik volumio[27282]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:14 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Aug 31 15:57:14 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:14 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:14 bcik go-librespot[27696]: go-librespot daemon starting... Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=debug msg="app state loaded" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=info msg="zeroconf server listening on port 44795" Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::volumioGetBrowseSources Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=debug msg="obtained new client token: AAHMHk0hV+wz9StvuXfgRy5WJzlu68EaSXxmqY8fDPfGkJqTz/C56JxhMdWj6Ye0XmeSeJjQDxqL3us6bX6DH5n9M58sK7itBVtRkDwaAhqBiuhiojdpxKRjIU80tjAo0SXW5fOrqcNuwIR2qI5MEvJpI6ul2cFtd4UQbxpkv0/qGhN3Pc8DpieP+tZeRWoWllhOLPKUdOuVfAiIRlnzzSsfEc6CDuvIybxzY00hKL+bydfw46tU" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=debug msg="completed challenge" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:14 bcik volumio[27282]: error: MyVolumio Plugin failed to authenticate in a timely fashion Aug 31 15:57:14 bcik volumio[27282]: info: Completed starting MyVolumio Plugin Aug 31 15:57:14 bcik volumio[27282]: [Metrics] CommandRouter: 30s 712.62ms Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::volumiosetStartupVolume Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::Close All Modals sent Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::Close All Modals sent Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:14 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:14 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:15 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:57:15 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:15 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 31 15:57:15 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 31 15:57:15 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 31 15:57:15 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 31 15:57:15 bcik volumio-remote-updater[962]: Test mode disabled Aug 31 15:57:15 bcik volumio-remote-updater[962]: Alpha mode disabled Aug 31 15:57:15 bcik volumio-remote-updater[962]: Alpha legacy test mode disabled Aug 31 15:57:15 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 31 15:57:15 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:15 bcik volumio[27282]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:15 bcik volumio[27282]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 31 15:57:15 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 31 15:57:17 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Aug 31 15:57:17 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:17 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:17 bcik go-librespot[27727]: go-librespot daemon starting... Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=debug msg="app state loaded" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+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 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+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 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+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 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=info msg="zeroconf server listening on port 41979" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=debug msg="obtained new client token: AAEl4DWxZZ1Hm2PIxn7BKB13IaKfpEXcZVsEOFohXs04QePIiB+yYh32pxIdDfx8zMOkNCu85a3BxZ9jOHSNvmI9ie7x+ZLgKK0pOqh5ByINEHqzo4eIuKcqPYqPd/1t1m2orqsUA19R4Zug7aoTdwkaNwcoL1j/HK7D8AJEA911zl0mMhKnxAOmRkhun6RzRcm98od/Tx2nqZ11/PVqzrDWFp37oVQnzYIQT3zPTAQVJ1CsepudS9Y=" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=debug msg="completed challenge" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:18 bcik go-librespot[27728]: time="2026-08-31T15:57:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:18 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:18 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:18 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:18 bcik volumio[27282]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:21 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Aug 31 15:57:21 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:21 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:21 bcik go-librespot[27737]: go-librespot daemon starting... Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=debug msg="app state loaded" Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+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 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+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 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+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 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=info msg="zeroconf server listening on port 46017" Aug 31 15:57:21 bcik volumio[27282]: info: BOOT COMPLETED Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=debug msg="obtained new client token: AAHwtW4XHgpb2jXOceN97L7fK6wz+YKJ4iayiLBK/sXkMXZmfhJWIu0+ht20j/wZ63H8bRQVQ1aJRShf+I4+4hNy9Z3/I6Htju6DeThNOPr+Dyc05Ii/qBexKQyhOL1rPKxVzAJE2c5AKfHHu9e+NxYeT926zVpElFq2228HSbCWAyfYImeTKdwtQpQLLlhOzlxu8+VN+tFZtqCX9x/MCoU2FXajkSKMLOTgA1ksKxl6sR1vR1dbl9Y=" Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:21 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=debug msg="new websocket client" Aug 31 15:57:21 bcik volumio[27282]: info: Connection to go-librespot Websocket established Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=debug msg="completed challenge" Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:21 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:21 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:21 bcik volumio[27282]: info: Connection to go-librespot Websocket closed Aug 31 15:57:24 bcik volumio[27282]: info: Getting Spotify volume Aug 31 15:57:24 bcik volumio[27282]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 15:57:24 bcik volumio[27282]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:24 bcik volumio[27282]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 31 15:57:24 bcik volumio[27282]: errno: -111, Aug 31 15:57:24 bcik volumio[27282]: code: 'ECONNREFUSED', Aug 31 15:57:24 bcik volumio[27282]: syscall: 'connect', Aug 31 15:57:24 bcik volumio[27282]: address: '127.0.0.1', Aug 31 15:57:24 bcik volumio[27282]: port: 9879, Aug 31 15:57:24 bcik volumio[27282]: response: undefined Aug 31 15:57:24 bcik volumio[27282]: } Aug 31 15:57:24 bcik volumio[27282]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 15:57:24 bcik sudo[27777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 15:56' Aug 31 15:57:24 bcik sudo[27777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:24 bcik sudo[27777]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:24 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Aug 31 15:57:24 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:24 bcik volumio-remote-updater[962]: [2026-08-31 15:57:24] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 31 15:57:24 bcik volumio-remote-updater[962]: [2026-08-31 15:57:24] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 31 15:57:24 bcik volumio5-onboarding[1666]: time=2026-08-31T15:57:24.773+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Aug 31 15:57:24 bcik volumio5-onboarding[1666]: time=2026-08-31T15:57:24.773+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 31 15:57:24 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:24 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:24 bcik go-librespot[27782]: go-librespot daemon starting... Aug 31 15:57:24 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 31 15:57:24 bcik systemd[1]: volumio.service: Consumed 6.624s CPU time. Aug 31 15:57:24 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 31 15:57:24 bcik go-librespot[27783]: time="2026-08-31T15:57:24+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:24 bcik go-librespot[27783]: time="2026-08-31T15:57:24+02:00" level=debug msg="app state loaded" Aug 31 15:57:24 bcik go-librespot[27783]: time="2026-08-31T15:57:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:24 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Aug 31 15:57:24 bcik go-librespot[27783]: time="2026-08-31T15:57: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:57:24 bcik go-librespot[27783]: time="2026-08-31T15:57:24+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:57:24 bcik go-librespot[27783]: time="2026-08-31T15:57:24+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:57:24 bcik go-librespot[27783]: time="2026-08-31T15:57:24+02:00" level=info msg="zeroconf server listening on port 35229" Aug 31 15:57:24 bcik go-librespot[27783]: time="2026-08-31T15:57:24+02:00" level=debug msg="obtained new client token: AAH0mR2/qwQZwJxgDlMIfrrbO2kEoeyZ7n5NQdKgylU7r8hIURuYLIvx2E2T7VmBu2p4p5N4TsADkmNHuwQq0LteXnMdAgFIMZy72vpDzhN7HcyPjGLMaBSt+ZYyjSOfsJTzYBB+qwMxiDdZiHrTWWGQ7YfX2vLwtpk+NFFaT0AtOjiKPGgtnfLIewkU/NuRIE4z+CzjJ8DeBOWSiWz31/J7SY+i0pXp+l4PW/mnmqCPHlHU/944afE=" Aug 31 15:57:24 bcik go-librespot[27783]: time="2026-08-31T15:57:24+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:25 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 242. Aug 31 15:57:25 bcik go-librespot[27783]: time="2026-08-31T15:57:25+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:25 bcik go-librespot[27783]: time="2026-08-31T15:57:25+02:00" level=debug msg="completed challenge" Aug 31 15:57:25 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 31 15:57:25 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Aug 31 15:57:25 bcik systemd[1]: volumio.service: Consumed 6.624s CPU time. Aug 31 15:57:25 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Aug 31 15:57:25 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Aug 31 15:57:25 bcik go-librespot[27783]: time="2026-08-31T15:57:25+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:25 bcik go-librespot[27783]: time="2026-08-31T15:57:25+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:25 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:25 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:25 bcik volumio[27798]: info: ------------------------------------------- Aug 31 15:57:25 bcik volumio[27798]: info: ----- Volumio3 ---- Aug 31 15:57:25 bcik volumio[27798]: info: ------------------------------------------- Aug 31 15:57:25 bcik volumio[27798]: info: ----- System startup ---- Aug 31 15:57:25 bcik volumio[27798]: info: ------------------------------------------- Aug 31 15:57:25 bcik volumio[27798]: info: MYVOLUMIO Environment detected Aug 31 15:57:25 bcik volumio[27798]: info: Plugin folders cleanup Aug 31 15:57:25 bcik volumio[27798]: info: Scanning into folder /volumio/app/plugins/ Aug 31 15:57:25 bcik volumio[27798]: info: Scanning category audio_interface Aug 31 15:57:25 bcik volumio[27798]: info: Scanning category miscellanea Aug 31 15:57:25 bcik volumio[27798]: info: Scanning category music_service Aug 31 15:57:25 bcik volumio[27798]: info: Scanning category plugins.json Aug 31 15:57:25 bcik volumio[27798]: info: Scanning category system_controller Aug 31 15:57:25 bcik volumio[27798]: info: Scanning category user_interface Aug 31 15:57:25 bcik volumio[27798]: info: Scanning into folder /data/plugins/ Aug 31 15:57:25 bcik volumio[27798]: info: Scanning category music_service Aug 31 15:57:25 bcik volumio[27798]: info: Plugin folders cleanup completed Aug 31 15:57:25 bcik volumio[27798]: info: ------------------------------------------- Aug 31 15:57:25 bcik volumio[27798]: info: ----- Core plugins startup ---- Aug 31 15:57:25 bcik volumio[27798]: info: ------------------------------------------- Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugins from folder /volumio/app/plugins/ Aug 31 15:57:25 bcik volumio[27798]: info: Adding plugin upnp to MyMusic Plugins Aug 31 15:57:25 bcik volumio[27798]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 31 15:57:25 bcik volumio[27798]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugins from folder /data/plugins/ Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "system"... Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "appearance"... Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "network"... Aug 31 15:57:25 bcik volumio[27798]: info: Refreshing Cached IP Addresses Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "services"... Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "volumio5onboarding"... Aug 31 15:57:25 bcik sudo[27827]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 15:57:25 bcik sudo[27829]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 15:57:25 bcik sudo[27827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:25 bcik sudo[27829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:25 bcik sudo[27827]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:25 bcik sudo[27829]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "alsa_controller"... Aug 31 15:57:25 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "wizard"... Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "networkfs"... Aug 31 15:57:25 bcik volumio[27798]: info: Starting Udev Watcher for removable devices Aug 31 15:57:25 bcik volumio[27798]: info: Ignoring mount for partition: boot Aug 31 15:57:25 bcik volumio[27798]: info: Ignoring mount for partition: volumio Aug 31 15:57:25 bcik volumio[27798]: info: Ignoring mount for partition: volumio_data Aug 31 15:57:25 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "volumio_command_line_client"... Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "upnp"... Aug 31 15:57:25 bcik volumio[27798]: info: [1788184645827] Starting Upmpd Daemon Aug 31 15:57:25 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "my_music"... Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "mpd"... Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "upnp_browser"... Aug 31 15:57:26 bcik volumio[27798]: info: Starting UPNP Browser Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "alarm-clock"... Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "airplay_emulation"... Aug 31 15:57:26 bcik volumio[27798]: info: Starting Shairport Sync Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "last_100"... Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "webradio"... Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "i2s_dacs"... Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "volumiodiscovery"... Aug 31 15:57:26 bcik volumio[27798]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 15:57:26 bcik volumio[27798]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:57:26 bcik volumio[27798]: *** WARNING *** For more information see Aug 31 15:57:26 bcik volumio[27798]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 15:57:26 bcik volumio[27798]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:57:26 bcik volumio[27798]: *** WARNING *** For more information see Aug 31 15:57:26 bcik volumio[27798]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 31 15:57:26 bcik volumio[27798]: info: Discovery: Started advertising with name: Bącik Aug 31 15:57:26 bcik node[27798]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 15:57:26 bcik node[27798]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:57:26 bcik node[27798]: *** WARNING *** For more information see Aug 31 15:57:26 bcik node[27798]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 15:57:26 bcik node[27798]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:57:26 bcik node[27798]: *** WARNING *** For more information see Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "spop"... Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "outputs"... Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "albumart"... Aug 31 15:57:26 bcik volumio[27798]: info: Plugin example_plugin is not enabled Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "inputs"... Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "updater_comm"... Aug 31 15:57:26 bcik volumio[27798]: info: Plugin mpdemulation is not enabled Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "rest_api"... Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "websocket"... Aug 31 15:57:26 bcik volumio[27798]: info: Starting Socket.io Server version 1.7.4 Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "radio_browser"... Aug 31 15:57:26 bcik volumio[27859]: Forking 3 albumart workers Aug 31 15:57:26 bcik volumio[27798]: info: Loading i18n strings for locale pl Aug 31 15:57:26 bcik volumio[27798]: Updating browse sources language Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::initPlayerControls Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: Express server listening on port 3000 Aug 31 15:57:26 bcik volumio[27798]: [Metrics] WebUI: 1s 290.01ms Aug 31 15:57:26 bcik volumio[27798]: info: CoreStateMachine::resetVolumioState Aug 31 15:57:26 bcik volumio[27798]: info: CoreStateMachine::getcurrentVolume Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 15:57:26 bcik volumio[27798]: info: Volumio Network Manager: Network status updated: 1 Aug 31 15:57:26 bcik volumio[27798]: 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: 1 Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: Reloading queue from file Aug 31 15:57:26 bcik volumio[27798]: 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: 1 Aug 31 15:57:26 bcik volumio[27798]: info: CoreStateMachine::setRepeat false single undefined Aug 31 15:57:26 bcik volumio[27798]: info: CoreStateMachine::pushState Aug 31 15:57:26 bcik volumio[27798]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioPushState Aug 31 15:57:26 bcik volumio[27798]: info: CoreStateMachine::setRandom false Aug 31 15:57:26 bcik volumio[27798]: info: CoreStateMachine::pushState Aug 31 15:57:26 bcik volumio[27798]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioPushState Aug 31 15:57:26 bcik volumio[27798]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 31 15:57:26 bcik volumio[27798]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Aug 31 15:57:26 bcik volumio[27798]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 31 15:57:26 bcik volumio[27798]: 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: 1 Aug 31 15:57:26 bcik volumio[27798]: info: VolumeController:: Volume=53 Mute =false Aug 31 15:57:26 bcik volumio[27798]: info: CoreStateMachine::pushState Aug 31 15:57:26 bcik volumio[27798]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioPushState Aug 31 15:57:26 bcik volumio[27798]: info: CoreStateMachine::updateTrackBlock Aug 31 15:57:26 bcik volumio[27798]: info: CorePlayQueue::getTrackBlock Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 15:57:26 bcik volumio[27798]: info: Setting Device type: Raspberry PI Aug 31 15:57:26 bcik volumio[27798]: info: Completed loading Core Plugins Aug 31 15:57:26 bcik volumio[27798]: info: Preparing to generate the ALSA configuration file Aug 31 15:57:26 bcik volumio[27798]: info: VolumeController:: Volume=53 Mute =false Aug 31 15:57:26 bcik volumio[27798]: info: CoreStateMachine::pushState Aug 31 15:57:26 bcik volumio[27798]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioPushState Aug 31 15:57:26 bcik volumio[27798]: info: Asound.conf file unchanged, so no further update is needed Aug 31 15:57:26 bcik volumio[27798]: info: Output device has changed, restarting MPD Aug 31 15:57:26 bcik volumio[27798]: info: Output device has changed, restarting Shairport Sync Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:26 bcik sudo[27914]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 15:57:26 bcik sudo[27914]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:26 bcik volumio[27798]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:57:26 bcik volumio[27798]: info: ___________ START PLUGINS ___________ Aug 31 15:57:26 bcik sudo[27914]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:26 bcik sudo[27916]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 15:57:26 bcik sudo[27916]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:26 bcik volumio[27798]: info: ControllerMpd::onStart: Initializing MPD Aug 31 15:57:26 bcik volumio[27798]: info: Creating MPD Configuration file Aug 31 15:57:26 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 31 15:57:26 bcik sudo[27924]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 31 15:57:26 bcik sudo[27924]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:57:26 bcik volumio[27798]: info: [1788184646768] CoreMusicLibrary::Adding element Serwery Mediów Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:57:26 bcik sudo[27926]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 15:57:26 bcik volumio[27798]: info: UPNP Browser: Client initialized successfully Aug 31 15:57:26 bcik sudo[27926]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:26 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 15:57:26 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 15:57:26 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 15:57:26 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 15:57:26 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:26 bcik sudo[27926]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:26 bcik sudo[27929]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 15:57:26 bcik sudo[27929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:26 bcik volumio[27798]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:26 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 15:57:26 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 15:57:26 bcik volumio[27798]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:57:26 bcik volumio[27798]: info: [1788184646811] CoreMusicLibrary::Adding element Last_100 Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:57:26 bcik volumio[27798]: info: [1788184646811] CoreMusicLibrary::Adding element Webradio Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:57:26 bcik sudo[27924]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:26 bcik volumio[27798]: info: Initializing BBC Radios Aug 31 15:57:26 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 15:57:26 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 15:57:26 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 15:57:26 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 15:57:26 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 15:57:26 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 15:57:26 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: Creating Spotify config file Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik sudo[27946]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 15:57:26 bcik sudo[27946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 31 15:57:26 bcik volumio[27870]: Starting albumart workers Aug 31 15:57:26 bcik sudo[27946]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:26 bcik volumio[27869]: Starting albumart workers Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:57:26 bcik volumio[27798]: info: [1788184646970] CoreMusicLibrary::Adding element Radio Browser Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:57:26 bcik volumio[27798]: Cannot find translation for source Radio Browser Aug 31 15:57:26 bcik volumio[27798]: info: Volumio Calling Home Aug 31 15:57:27 bcik volumio[27798]: info: MPD Permissions set Aug 31 15:57:27 bcik volumio[27798]: info: MPD Permissions set Aug 31 15:57:27 bcik volumio[27798]: info: Spotify config file written Aug 31 15:57:27 bcik sudo[27969]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 15:57:27 bcik sudo[27969]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:27 bcik volumio[27798]: 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 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: No need to fix Spotify hosts Aug 31 15:57:27 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:27 bcik sudo[27969]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:27 bcik go-librespot[27972]: go-librespot daemon starting... Aug 31 15:57:27 bcik volumio[27871]: Starting albumart workers Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=debug msg="app state loaded" Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:27 bcik volumio[27798]: info: Volumio called home Aug 31 15:57:27 bcik volumio[27798]: info: Starting Shairport Sync Aug 31 15:57:27 bcik volumio[27798]: info: Starting Shairport Sync Aug 31 15:57:27 bcik volumio[27798]: info: Starting Shairport Sync Aug 31 15:57:27 bcik sudo[27997]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:57:27 bcik sudo[27997]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:27 bcik sudo[27998]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:57:27 bcik sudo[27998]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:27 bcik sudo[28000]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:57:27 bcik sudo[28000]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::volumioGetState Aug 31 15:57:27 bcik volumio[27798]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=info msg="zeroconf server listening on port 46431" Aug 31 15:57:27 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 31 15:57:27 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Aug 31 15:57:27 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:57:27 bcik systemd[1]: shairport-sync.service: Consumed 1.552s CPU time. Aug 31 15:57:27 bcik volumio[27798]: info: An error occurred while refreshing Spotify Token Error: Bad Request Aug 31 15:57:27 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:57:27 bcik sudo[27997]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:27 bcik volumio[27798]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 15:57:27 bcik sudo[27998]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:27 bcik volumio[27798]: info: Discovery: Found device Bącik Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::volumioGetState Aug 31 15:57:27 bcik volumio[27798]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:27 bcik sudo[28000]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:27 bcik volumio[27798]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 15:57:27 bcik volumio[27798]: info: Discovery: Found device Bącik Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::volumioGetState Aug 31 15:57:27 bcik volumio[27798]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:27 bcik volumio[27798]: info: Shairport-Sync Started Aug 31 15:57:27 bcik volumio[27798]: Error adding Membership: Error: addMembership EINVAL Aug 31 15:57:27 bcik volumio[27798]: info: Shairport-Sync Started Aug 31 15:57:27 bcik volumio[27798]: info: Shairport-Sync Started Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=debug msg="obtained new client token: AAGfZy1o8tYzJ07Aw/4uVs9hK2ZlRKBFYuGm8qjkkvKlBcnUxm716i3pxHvZS+fd5OvJgDJ+nyyYClOWKRNoVCIE1PFsQNJQnGysqrIqo6qe93ulan02qqNslJ3d3r+JuPaMzRhlYDPiS4ZrGs1bihKH92F4oTQHuhrNdT/unkLgjqJ1t3Covmlg1BWlgFLZhsTaNrTE7/hvA321JjEeKeFgOYcNtQVZ/4M9+MA0nmYiqzSPVMb0" Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=debug msg="completed challenge" Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:27 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:27 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:27 bcik mpd[27958]: 2026-08-31T15:57:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 15:57:27 bcik systemd[1]: Started mpd.service - Music Player Daemon. Aug 31 15:57:27 bcik sudo[27929]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:27 bcik sudo[27916]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:27 bcik volumio[27798]: info: Completed starting Core Plugins Aug 31 15:57:27 bcik volumio[27798]: info: ------------------------------------------- Aug 31 15:57:27 bcik volumio[27798]: info: ----- MyVolumio plugins startup ---- Aug 31 15:57:27 bcik volumio[27798]: info: ------------------------------------------- Aug 31 15:57:27 bcik volumio[27798]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 31 15:57:27 bcik volumio[27798]: error: MPD error: The expression evaluated to a falsy value: Aug 31 15:57:27 bcik volumio[27798]: assert.ok(self.idling) Aug 31 15:57:27 bcik volumio[27798]: error: The expression evaluated to a falsy value: Aug 31 15:57:27 bcik volumio[27798]: assert.ok(self.idling) Aug 31 15:57:27 bcik volumio[27798]: error: updateQueue error: null Aug 31 15:57:27 bcik volumio[27798]: info: MPD running with PID27958 Aug 31 15:57:27 bcik volumio[27798]: ,establishing connection Aug 31 15:57:27 bcik volumio[27798]: error: updateQueue error: null Aug 31 15:57:29 bcik volumio-remote-updater[962]: [2026-08-31 15:57:29] [connect] Successful connection Aug 31 15:57:29 bcik volumio-remote-updater[962]: [2026-08-31 15:57:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788184649 101 Aug 31 15:57:29 bcik volumio[27798]: 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: 3 Aug 31 15:57:30 bcik volumio[27798]: info: go-librespot daemon successfully initialized Aug 31 15:57:30 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Aug 31 15:57:30 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:30 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:30 bcik go-librespot[28036]: go-librespot daemon starting... Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=debug msg="app state loaded" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=info msg="zeroconf server listening on port 37471" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=debug msg="obtained new client token: AAFY4jBB04sOG0C+fQ9M5HPXtjXxk7IyGtNlOZcDBBM86Y2N/qTcXNM5in36i5qnzN6ctRwLcURSUCvOKk2t+PH1GIkne0S+2qLTZv2s/va3HKVjn6AD9/4DB/auyASe9i2Psg7wfVXxYMSN0OUzDEk50lb1Q05nTWBsqNh3jgjodFGZ5CLvU5+hQ7nWEDJonQPcceWLdLRi333oWJPKLogJ7tHXVsX6fjQUNOeR4lyqB7Z5MKmqck4=" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=debug msg="completed challenge" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:30 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:30 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:32 bcik volumio[27798]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 31 15:57:33 bcik volumio[27798]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:33 bcik volumio[27798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:34 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Aug 31 15:57:34 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:34 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:34 bcik go-librespot[28046]: go-librespot daemon starting... Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=debug msg="app state loaded" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=info msg="zeroconf server listening on port 39963" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=debug msg="obtained new client token: AAG7OarenqOm0L2NUV2a2BtEhro/O+KRUanaZNZb2OWztFkfwmuLIMk8kBh02+/a4sHiWVr6ZG/Cl5+sa5ESOWMj4NMLXTQ93Gr63mzpOsJ+OpAWxXUVCtZaUixq3q8WT73QBX7bMarXYYQrUVBWIOPPNvOgg4CmhubYcgsFefR7K6E+bv6XsDmgbBh80kV0kX/pPgFjgShlmZSt2abrFG7pmuIOzymg4kpvCaEP6i5c6MPM1IAe" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=debug msg="completed challenge" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:34 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:34 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 31 15:57:35 bcik volumio[27798]: info: Adding plugin bluetooth to MyMusic Plugins Aug 31 15:57:35 bcik volumio[27798]: info: Adding plugin multiroom to MyMusic Plugins Aug 31 15:57:35 bcik volumio[27798]: info: Adding plugin metavolumio to MyMusic Plugins Aug 31 15:57:35 bcik volumio[27798]: info: Adding plugin cd_controller to MyMusic Plugins Aug 31 15:57:35 bcik volumio[27798]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 31 15:57:35 bcik volumio[27798]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 31 15:57:35 bcik volumio[27798]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 31 15:57:35 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:35 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:35 bcik volumio[27798]: info: Starting MyVolumio Remote Streaming Endpoints Aug 31 15:57:35 bcik volumio[27798]: info: MyVolumio login type: Token Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 31 15:57:36 bcik volumio[27798]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 31 15:57:36 bcik volumio[27798]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 31 15:57:36 bcik volumio[27798]: info: Streaming services startup Aug 31 15:57:36 bcik volumio[27798]: info: Starting Streaming Daemon Aug 31 15:57:36 bcik sudo[28071]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 15:57:36 bcik sudo[28071]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:36 bcik volumio[27798]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 31 15:57:36 bcik sudo[28071]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:36 bcik sudo[28078]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 15:57:36 bcik sudo[28078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:36 bcik sudo[28080]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 15:57:36 bcik sudo[28080]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:36 bcik sudo[28078]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:36 bcik sudo[28080]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:36 bcik volumio[27798]: error: Cannot start Volumio Streaming Daemon Aug 31 15:57:36 bcik volumio[27798]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 15:57:36 bcik volumio[27798]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 15:57:36 bcik sudo[28084]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 31 15:57:36 bcik sudo[28084]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:36 bcik sudo[28084]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:36 bcik volumio[27798]: info: Upmpdcli Daemon Started Aug 31 15:57:36 bcik volumio[27798]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:36 bcik volumio[27798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:36 bcik volumio[27798]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 31 15:57:36 bcik volumio[27798]: info: MyVolumio token set successfully Aug 31 15:57:36 bcik volumio[27798]: info: MYVOLUMIO: Adding device Aug 31 15:57:36 bcik volumio[27798]: info: MYVOLUMIO: Evaluating Server Aug 31 15:57:37 bcik volumio[27798]: info: MyVolumio status changed Aug 31 15:57:37 bcik volumio[27798]: info: Streaming services startup Aug 31 15:57:37 bcik volumio[27798]: info: Starting Streaming Daemon Aug 31 15:57:37 bcik volumio[27798]: info: Removing browser output: myVolumio user plan is not superstar Aug 31 15:57:37 bcik volumio[27798]: info: Removing audio output: Aug 31 15:57:37 bcik volumio[27798]: info: Stoppping Tunnel 1 Aug 31 15:57:37 bcik sudo[28107]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 15:57:37 bcik sudo[28107]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:37 bcik sudo[28107]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:37 bcik volumio[27798]: error: Cannot start Volumio Streaming Daemon Aug 31 15:57:37 bcik volumio[27798]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 15:57:37 bcik volumio[27798]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 15:57:37 bcik sudo[28110]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 31 15:57:37 bcik sudo[28110]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:37 bcik 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. Aug 31 15:57:37 bcik 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. Aug 31 15:57:37 bcik 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. Aug 31 15:57:37 bcik 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. Aug 31 15:57:37 bcik 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. Aug 31 15:57:37 bcik 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. Aug 31 15:57:37 bcik 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. Aug 31 15:57:37 bcik 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. Aug 31 15:57:37 bcik sudo[28110]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:37 bcik volumio[27798]: info: Remote SSH Stopped Aug 31 15:57:37 bcik volumio[27798]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 15:57:37 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:37 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:37 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:37 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Aug 31 15:57:37 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:37 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:37 bcik go-librespot[28112]: go-librespot daemon starting... Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=debug msg="app state loaded" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=info msg="zeroconf server listening on port 46063" Aug 31 15:57:37 bcik volumio[27798]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=debug msg="obtained new client token: AAGBuh0kjI7SvE/8/K/3bCm/yDxiGlgwGj9wRKhrwYW0cbsinGD1249mWQ+aH6sVLx73jyRCfAEgqzfmrG3KzyVHc02FQ3FwAoMk7EqyV+0u6E5oFlEfjak5shSDQIT2xUuEQMI54eDbld17bGofwDYSnjK4uSIT0CjFN2HDTFGRBrC3DTupSWT9LLcPtmMUYDYUFzBbrThyKnTESWhsLfXpdHe9hWqHj1OWfx669wzRkN9q1WGAvvE=" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=debug msg="completed challenge" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:37 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:37 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:38 bcik volumio[27798]: info: Updating MyVolumio device info Aug 31 15:57:38 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:38 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:38 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:39 bcik volumio[27798]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 15:57:39 bcik volumio[27798]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:39 bcik volumio[27798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:41 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Aug 31 15:57:41 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:41 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:41 bcik go-librespot[28123]: go-librespot daemon starting... Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=debug msg="app state loaded" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=info msg="zeroconf server listening on port 40297" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=debug msg="obtained new client token: AAHFh291EqwenVeXMHiG4mPMIks7RajIsWZxJTpBZ5+4v+Bp3SjkvXrKz7qlkPVclltZgNUpQkKyq4QZmkTAjTD6UpzTWOy2UY/2Kflq+MLrwrL3JAUE0brp4yVRFSoUwl4WpouHFRozICvNunaFw4Sy/VmJQ+zbIVhWLFNfyuZIFuJtB/dtmJtfIoNxS8tr6xpVOcW/YvnG3/fTCejOJMPW/TD1pYk8MVZskdQT/G9mXjcX+AdN" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=debug msg="completed challenge" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:41 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:41 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:41 bcik volumio[27798]: info: MYVOLUMIO: Adding device Aug 31 15:57:41 bcik volumio[27798]: info: MYVOLUMIO: Evaluating Server Aug 31 15:57:42 bcik volumio[27798]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:42 bcik volumio[27798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:42 bcik volumio[27798]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 15:57:42 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:42 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:42 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:42 bcik volumio[27798]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 15:57:43 bcik volumio[27798]: info: Updating MyVolumio device info Aug 31 15:57:43 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:43 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:43 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:43 bcik volumio[27798]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 15:57:44 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Aug 31 15:57:44 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:44 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:44 bcik go-librespot[28151]: go-librespot daemon starting... Aug 31 15:57:44 bcik go-librespot[28152]: time="2026-08-31T15:57:44+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:44 bcik go-librespot[28152]: time="2026-08-31T15:57:44+02:00" level=debug msg="app state loaded" Aug 31 15:57:44 bcik go-librespot[28152]: time="2026-08-31T15:57:44+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:44 bcik go-librespot[28152]: time="2026-08-31T15:57:44+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 31 15:57:44 bcik go-librespot[28152]: time="2026-08-31T15:57:44+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 31 15:57:44 bcik go-librespot[28152]: time="2026-08-31T15:57:44+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 31 15:57:44 bcik go-librespot[28152]: time="2026-08-31T15:57:44+02:00" level=info msg="zeroconf server listening on port 44165" Aug 31 15:57:44 bcik go-librespot[28152]: time="2026-08-31T15:57:44+02:00" level=debug msg="obtained new client token: AAHw7t7L3yZCbVW3H25+BIPjzSZPP7USRSfs7+iSq8m+h+4hZ0F7SRDhPdXWC3uNFpRkz6Lb99Au5oyzORumiG71S+xZSQHc1kgHz9IUZQ1u2V/vTObbHvIe+wEfxfmH/5G6p/yKS91wc9uE59wI2uULtp5q5bzFa0KLcX/1GftUZMQ48rEAjXvE3Qbg7zGiXU40f+vTP22KUZi91UU9AY7F7CjMFmTUkua1bqce1FhuXa5s+3AS9nU=" Aug 31 15:57:44 bcik go-librespot[28152]: time="2026-08-31T15:57:44+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:45 bcik volumio[27798]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:45 bcik go-librespot[28152]: time="2026-08-31T15:57:45+02:00" level=debug msg="new websocket client" Aug 31 15:57:45 bcik volumio[27798]: info: Connection to go-librespot Websocket established Aug 31 15:57:48 bcik volumio[27798]: info: Getting Spotify volume Aug 31 15:57:48 bcik volumio[27798]: 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 31 15:57:48 bcik volumio[27798]: info: CoreCommandRouter::volumioGetState Aug 31 15:57:48 bcik volumio[27798]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:48 bcik volumio[27798]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53 Aug 31 15:57:48 bcik volumio[27798]: SPOTIFY: SPOTIFY VOLUME undefined Aug 31 15:57:48 bcik volumio[27798]: SPOTIFY: VOLUMIO VOLUME 53 Aug 31 15:57:48 bcik volumio[27798]: info: Aligning Spotify Volume to Volumio Volume Aug 31 15:57:48 bcik volumio[27798]: info: CoreCommandRouter::volumioGetState Aug 31 15:57:48 bcik volumio[27798]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:48 bcik volumio[27798]: info: Setting Spotify Volume from Volumio: 53 Aug 31 15:57:48 bcik go-librespot[28152]: time="2026-08-31T15:57:48+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:48 bcik go-librespot[28152]: time="2026-08-31T15:57:48+02:00" level=debug msg="completed challenge" Aug 31 15:57:48 bcik go-librespot[28152]: time="2026-08-31T15:57:48+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:48 bcik go-librespot[28152]: time="2026-08-31T15:57:48+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:48 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:48 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:48 bcik volumio[27798]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 15:57:48 bcik volumio[27798]: Error: socket hang up Aug 31 15:57:48 bcik volumio[27798]: at connResetException (node:internal/errors:720:14) Aug 31 15:57:48 bcik volumio[27798]: at Socket.socketOnEnd (node:_http_client:519:23) Aug 31 15:57:48 bcik volumio[27798]: at Socket.emit (node:events:526:35) Aug 31 15:57:48 bcik volumio[27798]: at endReadableNT (node:internal/streams/readable:1376:12) Aug 31 15:57:48 bcik volumio[27798]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Aug 31 15:57:48 bcik volumio[27798]: code: 'ECONNRESET', Aug 31 15:57:48 bcik volumio[27798]: response: undefined Aug 31 15:57:48 bcik volumio[27798]: } Aug 31 15:57:48 bcik volumio[27798]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 15:57:49 bcik sudo[28197]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 15:56' Aug 31 15:57:49 bcik sudo[28197]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"