Dec 10 03:35:00 volumio volumio[10381]: info: Loading i18n strings for locale en Dec 10 03:35:00 volumio volumio[10381]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 10 03:35:00 volumio volumio[10381]: Updating browse sources language Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::initPlayerControls Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 10 03:35:00 volumio volumio[10381]: Express server listening on port 3000 Dec 10 03:35:00 volumio volumio[10381]: [Metrics] WebUI: 14s 814.00ms Dec 10 03:35:00 volumio volumio[10381]: info: CoreStateMachine::resetVolumioState Dec 10 03:35:00 volumio volumio[10381]: info: CoreStateMachine::getcurrentVolume Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::volumioRetrievevolume Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:00 volumio sudo[10566]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 10 03:35:00 volumio sudo[10566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:00 volumio sudo[10566]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:00 volumio sudo[10568]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 10 03:35:00 volumio sudo[10568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:00 volumio sudo[10568]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:00 volumio volumio[10381]: info: Volumio Network Manager: Network status updated: 1 Dec 10 03:35:00 volumio volumio[10381]: info: VolumeController:: Volume=86 Mute =false Dec 10 03:35:00 volumio volumio[10381]: info: CoreStateMachine::pushState Dec 10 03:35:00 volumio volumio[10381]: info: CorePlayQueue::getTrack 0 Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::volumioPushState Dec 10 03:35:00 volumio volumio[10381]: info: CoreStateMachine::updateTrackBlock Dec 10 03:35:00 volumio volumio[10381]: info: CorePlayQueue::getTrackBlock Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::volumioRetrievevolume Dec 10 03:35:00 volumio volumio[10381]: info: Reloading queue from file Dec 10 03:35:00 volumio volumio[10381]: info: CoreStateMachine::setRepeat null single undefined Dec 10 03:35:00 volumio volumio[10381]: info: CoreStateMachine::pushState Dec 10 03:35:00 volumio volumio[10381]: info: CorePlayQueue::getTrack 0 Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::volumioPushState Dec 10 03:35:00 volumio volumio[10381]: info: CoreStateMachine::setRandom null Dec 10 03:35:00 volumio volumio[10381]: info: CoreStateMachine::pushState Dec 10 03:35:00 volumio volumio[10381]: info: CorePlayQueue::getTrack 0 Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::volumioPushState Dec 10 03:35:00 volumio volumio[10381]: info: Setting Device type: Raspberry PI Dec 10 03:35:00 volumio volumio[10381]: info: VolumeController:: Volume=86 Mute =false Dec 10 03:35:00 volumio volumio[10381]: info: CoreStateMachine::pushState Dec 10 03:35:00 volumio volumio[10381]: info: CorePlayQueue::getTrack 0 Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::volumioPushState Dec 10 03:35:00 volumio sudo[10581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 10 03:35:00 volumio sudo[10581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:00 volumio volumio[10381]: info: Completed loading Core Plugins Dec 10 03:35:00 volumio volumio[10381]: info: Preparing to generate the ALSA configuration file Dec 10 03:35:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Dec 10 03:35:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:00 volumio volumio[10381]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Dec 10 03:35:00 volumio volumio[10381]: info: Discovery: Found device Volumio Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::volumioGetState Dec 10 03:35:00 volumio volumio[10381]: info: CorePlayQueue::getTrack 0 Dec 10 03:35:00 volumio volumio[10381]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 10 03:35:00 volumio volumio[10381]: info: Reading ALSA contributions from plugins. Dec 10 03:35:00 volumio volumio[10381]: info: Asound.conf file unchanged, so no further update is needed Dec 10 03:35:00 volumio volumio[10381]: info: Output device has changed, restarting MPD Dec 10 03:35:00 volumio volumio[10381]: info: Output device has changed, restarting Shairport Sync Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:00 volumio go-librespot[10584]: go-librespot daemon starting... Dec 10 03:35:00 volumio sudo[10581]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:00 volumio sudo[10588]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 10 03:35:00 volumio sudo[10586]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 10 03:35:00 volumio sudo[10588]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:00 volumio sudo[10586]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:00 volumio sudo[10586]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:00 volumio volumio[10381]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 10 03:35:00 volumio go-librespot[10590]: time="2025-12-10T03:35:00-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:35:00 volumio volumio[10381]: info: ___________ START PLUGINS ___________ Dec 10 03:35:00 volumio go-librespot[10590]: time="2025-12-10T03:35:00-06:00" level=debug msg="app state loaded" Dec 10 03:35:00 volumio go-librespot[10590]: time="2025-12-10T03:35:00-06:00" level=debug msg="stored credentials not found" Dec 10 03:35:00 volumio go-librespot[10590]: time="2025-12-10T03:35:00-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:35:00 volumio volumio[10381]: info: ControllerMpd::onStart: Initializing MPD Dec 10 03:35:00 volumio volumio[10381]: info: Creating MPD Configuration file Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 03:35:00 volumio volumio[10381]: info: [1765359300832] CoreMusicLibrary::Adding element Media Servers Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 03:35:00 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 10 03:35:00 volumio sudo[10602]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 10 03:35:00 volumio sudo[10602]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:00 volumio sudo[10604]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 10 03:35:00 volumio sudo[10604]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:00 volumio sudo[10602]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:00 volumio volumio[10381]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:00 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 10 03:35:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 10 03:35:00 volumio systemd[1]: mpd.service: Consumed 4.592s CPU time. Dec 10 03:35:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 10 03:35:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 10 03:35:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 10 03:35:00 volumio volumio[10381]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 03:35:00 volumio volumio[10381]: info: [1765359300996] CoreMusicLibrary::Adding element Last_100 Dec 10 03:35:00 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 03:35:01 volumio volumio[10381]: info: [1765359301000] CoreMusicLibrary::Adding element Webradio Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 10 03:35:01 volumio volumio[10381]: info: Initializing BBC Radios Dec 10 03:35:01 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 10 03:35:01 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 03:35:01 volumio volumio[10381]: info: [1765359301099] CoreMusicLibrary::Adding element Bandcamp Discover Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source Bandcamp Discover Dec 10 03:35:01 volumio go-librespot[10590]: time="2025-12-10T03:35:01-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:35:01 volumio go-librespot[10590]: time="2025-12-10T03:35:01-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:35:01 volumio go-librespot[10590]: time="2025-12-10T03:35:01-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 03:35:01 volumio volumio[10381]: info: [1765359301113] CoreMusicLibrary::Adding element SoundCloud Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source Bandcamp Discover Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source SoundCloud Dec 10 03:35:01 volumio go-librespot[10590]: time="2025-12-10T03:35:01-06:00" level=info msg="zeroconf server listening on port 34469" Dec 10 03:35:01 volumio volumio[10381]: info: Creating Spotify config file Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:01 volumio volumio-remote-updater[9752]: [2025-12-10 03:35:01] [connect] Successful connection Dec 10 03:35:01 volumio go-librespot[10590]: time="2025-12-10T03:35:01-06:00" level=debug msg="obtained new client token: AABtVb6hlJcqesaJzAOWIBAZD3bayAeWRVTYXh4jnLU2HkRQbS32GKzlhFKAyjtRwZnCNBeDiKNBPz/QTCC6VCiv9bYu6n1pyn30caCwEt516UdRt8gvCvBy5SjRKNMgBI4js3w+7oQmqwSazUoJBq962lhetW6lawSUas8gVdTzxCYmByNqWgt4lpXOYxe5qoDQV5wvhTrmi19/QYPVuFFU+qr05HvFzGflg5gBLheNsT+3+x/Hd7I=" Dec 10 03:35:01 volumio go-librespot[10590]: time="2025-12-10T03:35:01-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:35:01 volumio sudo[10625]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 10 03:35:01 volumio sudo[10625]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 10 03:35:01 volumio sudo[10625]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:01 volumio go-librespot[10590]: time="2025-12-10T03:35:01-06:00" level=debug msg="completed keyexchange" Dec 10 03:35:01 volumio go-librespot[10590]: time="2025-12-10T03:35:01-06:00" level=debug msg="completed challenge" Dec 10 03:35:01 volumio go-librespot[10590]: time="2025-12-10T03:35:01-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:35:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:35:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:35:01 volumio volumio[10381]: info: [squeezelite_mc] Starting proxy server... Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 03:35:01 volumio volumio[10381]: info: [1765359301500] CoreMusicLibrary::Adding element YouTube2 Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source Bandcamp Discover Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source SoundCloud Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source YouTube2 Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 03:35:01 volumio volumio[10381]: info: [1765359301518] CoreMusicLibrary::Adding element YouTube Music Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source Bandcamp Discover Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source SoundCloud Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source YouTube2 Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source YouTube Music Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 03:35:01 volumio volumio[10381]: info: [1765359301529] CoreMusicLibrary::Adding element Podcast Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source Bandcamp Discover Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source SoundCloud Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source YouTube2 Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source YouTube Music Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source Podcast Dec 10 03:35:01 volumio volumio[10381]: info: Loading i18n strings for locale en Dec 10 03:35:01 volumio volumio[10381]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 10 03:35:01 volumio volumio[10381]: Updating browse sources language Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source Bandcamp Discover Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source SoundCloud Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source YouTube2 Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source YouTube Music Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source Podcast Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source Bandcamp Discover Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source SoundCloud Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source YouTube2 Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source YouTube Music Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source Podcast Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 03:35:01 volumio volumio[10381]: info: [1765359301577] CoreMusicLibrary::Adding element Volusonic Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source Bandcamp Discover Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source SoundCloud Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source YouTube2 Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source YouTube Music Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source Podcast Dec 10 03:35:01 volumio volumio[10381]: Cannot find translation for source Volusonic Dec 10 03:35:01 volumio volumio[10381]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 10 03:35:01 volumio volumio[10381]: info: Volumio Calling Home Dec 10 03:35:01 volumio volumio[10381]: info: [squeezelite_mc] Proxy server started on port 41479 Dec 10 03:35:01 volumio volumio[10381]: info: Preparing to generate the ALSA configuration file Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::volumioRetrievevolume Dec 10 03:35:01 volumio volumio[10381]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Dec 10 03:35:01 volumio volumio[10381]: info: Discovery: Found device Volumio Dec 10 03:35:01 volumio volumio[10381]: info: CoreCommandRouter::volumioGetState Dec 10 03:35:01 volumio volumio[10381]: info: CorePlayQueue::getTrack 0 Dec 10 03:35:01 volumio volumio[10381]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 10 03:35:01 volumio volumio[10381]: info: Reading ALSA contributions from plugins. Dec 10 03:35:01 volumio volumio[10381]: info: MPD Permissions set Dec 10 03:35:01 volumio volumio[10381]: info: MPD Permissions set Dec 10 03:35:01 volumio volumio[10381]: info: Upmpdcli Daemon Started Dec 10 03:35:01 volumio volumio-remote-updater[9752]: [2025-12-10 03:35:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765359301 101 Dec 10 03:35:01 volumio volumio[10381]: 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: 1 Dec 10 03:35:01 volumio volumio[10381]: info: Spotify config file written Dec 10 03:35:01 volumio sudo[10640]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 10 03:35:01 volumio sudo[10640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:02 volumio volumio[10381]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 10 03:35:02 volumio volumio[10381]: info: VolumeController:: Volume=86 Mute =false Dec 10 03:35:02 volumio volumio[10381]: info: CoreStateMachine::pushState Dec 10 03:35:02 volumio volumio[10381]: info: CorePlayQueue::getTrack 0 Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::volumioPushState Dec 10 03:35:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:02 volumio volumio[10381]: info: [squeezelite_mc] Server discovery started Dec 10 03:35:02 volumio volumio[10381]: info: [squeezelite_mc] Player finder started Dec 10 03:35:02 volumio go-librespot[10642]: go-librespot daemon starting... Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Dec 10 03:35:02 volumio sudo[10640]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio go-librespot[10643]: time="2025-12-10T03:35:02-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:35:02 volumio go-librespot[10643]: time="2025-12-10T03:35:02-06:00" level=debug msg="app state loaded" Dec 10 03:35:02 volumio go-librespot[10643]: time="2025-12-10T03:35:02-06:00" level=debug msg="stored credentials not found" Dec 10 03:35:02 volumio go-librespot[10643]: time="2025-12-10T03:35:02-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: No need to fix Spotify hosts Dec 10 03:35:02 volumio volumio[10381]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 10 03:35:02 volumio volumio[10381]: info: [squeezelite_mc] Server discovered: {"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"} Dec 10 03:35:02 volumio go-librespot[10643]: time="2025-12-10T03:35:02-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:35:02 volumio go-librespot[10643]: time="2025-12-10T03:35:02-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:35:02 volumio go-librespot[10643]: time="2025-12-10T03:35:02-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:35:02 volumio go-librespot[10643]: time="2025-12-10T03:35:02-06:00" level=info msg="zeroconf server listening on port 41335" Dec 10 03:35:02 volumio volumio[10381]: info: Volumio called home Dec 10 03:35:02 volumio volumio[10381]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Dec 10 03:35:02 volumio volumio[10381]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Dec 10 03:35:02 volumio volumio[10381]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Dec 10 03:35:02 volumio volumio[10381]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 10 03:35:02 volumio volumio[10381]: SPOTIFY: BQBFw0ZkGdRKXXsbYp1U2MMg_EalTEfIyxz3X7DE4aK2TX3emfF7SdY-nTdavuO97rejAKSwmadb7rcFr3u01rb-Bgfl3bpbofUcDWLDbRzE-OyTG36tcAwTXivbtOycQjv-IjjfJJaOp1hGY7C5J-d3M5FDOtTud7qvP2eFqCWKApIJXPaHLyy9Jn4DbBBLBN8gNPBQUfM_eUJd-BbZt7x4MwxYDMRkklLoeKA Dec 10 03:35:02 volumio volumio[10381]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 10 03:35:02 volumio volumio[10381]: info: New Spotify access token = BQBFw0ZkGdRKXXsbYp1U2MMg_EalTEfIyxz3X7DE4aK2TX3emfF7SdY-nTdavuO97rejAKSwmadb7rcFr3u01rb-Bgfl3bpbofUcDWLDbRzE-OyTG36tcAwTXivbtOycQjv-IjjfJJaOp1hGY7C5J-d3M5FDOtTud7qvP2eFqCWKApIJXPaHLyy9Jn4DbBBLBN8gNPBQUfM_eUJd-BbZt7x4MwxYDMRkklLoeKA Dec 10 03:35:02 volumio volumio[10381]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 10 03:35:02 volumio go-librespot[10643]: time="2025-12-10T03:35:02-06:00" level=debug msg="obtained new client token: AABCSvUIICCOG9W8MatdKezn75FZVLMkc2EfTvrMKVOMdzjWwg0sJp8O2y2QRhpTLofCzM8/0u9DD0Rj2KnuDJIGLeY8ZQwRWYKe6IahwcVEuYDj6xjodviYMLhHKhrTtK1rQIeWrR/SXBgwKaph8cWN0szbUvH0aX87lAjDA7oyVMWd0T3c2YOQm8oSBl/0SPTVpoQcpyOUDAp0/5jJ4KLoVIysx/kKuxZ6Y1PS3PMs4kNxrzrezP3elA==" Dec 10 03:35:02 volumio volumio[10381]: info: Starting Shairport Sync Dec 10 03:35:02 volumio volumio[10381]: info: Starting Shairport Sync Dec 10 03:35:02 volumio volumio[10381]: info: Starting Shairport Sync Dec 10 03:35:02 volumio sudo[10668]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 10 03:35:02 volumio sudo[10668]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:02 volumio go-librespot[10643]: time="2025-12-10T03:35:02-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:35:02 volumio sudo[10665]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Dec 10 03:35:02 volumio sudo[10665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:02 volumio sudo[10665]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:02 volumio sudo[10670]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 10 03:35:02 volumio sudo[10670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:02 volumio sudo[10673]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 10 03:35:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 10 03:35:02 volumio sudo[10673]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:02 volumio go-librespot[10643]: time="2025-12-10T03:35:02-06:00" level=debug msg="completed keyexchange" Dec 10 03:35:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 10 03:35:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 03:35:02 volumio systemd[1]: shairport-sync.service: Consumed 4.051s CPU time. Dec 10 03:35:02 volumio go-librespot[10643]: time="2025-12-10T03:35:02-06:00" level=debug msg="completed challenge" Dec 10 03:35:02 volumio volumio[10381]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Dec 10 03:35:02 volumio go-librespot[10643]: time="2025-12-10T03:35:02-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:35:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 03:35:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:35:02 volumio sudo[10668]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:35:02 volumio volumio[10381]: info: Asound.conf file unchanged, so no further update is needed Dec 10 03:35:02 volumio volumio[10381]: info: Output device has changed, restarting MPD Dec 10 03:35:02 volumio sudo[10680]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Dec 10 03:35:02 volumio sudo[10680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 10 03:35:02 volumio sudo[10680]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:02 volumio sudo[10693]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 10 03:35:02 volumio sudo[10693]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 10 03:35:02 volumio sudo[10693]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 03:35:02 volumio volumio[10381]: info: Output device has changed, restarting Shairport Sync Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:02 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:02 volumio sudo[10698]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 10 03:35:02 volumio sudo[10698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:02 volumio volumio[10381]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 10 03:35:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 03:35:02 volumio sudo[10670]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:02 volumio sudo[10673]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:03 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 10 03:35:03 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 10 03:35:03 volumio systemd[1]: mpd.service: Consumed 1.769s CPU time. Dec 10 03:35:03 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 10 03:35:03 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 10 03:35:03 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 10 03:35:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 10 03:35:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 10 03:35:03 volumio volumio[10381]: info: MPD Permissions set Dec 10 03:35:03 volumio volumio[10381]: info: Shairport-Sync Started Dec 10 03:35:03 volumio volumio[10381]: Error adding Membership: Error: addMembership EINVAL Dec 10 03:35:03 volumio volumio[10381]: info: Shairport-Sync Started Dec 10 03:35:03 volumio volumio[10381]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Dec 10 03:35:03 volumio volumio[10381]: info: Shairport-Sync Started Dec 10 03:35:03 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:03 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:03 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:03 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:03 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:03 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:03 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:03 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:03 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:03 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:03 volumio volumio[10381]: info: CoreCommandRouter::volumioGetState Dec 10 03:35:03 volumio volumio[10381]: info: CorePlayQueue::getTrack 0 Dec 10 03:35:03 volumio sudo[10728]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Dec 10 03:35:03 volumio sudo[10728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:03 volumio sudo[10728]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:03 volumio sudo[10723]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 10 03:35:03 volumio sudo[10723]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 10 03:35:03 volumio volumio[10381]: info: Starting Shairport Sync Dec 10 03:35:03 volumio sudo[10723]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:03 volumio volumio[10381]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Dec 10 03:35:03 volumio sudo[10737]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 10 03:35:03 volumio sudo[10737]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:03 volumio volumio[10381]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"} Dec 10 03:35:03 volumio volumio[10381]: info: Spotify Successfully logged in Dec 10 03:35:03 volumio sudo[10740]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Dec 10 03:35:03 volumio sudo[10740]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:03 volumio volumio[10381]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 03:35:03 volumio volumio[10381]: info: [1765359303450] CoreMusicLibrary::Adding element Spotify Dec 10 03:35:03 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 03:35:03 volumio volumio[10381]: Cannot find translation for source Bandcamp Discover Dec 10 03:35:03 volumio volumio[10381]: Cannot find translation for source SoundCloud Dec 10 03:35:03 volumio volumio[10381]: Cannot find translation for source YouTube2 Dec 10 03:35:03 volumio volumio[10381]: Cannot find translation for source YouTube Music Dec 10 03:35:03 volumio volumio[10381]: Cannot find translation for source Podcast Dec 10 03:35:03 volumio volumio[10381]: Cannot find translation for source Volusonic Dec 10 03:35:03 volumio volumio[10381]: Cannot find translation for source Spotify Dec 10 03:35:03 volumio systemd[1]: Reloading. Dec 10 03:35:03 volumio volumio[10381]: info: [squeezelite_mc] Notification listener started Dec 10 03:35:03 volumio volumio[10381]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180) Dec 10 03:35:04 volumio volumio[10381]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"id":"00:04:20:27:50:e8","uuid":"01ef6d9b3e5a11e37681969e3bc3ac56","ip":"192.168.1.148","name":"Squeezebox Radio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}},{"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}}] Dec 10 03:35:04 volumio volumio[10381]: info: [squeezelite_mc] Player found: {"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}} Dec 10 03:35:04 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:04 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:04 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:04 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 10 03:35:05 volumio volumio[10381]: info: CoreCommandRouter::volumioGetState Dec 10 03:35:05 volumio volumio[10381]: info: CorePlayQueue::getTrack 0 Dec 10 03:35:05 volumio volumio[10381]: info: go-librespot daemon successfully initialized Dec 10 03:35:05 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 10 03:35:05 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 10 03:35:05 volumio sudo[10740]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:05 volumio volumio[10381]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 10 03:35:05 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 10 03:35:05 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 10 03:35:05 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 03:35:05 volumio systemd[1]: shairport-sync.service: Consumed 1.493s CPU time. Dec 10 03:35:05 volumio sudo[10761]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 10 03:35:05 volumio sudo[10761]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:05 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 03:35:05 volumio sudo[10737]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Dec 10 03:35:05 volumio volumio[10381]: info: Shairport-Sync Started Dec 10 03:35:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:05 volumio sudo[10761]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:05 volumio go-librespot[10777]: go-librespot daemon starting... Dec 10 03:35:05 volumio volumio[10381]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Dec 10 03:35:05 volumio go-librespot[10778]: time="2025-12-10T03:35:05-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:35:05 volumio go-librespot[10778]: time="2025-12-10T03:35:05-06:00" level=debug msg="app state loaded" Dec 10 03:35:05 volumio go-librespot[10778]: time="2025-12-10T03:35:05-06:00" level=debug msg="stored credentials not found" Dec 10 03:35:05 volumio go-librespot[10778]: time="2025-12-10T03:35:05-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:35:05 volumio sudo[10785]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Dec 10 03:35:05 volumio sudo[10785]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:06 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 10 03:35:06 volumio volumio[10381]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'disconnect' Dec 10 03:35:06 volumio volumio[10381]: info: CoreCommandRouter::volumioGetState Dec 10 03:35:06 volumio volumio[10381]: info: CorePlayQueue::getTrack 0 Dec 10 03:35:06 volumio go-librespot[10778]: time="2025-12-10T03:35:06-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:35:06 volumio go-librespot[10778]: time="2025-12-10T03:35:06-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:35:06 volumio go-librespot[10778]: time="2025-12-10T03:35:06-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:35:06 volumio go-librespot[10778]: time="2025-12-10T03:35:06-06:00" level=info msg="zeroconf server listening on port 36403" Dec 10 03:35:06 volumio systemd[1]: squeezelite.service: Deactivated successfully. Dec 10 03:35:06 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 10 03:35:06 volumio go-librespot[10778]: time="2025-12-10T03:35:06-06:00" level=debug msg="obtained new client token: AAAruT/oWRRfIkwJithybQIDHpFEn/pZpe8MimPMwSx1UZ4SIO+1f3uNybY/zCVJ/ll39/Hd44VKI44/xKnmnVhcP0Hz+PXK0wy20cxlF31EAD7VRLMwoEEx4cZQlH9CCHOE7vMHmU2875EKwd1EoDKspMXpK3LvNxgTNafuZ2A5J8HhV5I1CVIEA7MSPozEbvlI1Oyfg7TPJh1Nck1l8DO85yFXYt4/K3thTf0oc43x6MjGWCe3of7KDA==" Dec 10 03:35:06 volumio sudo[10785]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:06 volumio go-librespot[10778]: time="2025-12-10T03:35:06-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:35:06 volumio go-librespot[10778]: time="2025-12-10T03:35:06-06:00" level=debug msg="completed keyexchange" Dec 10 03:35:06 volumio go-librespot[10778]: time="2025-12-10T03:35:06-06:00" level=debug msg="completed challenge" Dec 10 03:35:06 volumio go-librespot[10778]: time="2025-12-10T03:35:06-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:35:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:35:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:35:06 volumio volumio[10381]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 10 03:35:06 volumio sudo[10791]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 10 03:35:06 volumio sudo[10791]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:06 volumio sudo[10791]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:06 volumio volumio[10381]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Dec 10 03:35:07 volumio sudo[10795]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Dec 10 03:35:07 volumio sudo[10795]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:07 volumio sudo[10795]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:07 volumio volumio[10381]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Dec 10 03:35:07 volumio sudo[10798]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Dec 10 03:35:07 volumio sudo[10798]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:07 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 10 03:35:07 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 10 03:35:07 volumio sudo[10798]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:07 volumio mpd[10738]: 2025-12-10T03:35:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 10 03:35:07 volumio volumio[10381]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'connect' Dec 10 03:35:07 volumio volumio[10381]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180) Dec 10 03:35:07 volumio volumio[10381]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"id":"00:04:20:27:50:e8","uuid":"01ef6d9b3e5a11e37681969e3bc3ac56","ip":"192.168.1.148","name":"Squeezebox Radio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}},{"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}}] Dec 10 03:35:07 volumio volumio[10381]: info: [squeezelite_mc] Player found: {"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}} Dec 10 03:35:07 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 10 03:35:07 volumio sudo[10604]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:07 volumio sudo[10698]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:07 volumio sudo[10588]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:07 volumio volumio[10381]: error: MPD error: The expression evaluated to a falsy value: Dec 10 03:35:07 volumio volumio[10381]: assert.ok(self.idling) Dec 10 03:35:07 volumio volumio[10381]: error: The expression evaluated to a falsy value: Dec 10 03:35:07 volumio volumio[10381]: assert.ok(self.idling) Dec 10 03:35:07 volumio volumio[10381]: error: MPD error: The expression evaluated to a falsy value: Dec 10 03:35:07 volumio volumio[10381]: assert.ok(self.idling) Dec 10 03:35:07 volumio volumio[10381]: error: The expression evaluated to a falsy value: Dec 10 03:35:07 volumio volumio[10381]: assert.ok(self.idling) Dec 10 03:35:07 volumio volumio[10381]: info: MPD running with PID10738 Dec 10 03:35:07 volumio volumio[10381]: ,establishing connection Dec 10 03:35:07 volumio volumio[10381]: error: updateQueue error: null Dec 10 03:35:07 volumio volumio[10381]: error: updateQueue error: null Dec 10 03:35:07 volumio volumio[10381]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 10 03:35:07 volumio sudo[10809]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 10 03:35:07 volumio sudo[10809]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:07 volumio sudo[10809]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:08 volumio volumio[10381]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 10 03:35:08 volumio sudo[10826]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 10 03:35:08 volumio sudo[10826]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:08 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:35:08 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:35:08 volumio sudo[10826]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:08 volumio volumio[10381]: info: CoreCommandRouter::volumioGetState Dec 10 03:35:08 volumio volumio[10381]: info: CorePlayQueue::getTrack 0 Dec 10 03:35:08 volumio volumio[10381]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 10 03:35:08 volumio sudo[10829]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 10 03:35:08 volumio sudo[10829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:09 volumio sudo[10829]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:09 volumio volumio[10381]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 10 03:35:09 volumio sudo[10832]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 10 03:35:09 volumio sudo[10832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. Dec 10 03:35:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:09 volumio go-librespot[10834]: go-librespot daemon starting... Dec 10 03:35:09 volumio go-librespot[10835]: time="2025-12-10T03:35:09-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:35:09 volumio go-librespot[10835]: time="2025-12-10T03:35:09-06:00" level=debug msg="app state loaded" Dec 10 03:35:09 volumio go-librespot[10835]: time="2025-12-10T03:35:09-06:00" level=debug msg="stored credentials not found" Dec 10 03:35:09 volumio sudo[10832]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:09 volumio go-librespot[10835]: time="2025-12-10T03:35:09-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:35:09 volumio go-librespot[10835]: time="2025-12-10T03:35:09-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:35:09 volumio go-librespot[10835]: time="2025-12-10T03:35:09-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:35:09 volumio go-librespot[10835]: time="2025-12-10T03:35:09-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:35:09 volumio go-librespot[10835]: time="2025-12-10T03:35:09-06:00" level=info msg="zeroconf server listening on port 34409" Dec 10 03:35:10 volumio go-librespot[10835]: time="2025-12-10T03:35:10-06:00" level=debug msg="obtained new client token: AACPD6qdcAZyIzpC4w+qsiffLn15LA//OzWo7TPI0seiprAsRgPkrIFTSajM1XYYhgYEkXSPFs7dTi5oR9tzAejJEKzC5EACyEhLt15kI3B1BLzBP9vCf4JzFu6C+IqKuJxSklM7Z8efz6C+AO7hPasAXB+qp5SUX9eATENdiBkUMywCh/Vo4x7Py8EmBtjWuzwq+i9W3OzQpENz2EdZEZw9LRMv/+oUVpGsy9HzftO+OzouUg9e1IQRFQ==" Dec 10 03:35:10 volumio go-librespot[10835]: time="2025-12-10T03:35:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:35:10 volumio go-librespot[10835]: time="2025-12-10T03:35:10-06:00" level=debug msg="completed keyexchange" Dec 10 03:35:10 volumio go-librespot[10835]: time="2025-12-10T03:35:10-06:00" level=debug msg="completed challenge" Dec 10 03:35:10 volumio go-librespot[10835]: time="2025-12-10T03:35:10-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:35:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:35:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:35:10 volumio volumio[10381]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 10 03:35:10 volumio sudo[10845]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 10 03:35:10 volumio sudo[10845]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:10 volumio sudo[10845]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:10 volumio volumio[10381]: info: Completed starting Core Plugins Dec 10 03:35:10 volumio volumio[10381]: info: ------------------------------------------- Dec 10 03:35:10 volumio volumio[10381]: info: ----- MyVolumio plugins startup ---- Dec 10 03:35:10 volumio volumio[10381]: info: ------------------------------------------- Dec 10 03:35:10 volumio volumio[10381]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 10 03:35:10 volumio sudo[10848]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 10 03:35:10 volumio sudo[10848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:10 volumio sudo[10850]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 10 03:35:10 volumio sudo[10850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:10 volumio sudo[10853]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 10 03:35:10 volumio sudo[10853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:10 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 10 03:35:10 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 10 03:35:10 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 10 03:35:10 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 10 03:35:10 volumio sudo[10850]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:10 volumio sudo[10848]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:10 volumio mpd_monitor.sh[10856]: MPD Monitor Service: Starting MPD Monitor Service Dec 10 03:35:10 volumio sudo[10853]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:10 volumio volumio[10381]: info: Successfully started MPD Monitor Dec 10 03:35:10 volumio volumio[10381]: info: Successfully started MPD Monitor Dec 10 03:35:10 volumio volumio[10381]: info: Successfully started MPD Monitor Dec 10 03:35:11 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:35:11 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:35:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. Dec 10 03:35:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:13 volumio go-librespot[10860]: go-librespot daemon starting... Dec 10 03:35:13 volumio go-librespot[10861]: time="2025-12-10T03:35:13-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:35:13 volumio go-librespot[10861]: time="2025-12-10T03:35:13-06:00" level=debug msg="app state loaded" Dec 10 03:35:13 volumio go-librespot[10861]: time="2025-12-10T03:35:13-06:00" level=debug msg="stored credentials not found" Dec 10 03:35:13 volumio go-librespot[10861]: time="2025-12-10T03:35:13-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:35:13 volumio go-librespot[10861]: time="2025-12-10T03:35:13-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 10 03:35:13 volumio go-librespot[10861]: time="2025-12-10T03:35:13-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 10 03:35:13 volumio go-librespot[10861]: time="2025-12-10T03:35:13-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 10 03:35:13 volumio go-librespot[10861]: time="2025-12-10T03:35:13-06:00" level=info msg="zeroconf server listening on port 33577" Dec 10 03:35:13 volumio go-librespot[10861]: time="2025-12-10T03:35:13-06:00" level=debug msg="obtained new client token: AABxK1VyFDzBk3Zwa995XvNOik1TOQnnRaRvPTCN4r0KvZntD5dm19zkA9EbT+PaSq4jUEqcB/dJYJLzeSGnrM5nML0R1nVIq9hDq/2LVZG8oinDB7NAgbhBtCAMGPLGdY4o84GkPhYDa3hevBzWAS+3VO6LJhX+fvFeBAcyPUW18+pKJxMTkLfgy5Do5MYWK6Rl3ujVRiUXhPVo4t2olFPU0U+2SbaAmhGN34X5rueH1sMcL8uorNf2CA==" Dec 10 03:35:13 volumio go-librespot[10861]: time="2025-12-10T03:35:13-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:35:13 volumio go-librespot[10861]: time="2025-12-10T03:35:13-06:00" level=debug msg="completed keyexchange" Dec 10 03:35:13 volumio go-librespot[10861]: time="2025-12-10T03:35:13-06:00" level=debug msg="completed challenge" Dec 10 03:35:13 volumio go-librespot[10861]: time="2025-12-10T03:35:13-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:35:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:35:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:35:15 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:35:15 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:35:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. Dec 10 03:35:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:16 volumio go-librespot[10868]: go-librespot daemon starting... Dec 10 03:35:17 volumio go-librespot[10869]: time="2025-12-10T03:35:17-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:35:17 volumio go-librespot[10869]: time="2025-12-10T03:35:17-06:00" level=debug msg="app state loaded" Dec 10 03:35:17 volumio go-librespot[10869]: time="2025-12-10T03:35:17-06:00" level=debug msg="stored credentials not found" Dec 10 03:35:17 volumio go-librespot[10869]: time="2025-12-10T03:35:17-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:35:17 volumio go-librespot[10869]: time="2025-12-10T03:35:17-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:35:17 volumio go-librespot[10869]: time="2025-12-10T03:35:17-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:35:17 volumio go-librespot[10869]: time="2025-12-10T03:35:17-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:35:17 volumio go-librespot[10869]: time="2025-12-10T03:35:17-06:00" level=info msg="zeroconf server listening on port 41109" Dec 10 03:35:17 volumio go-librespot[10869]: time="2025-12-10T03:35:17-06:00" level=debug msg="obtained new client token: AAAnHnUcBXXU/dkoWAwYhvymjsNAdmZTrTnKhrNCDfQkpThifITvwrUymbWSGO2IQrFqCTT4LockPgRFwKxrYiaek+J91H5wvulLGRCKUVMSLSVzf3AevNL3EeIY/sgdYRH6zwpOM0jcMHHnQU+fiTrZHcjj2+tLNiIaQEL8IAgZV1fd+6puDRF+morhcvp2lXcygKfPgsp3ZPcy5nyJ5Rhr0mnqoTtiClQfkeIWA0dISOHRBSZZ5xVGMQ==" Dec 10 03:35:17 volumio go-librespot[10869]: time="2025-12-10T03:35:17-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:35:17 volumio go-librespot[10869]: time="2025-12-10T03:35:17-06:00" level=debug msg="completed keyexchange" Dec 10 03:35:17 volumio go-librespot[10869]: time="2025-12-10T03:35:17-06:00" level=debug msg="completed challenge" Dec 10 03:35:17 volumio go-librespot[10869]: time="2025-12-10T03:35:17-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:35:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:35:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:35:18 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:35:18 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 10 03:35:18 volumio volumio[10381]: info: Adding plugin bluetooth to MyMusic Plugins Dec 10 03:35:18 volumio volumio[10381]: info: Adding plugin multiroom to MyMusic Plugins Dec 10 03:35:18 volumio volumio[10381]: info: Adding plugin metavolumio to MyMusic Plugins Dec 10 03:35:18 volumio volumio[10381]: info: Adding plugin cd_controller to MyMusic Plugins Dec 10 03:35:18 volumio volumio[10381]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 10 03:35:18 volumio volumio[10381]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 10 03:35:18 volumio volumio[10381]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 10 03:35:18 volumio volumio[10381]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 10 03:35:19 volumio volumio[10381]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 10 03:35:19 volumio volumio[10381]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 10 03:35:19 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:19 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:19 volumio volumio[10381]: info: Starting MyVolumio Remote Streaming Endpoints Dec 10 03:35:19 volumio volumio[10381]: info: MyVolumio login type: Token Dec 10 03:35:19 volumio volumio[10381]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 10 03:35:19 volumio volumio[10381]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 10 03:35:20 volumio volumio[10381]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 10 03:35:20 volumio volumio[10381]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 10 03:35:20 volumio volumio[10381]: info: Streaming services startup Dec 10 03:35:20 volumio volumio[10381]: info: Starting Streaming Daemon Dec 10 03:35:20 volumio sudo[10892]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 10 03:35:20 volumio sudo[10892]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:20 volumio volumio[10381]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 10 03:35:20 volumio sudo[10892]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:20 volumio volumio[10381]: error: Cannot start Volumio Streaming Daemon Dec 10 03:35:20 volumio volumio[10381]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 10 03:35:20 volumio volumio[10381]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 10 03:35:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49. Dec 10 03:35:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:20 volumio go-librespot[10899]: go-librespot daemon starting... Dec 10 03:35:20 volumio go-librespot[10900]: time="2025-12-10T03:35:20-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:35:20 volumio go-librespot[10900]: time="2025-12-10T03:35:20-06:00" level=debug msg="app state loaded" Dec 10 03:35:20 volumio go-librespot[10900]: time="2025-12-10T03:35:20-06:00" level=debug msg="stored credentials not found" Dec 10 03:35:20 volumio go-librespot[10900]: time="2025-12-10T03:35:20-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:35:20 volumio volumio[10381]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 10 03:35:21 volumio go-librespot[10900]: time="2025-12-10T03:35:21-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:35:21 volumio go-librespot[10900]: time="2025-12-10T03:35:21-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:35:21 volumio go-librespot[10900]: time="2025-12-10T03:35:21-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:35:21 volumio go-librespot[10900]: time="2025-12-10T03:35:21-06:00" level=info msg="zeroconf server listening on port 38221" Dec 10 03:35:21 volumio go-librespot[10900]: time="2025-12-10T03:35:21-06:00" level=debug msg="obtained new client token: AACmqHfRmXzBE6IUHpoGrJbtbrQpsGkbReaRM1lQ4M3Ssph86waxQkTSXBHLcYI8XjSj/wQ0Kp1enRCdVbYEkbe2sUqx8IgGV4rx3/PVT9fTg4yqbH6KYYc0jeenul4P/eLoe3K++XgJGQKE/k8vLpOXjuE9bfRR8PtvJCaYrbBAmaZEREoyR1Pk3YlxMpWd+2ej4xDyaSGNgYzEloxfTjzLPWUJf5iBAsk6Mw1f5dPQMaLWR7oTljA=" Dec 10 03:35:21 volumio go-librespot[10900]: time="2025-12-10T03:35:21-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:35:21 volumio go-librespot[10900]: time="2025-12-10T03:35:21-06:00" level=debug msg="completed keyexchange" Dec 10 03:35:21 volumio go-librespot[10900]: time="2025-12-10T03:35:21-06:00" level=debug msg="completed challenge" Dec 10 03:35:21 volumio go-librespot[10900]: time="2025-12-10T03:35:21-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:35:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:35:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:35:21 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:35:21 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:35:21 volumio volumio[10381]: info: MyVolumio token set successfully Dec 10 03:35:21 volumio volumio[10381]: info: MYVOLUMIO: Adding device Dec 10 03:35:21 volumio volumio[10381]: info: MYVOLUMIO: Evaluating Server Dec 10 03:35:21 volumio volumio[10381]: info: MyVolumio status changed Dec 10 03:35:21 volumio volumio[10381]: info: Streaming services startup Dec 10 03:35:21 volumio volumio[10381]: info: Starting Streaming Daemon Dec 10 03:35:21 volumio volumio[10381]: info: Removing browser output: myVolumio user plan is not superstar Dec 10 03:35:21 volumio volumio[10381]: info: Removing audio output: Dec 10 03:35:21 volumio volumio[10381]: info: Stoppping Tunnel 1 Dec 10 03:35:21 volumio sudo[10928]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 10 03:35:21 volumio sudo[10928]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:21 volumio sudo[10930]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 10 03:35:21 volumio sudo[10930]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:35:21 volumio 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. Dec 10 03:35:21 volumio 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. Dec 10 03:35:21 volumio sudo[10928]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:21 volumio volumio[10381]: error: Cannot start Volumio Streaming Daemon Dec 10 03:35:21 volumio volumio[10381]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 10 03:35:21 volumio volumio[10381]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 10 03:35:21 volumio 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. Dec 10 03:35:21 volumio 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. Dec 10 03:35:21 volumio 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. Dec 10 03:35:21 volumio 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. Dec 10 03:35:21 volumio 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. Dec 10 03:35:21 volumio 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. Dec 10 03:35:21 volumio sudo[10930]: pam_unix(sudo:session): session closed for user root Dec 10 03:35:21 volumio volumio[10381]: info: Remote SSH Stopped Dec 10 03:35:21 volumio volumio[10381]: info: Setting Geolocation for MyVolumio to us2 Dec 10 03:35:21 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:21 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:21 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:22 volumio volumio[10381]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 10 03:35:22 volumio volumio[10381]: info: Updating MyVolumio device info Dec 10 03:35:22 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:22 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:22 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:23 volumio volumio[10381]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 10 03:35:24 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:35:24 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:35:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. Dec 10 03:35:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:24 volumio go-librespot[10933]: go-librespot daemon starting... Dec 10 03:35:24 volumio go-librespot[10934]: time="2025-12-10T03:35:24-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:35:24 volumio go-librespot[10934]: time="2025-12-10T03:35:24-06:00" level=debug msg="app state loaded" Dec 10 03:35:24 volumio go-librespot[10934]: time="2025-12-10T03:35:24-06:00" level=debug msg="stored credentials not found" Dec 10 03:35:24 volumio go-librespot[10934]: time="2025-12-10T03:35:24-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:35:24 volumio go-librespot[10934]: time="2025-12-10T03:35:24-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:35:24 volumio go-librespot[10934]: time="2025-12-10T03:35:24-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:35:24 volumio go-librespot[10934]: time="2025-12-10T03:35:24-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:35:24 volumio go-librespot[10934]: time="2025-12-10T03:35:24-06:00" level=info msg="zeroconf server listening on port 44301" Dec 10 03:35:24 volumio go-librespot[10934]: time="2025-12-10T03:35:24-06:00" level=debug msg="obtained new client token: AAARsSirD0m0G/gdWnD28vyyQD9ihPURwHUK6IeWF3lSXce8p0HSfkno5EVVNAHGJtplIQuVIKYGluV5Ohcq83UT3pbrBUKv12fpr/+dzRocE+yFSYLLzK6WaElU+IlzEarPn/5sfg9CJpG9kNvNowv8qH01DnAViTjxZh8b0bxrmHTk9d/A/J5C0ynpxfa0D+vq4z83gXflQ1nIqu52ou8DR4/pnaN60yfvRa+TnNa9Q4tW8tHnzAoY8Q==" Dec 10 03:35:24 volumio go-librespot[10934]: time="2025-12-10T03:35:24-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:35:24 volumio go-librespot[10934]: time="2025-12-10T03:35:24-06:00" level=debug msg="completed keyexchange" Dec 10 03:35:24 volumio go-librespot[10934]: time="2025-12-10T03:35:24-06:00" level=debug msg="completed challenge" Dec 10 03:35:24 volumio go-librespot[10934]: time="2025-12-10T03:35:24-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:35:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:35:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:35:26 volumio volumio[10381]: info: MYVOLUMIO: Adding device Dec 10 03:35:26 volumio volumio[10381]: info: MYVOLUMIO: Evaluating Server Dec 10 03:35:26 volumio volumio[10381]: info: Setting Geolocation for MyVolumio to us1 Dec 10 03:35:26 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:26 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:26 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:26 volumio volumio[10381]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 10 03:35:27 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:35:27 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:35:27 volumio volumio[10381]: info: Updating MyVolumio device info Dec 10 03:35:27 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:27 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:27 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:27 volumio volumio[10381]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 10 03:35:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. Dec 10 03:35:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:28 volumio go-librespot[10960]: go-librespot daemon starting... Dec 10 03:35:28 volumio go-librespot[10961]: time="2025-12-10T03:35:28-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:35:28 volumio go-librespot[10961]: time="2025-12-10T03:35:28-06:00" level=debug msg="app state loaded" Dec 10 03:35:28 volumio go-librespot[10961]: time="2025-12-10T03:35:28-06:00" level=debug msg="stored credentials not found" Dec 10 03:35:28 volumio go-librespot[10961]: time="2025-12-10T03:35:28-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:35:28 volumio go-librespot[10961]: time="2025-12-10T03:35:28-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:35:28 volumio go-librespot[10961]: time="2025-12-10T03:35:28-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:35:28 volumio go-librespot[10961]: time="2025-12-10T03:35:28-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:35:28 volumio go-librespot[10961]: time="2025-12-10T03:35:28-06:00" level=info msg="zeroconf server listening on port 46197" Dec 10 03:35:28 volumio go-librespot[10961]: time="2025-12-10T03:35:28-06:00" level=debug msg="obtained new client token: AAAoQRlVk8oOSRW5NlNJuzMBi4qQGeyebpMQ3bfioAm/FJ7lcz+9ghDCWhSK7yMTiG6aVN66G0XVN5VAf4OE4HPOpYt3afXZNZJkD9xiYV2/gK/fbY9n3T0Cmsa6aeb+wfUIb+7GQ+x4g1YUQUNZLb6qH/9qM4/15nXZKScIC/nYD2nv8k8xXcGB87nCqmbrRq8So6+SsmtLbky6IyyXrHiLVxcKxexOcHCQ8PGbSO1O7bs+dX8LJ5DurQ==" Dec 10 03:35:28 volumio go-librespot[10961]: time="2025-12-10T03:35:28-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:35:28 volumio go-librespot[10961]: time="2025-12-10T03:35:28-06:00" level=debug msg="completed keyexchange" Dec 10 03:35:28 volumio go-librespot[10961]: time="2025-12-10T03:35:28-06:00" level=debug msg="completed challenge" Dec 10 03:35:28 volumio go-librespot[10961]: time="2025-12-10T03:35:28-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:35:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:35:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:35:30 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:35:30 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:35:31 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 10 03:35:31 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:31 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 10 03:35:31 volumio volumio-remote-updater[9752]: Test mode disabled Dec 10 03:35:31 volumio volumio-remote-updater[9752]: Alpha mode disabled Dec 10 03:35:31 volumio volumio-remote-updater[9752]: Alpha legacy test mode disabled Dec 10 03:35:31 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 10 03:35:31 volumio volumio[10381]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

ANNOUNCEMENT

\n
    \n
  • Production line
    • \n
\n

FIX

\n
    \n
  • Nodejs 20.5.1 version pinning with static package fallback
    • \n
\n","title":"Update v4.073","updateavailable":true} Dec 10 03:35:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52. Dec 10 03:35:31 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 10 03:35:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:32 volumio go-librespot[10990]: go-librespot daemon starting... Dec 10 03:35:32 volumio go-librespot[10991]: time="2025-12-10T03:35:32-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:35:32 volumio go-librespot[10991]: time="2025-12-10T03:35:32-06:00" level=debug msg="app state loaded" Dec 10 03:35:32 volumio go-librespot[10991]: time="2025-12-10T03:35:32-06:00" level=debug msg="stored credentials not found" Dec 10 03:35:32 volumio go-librespot[10991]: time="2025-12-10T03:35:32-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:35:32 volumio go-librespot[10991]: time="2025-12-10T03:35:32-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:35:32 volumio go-librespot[10991]: time="2025-12-10T03:35:32-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:35:32 volumio go-librespot[10991]: time="2025-12-10T03:35:32-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:35:32 volumio go-librespot[10991]: time="2025-12-10T03:35:32-06:00" level=info msg="zeroconf server listening on port 43739" Dec 10 03:35:32 volumio go-librespot[10991]: time="2025-12-10T03:35:32-06:00" level=debug msg="obtained new client token: AAAfsmVB7inhMm0Mm4EkW002uduWAOHGeclkvitDkYNFxqnEYgAuefDWX+hc6neSDci4Bi4YtwT5jlYGmUNqdN6CgagfqMrEx2DtyGyWPXk5ZnaBhJEJT1i0eyzSGStFMSEsWtEZiinHMGOWgWNG8enk3Wp3sEZ8wcqldj3TEHKy0bQXrzdE0CmeCshJ09nSCMjcZyeT9Y/Jx76OyYT5gEwFXyFjnl4QYj6q8nY/vpX0CwFlnK8lYY5DUg==" Dec 10 03:35:32 volumio go-librespot[10991]: time="2025-12-10T03:35:32-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:35:32 volumio go-librespot[10991]: time="2025-12-10T03:35:32-06:00" level=debug msg="completed keyexchange" Dec 10 03:35:32 volumio go-librespot[10991]: time="2025-12-10T03:35:32-06:00" level=debug msg="completed challenge" Dec 10 03:35:32 volumio go-librespot[10991]: time="2025-12-10T03:35:32-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:35:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:35:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:35:33 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:35:33 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:35:34 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 10 03:35:34 volumio volumio[10381]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 10 03:35:34 volumio volumio[10381]: info: CoreCommandRouter::volumioGetState Dec 10 03:35:34 volumio volumio[10381]: info: CorePlayQueue::getTrack 0 Dec 10 03:35:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53. Dec 10 03:35:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:35 volumio go-librespot[10999]: go-librespot daemon starting... Dec 10 03:35:35 volumio go-librespot[11000]: time="2025-12-10T03:35:35-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:35:35 volumio go-librespot[11000]: time="2025-12-10T03:35:35-06:00" level=debug msg="app state loaded" Dec 10 03:35:35 volumio go-librespot[11000]: time="2025-12-10T03:35:35-06:00" level=debug msg="stored credentials not found" Dec 10 03:35:35 volumio go-librespot[11000]: time="2025-12-10T03:35:35-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:35:35 volumio go-librespot[11000]: time="2025-12-10T03:35:35-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:35:35 volumio go-librespot[11000]: time="2025-12-10T03:35:35-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:35:35 volumio go-librespot[11000]: time="2025-12-10T03:35:35-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:35:35 volumio go-librespot[11000]: time="2025-12-10T03:35:35-06:00" level=info msg="zeroconf server listening on port 33923" Dec 10 03:35:36 volumio go-librespot[11000]: time="2025-12-10T03:35:36-06:00" level=debug msg="obtained new client token: AAC3H+7nhia/1+fI8/xdEgqiNo0hnQD66kNWMkPiTZlqhV3Y4jYmVgPOr4b7/ORk0Cbo4h8yV5z2lWLnlx2cfwE4Hf96q9Q/Q9Rxj6FJ5Pdtr+o5ze8+lP+3fu0rT4Knms70cc+Fpl/AftdokC7t3G4WHQIhfCuyh6A9qPojzmSRzmp8Fm1P937N805hdfUHlh0iR50xwRkuDUUseLvlWpSrolbrNvGsQ3k9UZN6WuqGnvwy38lsHJQ=" Dec 10 03:35:36 volumio go-librespot[11000]: time="2025-12-10T03:35:36-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:35:36 volumio go-librespot[11000]: time="2025-12-10T03:35:36-06:00" level=debug msg="completed keyexchange" Dec 10 03:35:36 volumio go-librespot[11000]: time="2025-12-10T03:35:36-06:00" level=debug msg="completed challenge" Dec 10 03:35:36 volumio go-librespot[11000]: time="2025-12-10T03:35:36-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:35:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:35:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:35:36 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:35:36 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:35:39 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:35:39 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:35:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54. Dec 10 03:35:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:39 volumio go-librespot[11021]: go-librespot daemon starting... Dec 10 03:35:39 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:39 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:39 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 10 03:35:39 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 10 03:35:39 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 10 03:35:39 volumio volumio[10381]: info: CoreCommandRouter::volumioGetBrowseSources Dec 10 03:35:39 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 10 03:35:39 volumio go-librespot[11022]: time="2025-12-10T03:35:39-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:35:39 volumio go-librespot[11022]: time="2025-12-10T03:35:39-06:00" level=debug msg="app state loaded" Dec 10 03:35:39 volumio go-librespot[11022]: time="2025-12-10T03:35:39-06:00" level=debug msg="stored credentials not found" Dec 10 03:35:39 volumio go-librespot[11022]: time="2025-12-10T03:35:39-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:35:39 volumio go-librespot[11022]: time="2025-12-10T03:35:39-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:35:39 volumio go-librespot[11022]: time="2025-12-10T03:35:39-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:35:39 volumio go-librespot[11022]: time="2025-12-10T03:35:39-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:35:39 volumio go-librespot[11022]: time="2025-12-10T03:35:39-06:00" level=info msg="zeroconf server listening on port 39367" Dec 10 03:35:39 volumio go-librespot[11022]: time="2025-12-10T03:35:39-06:00" level=debug msg="obtained new client token: AACTuZ5eGs0plL5cYCsb1qjBdktwPhE6dmZAr+tlyky4mxNIIGItm7c4sHv5W0jC93La+1CcN/97fyl2obWjFOLowCJ7lrekLNMkNPJaERuPwmD6AEZHkFiPG0ragMlooy4eGPZmky6NHSp+yD8Qhx7AeRW3ow6+d2FCEULFm4khA67yiz3zGgRtqf9QxtNJiDse8s98eg0ko3LfX6aIT/EmQ0R84JTdilGmLT6OUHGVJGyNYytmr5CXag==" Dec 10 03:35:39 volumio go-librespot[11022]: time="2025-12-10T03:35:39-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:35:39 volumio go-librespot[11022]: time="2025-12-10T03:35:39-06:00" level=debug msg="completed keyexchange" Dec 10 03:35:39 volumio go-librespot[11022]: time="2025-12-10T03:35:39-06:00" level=debug msg="completed challenge" Dec 10 03:35:39 volumio go-librespot[11022]: time="2025-12-10T03:35:39-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:35:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:35:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:35:40 volumio volumio[10381]: error: MyVolumio Plugin failed to authenticate in a timely fashion Dec 10 03:35:40 volumio volumio[10381]: info: Completed starting MyVolumio Plugin Dec 10 03:35:40 volumio volumio[10381]: [Metrics] CommandRouter: 54s 445.10ms Dec 10 03:35:40 volumio volumio[10381]: info: CoreCommandRouter::volumiosetStartupVolume Dec 10 03:35:40 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 03:35:40 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 03:35:40 volumio volumio[10381]: info: CoreCommandRouter::Close All Modals sent Dec 10 03:35:40 volumio volumio[10381]: info: CoreCommandRouter::Close All Modals sent Dec 10 03:35:41 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 10 03:35:41 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 10 03:35:41 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 10 03:35:42 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:35:42 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:35:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55. Dec 10 03:35:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:43 volumio go-librespot[11035]: go-librespot daemon starting... Dec 10 03:35:43 volumio go-librespot[11036]: time="2025-12-10T03:35:43-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:35:43 volumio go-librespot[11036]: time="2025-12-10T03:35:43-06:00" level=debug msg="app state loaded" Dec 10 03:35:43 volumio go-librespot[11036]: time="2025-12-10T03:35:43-06:00" level=debug msg="stored credentials not found" Dec 10 03:35:43 volumio go-librespot[11036]: time="2025-12-10T03:35:43-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:35:43 volumio go-librespot[11036]: time="2025-12-10T03:35:43-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:35:43 volumio go-librespot[11036]: time="2025-12-10T03:35:43-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:35:43 volumio go-librespot[11036]: time="2025-12-10T03:35:43-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:35:43 volumio go-librespot[11036]: time="2025-12-10T03:35:43-06:00" level=info msg="zeroconf server listening on port 36253" Dec 10 03:35:43 volumio go-librespot[11036]: time="2025-12-10T03:35:43-06:00" level=debug msg="obtained new client token: AADAtTBAfHvbVO4REf9Pbijzg3YgPYGNQWtEt1yMTj+ujULc6zzK/1ATVqX99rlQrElGW9EaiDkm379Clj06IEnGBaih4d7C4bFyzJMwONh4SSsIks+bAmtnt2MP4Ulyd+TJOkV1ell9Orvnzhi7GLXm5UgdEiPhVhg6Z5DlMrdBOEvBBdcSv3iKDiSpQ6ef6gj1byqQupSf0BRMjsqztwrnCJhGia8JbKo649f52jvx8AOM3sqvSJYzUQ==" Dec 10 03:35:43 volumio go-librespot[11036]: time="2025-12-10T03:35:43-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:35:43 volumio go-librespot[11036]: time="2025-12-10T03:35:43-06:00" level=debug msg="completed keyexchange" Dec 10 03:35:43 volumio go-librespot[11036]: time="2025-12-10T03:35:43-06:00" level=debug msg="completed challenge" Dec 10 03:35:43 volumio go-librespot[11036]: time="2025-12-10T03:35:43-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:35:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:35:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:35:45 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:35:45 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:35:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56. Dec 10 03:35:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:46 volumio go-librespot[11043]: go-librespot daemon starting... Dec 10 03:35:47 volumio go-librespot[11044]: time="2025-12-10T03:35:47-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:35:47 volumio go-librespot[11044]: time="2025-12-10T03:35:47-06:00" level=debug msg="app state loaded" Dec 10 03:35:47 volumio go-librespot[11044]: time="2025-12-10T03:35:47-06:00" level=debug msg="stored credentials not found" Dec 10 03:35:47 volumio go-librespot[11044]: time="2025-12-10T03:35:47-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:35:47 volumio go-librespot[11044]: time="2025-12-10T03:35:47-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:35:47 volumio go-librespot[11044]: time="2025-12-10T03:35:47-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:35:47 volumio go-librespot[11044]: time="2025-12-10T03:35:47-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:35:47 volumio go-librespot[11044]: time="2025-12-10T03:35:47-06:00" level=info msg="zeroconf server listening on port 46867" Dec 10 03:35:47 volumio go-librespot[11044]: time="2025-12-10T03:35:47-06:00" level=debug msg="obtained new client token: AACHBD9YHXwgA/QMUQcLMKPLVhM2jbTMvT/mHBK5qSSNZpdI53L7TiXY5nW1oVvFmmn4HPs+HJ1qsrUMIh02sTlqWLIEEKWHl339qbnaYfihzLt3Ws9AehU7O8Mn/fGKnZtrOvalruvFs1fZPq28mpOscV9cmInklkR8zlEKyVjex3bbLNwFWTNpkwDDGFhy039clRPljyjAWwspwVD4i1IiCYYeTzSXaIyVMtgj4FepNmv0zJHphj/6yA==" Dec 10 03:35:47 volumio go-librespot[11044]: time="2025-12-10T03:35:47-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:35:47 volumio go-librespot[11044]: time="2025-12-10T03:35:47-06:00" level=debug msg="completed keyexchange" Dec 10 03:35:47 volumio go-librespot[11044]: time="2025-12-10T03:35:47-06:00" level=debug msg="completed challenge" Dec 10 03:35:47 volumio volumio[10381]: info: BOOT COMPLETED Dec 10 03:35:47 volumio go-librespot[11044]: time="2025-12-10T03:35:47-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:35:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:35:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:35:48 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:35:48 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:35:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57. Dec 10 03:35:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:50 volumio go-librespot[11065]: go-librespot daemon starting... Dec 10 03:35:50 volumio go-librespot[11066]: time="2025-12-10T03:35:50-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:35:50 volumio go-librespot[11066]: time="2025-12-10T03:35:50-06:00" level=debug msg="app state loaded" Dec 10 03:35:50 volumio go-librespot[11066]: time="2025-12-10T03:35:50-06:00" level=debug msg="stored credentials not found" Dec 10 03:35:50 volumio go-librespot[11066]: time="2025-12-10T03:35:50-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:35:50 volumio go-librespot[11066]: time="2025-12-10T03:35:50-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:35:50 volumio go-librespot[11066]: time="2025-12-10T03:35:50-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:35:50 volumio go-librespot[11066]: time="2025-12-10T03:35:50-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:35:50 volumio go-librespot[11066]: time="2025-12-10T03:35:50-06:00" level=info msg="zeroconf server listening on port 41131" Dec 10 03:35:51 volumio go-librespot[11066]: time="2025-12-10T03:35:51-06:00" level=debug msg="obtained new client token: AAC0jaqXYvhk7FkCv8I+KtkohY2DMWEIDlUXZwJAAtCg8ZnYnimfLxvw71I0+UInG362oYcKJbHjyzYpr5hKu54gPrhlAmHUxr4sCX3I/paZkH9gvlo34IOtSTCbrz7S4e66DDWxsPH502Ywji4mHnjYHC+GTc21bYKFQP+HVxGM6cUY72LO5N7XL8tcR5d35N3yYkf2YHvR9Me5YK+R4tQFOzYOw/IJ6pphLJ/phjWBrjszsu3BQ2U=" Dec 10 03:35:51 volumio go-librespot[11066]: time="2025-12-10T03:35:51-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:35:51 volumio go-librespot[11066]: time="2025-12-10T03:35:51-06:00" level=debug msg="completed keyexchange" Dec 10 03:35:51 volumio go-librespot[11066]: time="2025-12-10T03:35:51-06:00" level=debug msg="completed challenge" Dec 10 03:35:51 volumio go-librespot[11066]: time="2025-12-10T03:35:51-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:35:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:35:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:35:51 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:35:51 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:35:54 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:35:54 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:35:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 58. Dec 10 03:35:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:54 volumio go-librespot[11078]: go-librespot daemon starting... Dec 10 03:35:54 volumio go-librespot[11079]: time="2025-12-10T03:35:54-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:35:54 volumio go-librespot[11079]: time="2025-12-10T03:35:54-06:00" level=debug msg="app state loaded" Dec 10 03:35:54 volumio go-librespot[11079]: time="2025-12-10T03:35:54-06:00" level=debug msg="stored credentials not found" Dec 10 03:35:54 volumio go-librespot[11079]: time="2025-12-10T03:35:54-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:35:54 volumio go-librespot[11079]: time="2025-12-10T03:35:54-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:35:54 volumio go-librespot[11079]: time="2025-12-10T03:35:54-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:35:54 volumio go-librespot[11079]: time="2025-12-10T03:35:54-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:35:54 volumio go-librespot[11079]: time="2025-12-10T03:35:54-06:00" level=info msg="zeroconf server listening on port 36831" Dec 10 03:35:54 volumio go-librespot[11079]: time="2025-12-10T03:35:54-06:00" level=debug msg="obtained new client token: AAAB/2UaPqMMcHyDa82jBlqAvriAdOF5KmEkO1RmzBzOYrulvbsqISPTb8LAeKp9LKb7RhuLWpfZxki1Oqzy6k8h95EE5Q4CoDZwAcmVoFaf9VORUeAwW0CuqtjGHmHGtEEFxz0JHWJbE1ceDVYdG0xlghgYoBvEMeyJ4t+ERL+A1aigNSSTDz1DErCdqXL8DpAXzBOFL+fvskQ3mSI9lrNL9tig0ggcIHuUF/QiaYgRqMlmopWwuWTIug==" Dec 10 03:35:54 volumio go-librespot[11079]: time="2025-12-10T03:35:54-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:35:54 volumio go-librespot[11079]: time="2025-12-10T03:35:54-06:00" level=debug msg="completed keyexchange" Dec 10 03:35:54 volumio go-librespot[11079]: time="2025-12-10T03:35:54-06:00" level=debug msg="completed challenge" Dec 10 03:35:54 volumio go-librespot[11079]: time="2025-12-10T03:35:54-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:35:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:35:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:35:57 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:35:57 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:35:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59. Dec 10 03:35:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:35:58 volumio go-librespot[11086]: go-librespot daemon starting... Dec 10 03:35:58 volumio go-librespot[11087]: time="2025-12-10T03:35:58-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:35:58 volumio go-librespot[11087]: time="2025-12-10T03:35:58-06:00" level=debug msg="app state loaded" Dec 10 03:35:58 volumio go-librespot[11087]: time="2025-12-10T03:35:58-06:00" level=debug msg="stored credentials not found" Dec 10 03:35:58 volumio go-librespot[11087]: time="2025-12-10T03:35:58-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:35:58 volumio go-librespot[11087]: time="2025-12-10T03:35:58-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:35:58 volumio go-librespot[11087]: time="2025-12-10T03:35:58-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:35:58 volumio go-librespot[11087]: time="2025-12-10T03:35:58-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:35:58 volumio go-librespot[11087]: time="2025-12-10T03:35:58-06:00" level=info msg="zeroconf server listening on port 41111" Dec 10 03:35:58 volumio go-librespot[11087]: time="2025-12-10T03:35:58-06:00" level=debug msg="obtained new client token: AAC5qqfP9C45aklAfQZJJxeayHPGkRVLLCndRKz55gri7FY7fP+k4gLse42mENaRxyRbUKY8LjxjM/kW9HJkwSn8zrYrAnpOYKZMjKk02pn+XTpQlBbvqu/Gb7Td63b8aJIGScwYyytqhJsgDvbXMAk1yQezaeJCyXSEiaE0BMBX8mC6Uz4IHWsigJ5GDSfASzNBqHL6I0Y7BiELFLfMuw6rBGjvk7q1V0o7WabhF3vC2Ut13sBGJ16taw==" Dec 10 03:35:58 volumio go-librespot[11087]: time="2025-12-10T03:35:58-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:35:58 volumio go-librespot[11087]: time="2025-12-10T03:35:58-06:00" level=debug msg="completed keyexchange" Dec 10 03:35:58 volumio go-librespot[11087]: time="2025-12-10T03:35:58-06:00" level=debug msg="completed challenge" Dec 10 03:35:58 volumio go-librespot[11087]: time="2025-12-10T03:35:58-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:35:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:35:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:36:00 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:36:00 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:36:01 volumio volumio[10381]: info: UPDATER: Scheduling automatic update Dec 10 03:36:01 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStartTime Dec 10 03:36:01 volumio volumio[10381]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStopTime Dec 10 03:36:01 volumio volumio[10381]: info: UPDATER: Auto update will take place at: Thu Dec 11 2025 03:59:35 GMT-0600 (Central Standard Time) Dec 10 03:36:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 60. Dec 10 03:36:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:01 volumio go-librespot[11108]: go-librespot daemon starting... Dec 10 03:36:02 volumio go-librespot[11109]: time="2025-12-10T03:36:02-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:36:02 volumio go-librespot[11109]: time="2025-12-10T03:36:02-06:00" level=debug msg="app state loaded" Dec 10 03:36:02 volumio go-librespot[11109]: time="2025-12-10T03:36:02-06:00" level=debug msg="stored credentials not found" Dec 10 03:36:02 volumio go-librespot[11109]: time="2025-12-10T03:36:02-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:36:02 volumio go-librespot[11109]: time="2025-12-10T03:36:02-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 10 03:36:02 volumio go-librespot[11109]: time="2025-12-10T03:36:02-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 10 03:36:02 volumio go-librespot[11109]: time="2025-12-10T03:36:02-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 10 03:36:02 volumio go-librespot[11109]: time="2025-12-10T03:36:02-06:00" level=info msg="zeroconf server listening on port 41257" Dec 10 03:36:02 volumio go-librespot[11109]: time="2025-12-10T03:36:02-06:00" level=debug msg="obtained new client token: AACB+VwD1i6SZrJGFxJ3JULyMi49QmfjNjlBJmuxDTmynUsnevr2ZCkf8EigRRxGfU1utLTMcX64xMSrs8mi3iB10l0UUHOfH+Gqi56hOGvWjR5C6JpKvhtk665SQXQ53fuASfCqMrAHERfy3wsVdaKCjOWbxScb4ubqUIgf/i0wkePnKLMK3MeGdA1LtCmOYW6IR6TWP2bwMtjC8c+TFXQYwOfHf0wKKqqGLamheOw9dCuDI/uaK/qqhA==" Dec 10 03:36:02 volumio go-librespot[11109]: time="2025-12-10T03:36:02-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:36:02 volumio go-librespot[11109]: time="2025-12-10T03:36:02-06:00" level=debug msg="completed keyexchange" Dec 10 03:36:02 volumio go-librespot[11109]: time="2025-12-10T03:36:02-06:00" level=debug msg="completed challenge" Dec 10 03:36:02 volumio go-librespot[11109]: time="2025-12-10T03:36:02-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:36:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:36:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:36:03 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:36:03 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:36:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 61. Dec 10 03:36:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:05 volumio go-librespot[11116]: go-librespot daemon starting... Dec 10 03:36:05 volumio go-librespot[11117]: time="2025-12-10T03:36:05-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:36:05 volumio go-librespot[11117]: time="2025-12-10T03:36:05-06:00" level=debug msg="app state loaded" Dec 10 03:36:05 volumio go-librespot[11117]: time="2025-12-10T03:36:05-06:00" level=debug msg="stored credentials not found" Dec 10 03:36:05 volumio go-librespot[11117]: time="2025-12-10T03:36:05-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:36:05 volumio go-librespot[11117]: time="2025-12-10T03:36:05-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:36:05 volumio go-librespot[11117]: time="2025-12-10T03:36:05-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:36:05 volumio go-librespot[11117]: time="2025-12-10T03:36:05-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:36:05 volumio go-librespot[11117]: time="2025-12-10T03:36:05-06:00" level=info msg="zeroconf server listening on port 37901" Dec 10 03:36:06 volumio go-librespot[11117]: time="2025-12-10T03:36:06-06:00" level=debug msg="obtained new client token: AABcBzPYBnlS8gcjJ5vmz5CBHYfNeu4K05q+lp4XOhjuom8XZB/tRfpss/ldFPsghJdYUY1JFoDh7ISZfVdcjqufp6kpjTXgMn1j2dXaFKFmmV5qylFbbG0udBVK9DaDwmCeOM3UoggUbR7DjqVCbs5XgWzrxJCiqZ4/zXDijHSYN+oAjlIomHyjdPwoMDg0fFpZXYW7oir8hh52Ka5mMqIRwjtO46BG56IvOjujNf1aPA2bjve1NWI=" Dec 10 03:36:06 volumio go-librespot[11117]: time="2025-12-10T03:36:06-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:36:06 volumio go-librespot[11117]: time="2025-12-10T03:36:06-06:00" level=debug msg="completed keyexchange" Dec 10 03:36:06 volumio go-librespot[11117]: time="2025-12-10T03:36:06-06:00" level=debug msg="completed challenge" Dec 10 03:36:06 volumio go-librespot[11117]: time="2025-12-10T03:36:06-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:36:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:36:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:36:06 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:36:06 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:36:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 62. Dec 10 03:36:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:09 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:36:09 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:36:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:09 volumio go-librespot[11138]: go-librespot daemon starting... Dec 10 03:36:09 volumio go-librespot[11139]: time="2025-12-10T03:36:09-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:36:09 volumio go-librespot[11139]: time="2025-12-10T03:36:09-06:00" level=debug msg="app state loaded" Dec 10 03:36:09 volumio go-librespot[11139]: time="2025-12-10T03:36:09-06:00" level=debug msg="stored credentials not found" Dec 10 03:36:09 volumio go-librespot[11139]: time="2025-12-10T03:36:09-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:36:09 volumio go-librespot[11139]: time="2025-12-10T03:36:09-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 10 03:36:09 volumio go-librespot[11139]: time="2025-12-10T03:36:09-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 10 03:36:09 volumio go-librespot[11139]: time="2025-12-10T03:36:09-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 10 03:36:09 volumio go-librespot[11139]: time="2025-12-10T03:36:09-06:00" level=info msg="zeroconf server listening on port 39485" Dec 10 03:36:09 volumio go-librespot[11139]: time="2025-12-10T03:36:09-06:00" level=debug msg="obtained new client token: AAADwLqacWjMboEbmFCo1nUtPLSQx93AQAhcQcL65CQIlMp2L6kZNkVjL1eLDndeQIkjB6us6xIm22iU72thguv5be2gITzeeOKiOJbFgxUNJPzQaX2CpaVtUE4VbdTNMd/SFgb5Hoy9xwJXczObtCEnEEwc8nyB/MJexdnOPO9FgnGDmmzrtz2NB3HY+Hc5qugnAjV98YjyeVXVgbs2ZbSA4dYWIHuL9vUU2hi6Q92hw3ey95W6hSbmxQ==" Dec 10 03:36:09 volumio go-librespot[11139]: time="2025-12-10T03:36:09-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:36:09 volumio go-librespot[11139]: time="2025-12-10T03:36:09-06:00" level=debug msg="completed keyexchange" Dec 10 03:36:09 volumio go-librespot[11139]: time="2025-12-10T03:36:09-06:00" level=debug msg="completed challenge" Dec 10 03:36:10 volumio go-librespot[11139]: time="2025-12-10T03:36:10-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:36:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:36:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:36:12 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:36:12 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:36:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 63. Dec 10 03:36:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:13 volumio go-librespot[11150]: go-librespot daemon starting... Dec 10 03:36:13 volumio go-librespot[11151]: time="2025-12-10T03:36:13-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:36:13 volumio go-librespot[11151]: time="2025-12-10T03:36:13-06:00" level=debug msg="app state loaded" Dec 10 03:36:13 volumio go-librespot[11151]: time="2025-12-10T03:36:13-06:00" level=debug msg="stored credentials not found" Dec 10 03:36:13 volumio go-librespot[11151]: time="2025-12-10T03:36:13-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:36:13 volumio go-librespot[11151]: time="2025-12-10T03:36:13-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:36:13 volumio go-librespot[11151]: time="2025-12-10T03:36:13-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:36:13 volumio go-librespot[11151]: time="2025-12-10T03:36:13-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:36:13 volumio go-librespot[11151]: time="2025-12-10T03:36:13-06:00" level=info msg="zeroconf server listening on port 35937" Dec 10 03:36:13 volumio go-librespot[11151]: time="2025-12-10T03:36:13-06:00" level=debug msg="obtained new client token: AACvwWXnI7fV1N4u9bkVfI9EjXiRUKvXqMz9a8CES830JrNU7xTaAXZlk51bfMfOS9QbHNB9403rwB0aGVVmSqkj0O2NwKYBdja+EvCE5P/Rza7uyqiS0JQWow0SqCmZjDzM975B3A1HIcISuD9ffYqoPhbcuHg2WYDi+5NbCA11AL8LeFHufZY0mYta/NcS0eg69UqJkZX2F7/PIecMlNR2DWB/cN5tWBgDWaDEKPckyFIkMPIk2h/XNw==" Dec 10 03:36:13 volumio go-librespot[11151]: time="2025-12-10T03:36:13-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:36:13 volumio go-librespot[11151]: time="2025-12-10T03:36:13-06:00" level=debug msg="completed keyexchange" Dec 10 03:36:13 volumio go-librespot[11151]: time="2025-12-10T03:36:13-06:00" level=debug msg="completed challenge" Dec 10 03:36:13 volumio go-librespot[11151]: time="2025-12-10T03:36:13-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:36:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:36:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:36:15 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:36:15 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:36:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 64. Dec 10 03:36:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:17 volumio go-librespot[11158]: go-librespot daemon starting... Dec 10 03:36:17 volumio go-librespot[11159]: time="2025-12-10T03:36:17-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:36:17 volumio go-librespot[11159]: time="2025-12-10T03:36:17-06:00" level=debug msg="app state loaded" Dec 10 03:36:17 volumio go-librespot[11159]: time="2025-12-10T03:36:17-06:00" level=debug msg="stored credentials not found" Dec 10 03:36:17 volumio go-librespot[11159]: time="2025-12-10T03:36:17-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:36:17 volumio go-librespot[11159]: time="2025-12-10T03:36:17-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 10 03:36:17 volumio go-librespot[11159]: time="2025-12-10T03:36:17-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 10 03:36:17 volumio go-librespot[11159]: time="2025-12-10T03:36:17-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 10 03:36:17 volumio go-librespot[11159]: time="2025-12-10T03:36:17-06:00" level=info msg="zeroconf server listening on port 42857" Dec 10 03:36:17 volumio go-librespot[11159]: time="2025-12-10T03:36:17-06:00" level=debug msg="obtained new client token: AADN6qlKUtdVwlpalrvrLWVdmM160S1hRfMT8VP2Eve4lo9lbxGXgeLGWLZ9XKaUgmayykpwYA+kCp4Djj6ePVEYzykagsD4LBggVk8CfI03dhwnrfai6cl8Mwr+7Xz3aqZ/Ot8nWxL7d8Z+QYlN/JOqluvz1JdbBBaBzTbf91NcsIHtivFrfD/ebCN8zwJ4WkvwkZQasQcdSJYTxw0u27TTQyixIBapVZUsYfhDvMM8p0/e4Hl5INqQRw==" Dec 10 03:36:17 volumio go-librespot[11159]: time="2025-12-10T03:36:17-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:36:17 volumio go-librespot[11159]: time="2025-12-10T03:36:17-06:00" level=debug msg="completed keyexchange" Dec 10 03:36:17 volumio go-librespot[11159]: time="2025-12-10T03:36:17-06:00" level=debug msg="completed challenge" Dec 10 03:36:17 volumio go-librespot[11159]: time="2025-12-10T03:36:17-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:36:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:36:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:36:18 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:36:18 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:36:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 65. Dec 10 03:36:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:20 volumio go-librespot[11180]: go-librespot daemon starting... Dec 10 03:36:20 volumio go-librespot[11181]: time="2025-12-10T03:36:20-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:36:20 volumio go-librespot[11181]: time="2025-12-10T03:36:20-06:00" level=debug msg="app state loaded" Dec 10 03:36:20 volumio go-librespot[11181]: time="2025-12-10T03:36:20-06:00" level=debug msg="stored credentials not found" Dec 10 03:36:20 volumio go-librespot[11181]: time="2025-12-10T03:36:20-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:36:20 volumio go-librespot[11181]: time="2025-12-10T03:36:20-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 10 03:36:20 volumio go-librespot[11181]: time="2025-12-10T03:36:20-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 10 03:36:20 volumio go-librespot[11181]: time="2025-12-10T03:36:20-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 10 03:36:20 volumio go-librespot[11181]: time="2025-12-10T03:36:20-06:00" level=info msg="zeroconf server listening on port 33795" Dec 10 03:36:21 volumio go-librespot[11181]: time="2025-12-10T03:36:21-06:00" level=debug msg="obtained new client token: AACoz+M/sqmUaDNaPfjgGiCQRSVVHpKuaf2Zm0SMREiXil9hPb6mahYOiCt//nFmSjOULiC8CykeENv8H9Nl/siH/zZtRYJPMcQcBFhI0GbcGttHuT4ZrOAvKI3QzwmwDQbTzkjTMzC3hyB9MJB4A6uQSKNL5V5vyKBNkmx0a2VD8PoycoYMFengqSwjx3LhqGtLPWczLS/voy5TRb/rPAPHkxyI0GtfGwmuhJBAxA6KAhReiMFmh/E=" Dec 10 03:36:21 volumio go-librespot[11181]: time="2025-12-10T03:36:21-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:36:21 volumio go-librespot[11181]: time="2025-12-10T03:36:21-06:00" level=debug msg="completed keyexchange" Dec 10 03:36:21 volumio go-librespot[11181]: time="2025-12-10T03:36:21-06:00" level=debug msg="completed challenge" Dec 10 03:36:21 volumio go-librespot[11181]: time="2025-12-10T03:36:21-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:36:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:36:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:36:21 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:36:21 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:36:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 66. Dec 10 03:36:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:24 volumio go-librespot[11188]: go-librespot daemon starting... Dec 10 03:36:24 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:36:24 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:36:24 volumio go-librespot[11189]: time="2025-12-10T03:36:24-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:36:24 volumio go-librespot[11189]: time="2025-12-10T03:36:24-06:00" level=debug msg="app state loaded" Dec 10 03:36:24 volumio go-librespot[11189]: time="2025-12-10T03:36:24-06:00" level=debug msg="stored credentials not found" Dec 10 03:36:24 volumio go-librespot[11189]: time="2025-12-10T03:36:24-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:36:24 volumio go-librespot[11189]: time="2025-12-10T03:36:24-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:36:24 volumio go-librespot[11189]: time="2025-12-10T03:36:24-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:36:24 volumio go-librespot[11189]: time="2025-12-10T03:36:24-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:36:24 volumio go-librespot[11189]: time="2025-12-10T03:36:24-06:00" level=info msg="zeroconf server listening on port 46611" Dec 10 03:36:24 volumio go-librespot[11189]: time="2025-12-10T03:36:24-06:00" level=debug msg="obtained new client token: AADUE6/Rvtg+fHIcGJ6Ct1L1HNxpobUT4FnP+pW/J9uvdG+ICtA3sgdU3ambbfD6uMQCGwmnuYuo06pIiUruloaHKXctU7AaOaNJ9C4F7KZNlzFKSvaZznbAhmxexTZ+I0iHCr9MRcIj599rnCZjClj83HpW0G+ISfdanyxlqUIs8MeRea29gD1c7P+dMzlqoqxT5huxk7VaDlgQXISy+Mvh2nZbYXtgqKLF+gUUuzoswkFLJlb4484mZA==" Dec 10 03:36:24 volumio go-librespot[11189]: time="2025-12-10T03:36:24-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:36:24 volumio go-librespot[11189]: time="2025-12-10T03:36:24-06:00" level=debug msg="completed keyexchange" Dec 10 03:36:24 volumio go-librespot[11189]: time="2025-12-10T03:36:24-06:00" level=debug msg="completed challenge" Dec 10 03:36:24 volumio go-librespot[11189]: time="2025-12-10T03:36:24-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:36:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:36:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:36:27 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:36:27 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:36:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 67. Dec 10 03:36:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:28 volumio go-librespot[11196]: go-librespot daemon starting... Dec 10 03:36:28 volumio go-librespot[11197]: time="2025-12-10T03:36:28-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:36:28 volumio go-librespot[11197]: time="2025-12-10T03:36:28-06:00" level=debug msg="app state loaded" Dec 10 03:36:28 volumio go-librespot[11197]: time="2025-12-10T03:36:28-06:00" level=debug msg="stored credentials not found" Dec 10 03:36:28 volumio go-librespot[11197]: time="2025-12-10T03:36:28-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:36:28 volumio go-librespot[11197]: time="2025-12-10T03:36:28-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:36:28 volumio go-librespot[11197]: time="2025-12-10T03:36:28-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:36:28 volumio go-librespot[11197]: time="2025-12-10T03:36:28-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:36:28 volumio go-librespot[11197]: time="2025-12-10T03:36:28-06:00" level=info msg="zeroconf server listening on port 42383" Dec 10 03:36:28 volumio go-librespot[11197]: time="2025-12-10T03:36:28-06:00" level=debug msg="obtained new client token: AAAu6y/jN4/i9IZP6gT6aTkDZ700imGfqLjtUz8xES/lqp/udOIyXMkADcI5HTOglJDZceNDP2U4kPpfOpcn1zJ04xdOOgvrieQiGGVvSrIH4ByF+IKhO3kPZWPgm/H/8z19Fe1BA69RdN2tusFyZqettkwMZgBc0qRmfM8MwNgnLex48b1xpOuzRNu5kUHO6ULQChIphD+NgZMSdEYKMBAsnuFELwpTxgsP88xiWMbfLUN+z6rj3OJ/Dw==" Dec 10 03:36:28 volumio go-librespot[11197]: time="2025-12-10T03:36:28-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:36:28 volumio go-librespot[11197]: time="2025-12-10T03:36:28-06:00" level=debug msg="completed keyexchange" Dec 10 03:36:28 volumio go-librespot[11197]: time="2025-12-10T03:36:28-06:00" level=debug msg="completed challenge" Dec 10 03:36:28 volumio go-librespot[11197]: time="2025-12-10T03:36:28-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:36:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:36:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:36:30 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:36:30 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:36:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 68. Dec 10 03:36:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:31 volumio go-librespot[11221]: go-librespot daemon starting... Dec 10 03:36:32 volumio go-librespot[11222]: time="2025-12-10T03:36:32-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:36:32 volumio go-librespot[11222]: time="2025-12-10T03:36:32-06:00" level=debug msg="app state loaded" Dec 10 03:36:32 volumio go-librespot[11222]: time="2025-12-10T03:36:32-06:00" level=debug msg="stored credentials not found" Dec 10 03:36:32 volumio go-librespot[11222]: time="2025-12-10T03:36:32-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:36:32 volumio go-librespot[11222]: time="2025-12-10T03:36:32-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:36:32 volumio go-librespot[11222]: time="2025-12-10T03:36:32-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:36:32 volumio go-librespot[11222]: time="2025-12-10T03:36:32-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:36:32 volumio go-librespot[11222]: time="2025-12-10T03:36:32-06:00" level=info msg="zeroconf server listening on port 42831" Dec 10 03:36:32 volumio go-librespot[11222]: time="2025-12-10T03:36:32-06:00" level=debug msg="obtained new client token: AAAQIg23ENDF6aldNmaNCg3OYV1wB3NuRXdRp8ImdTTthxYObzymqxObiZmNlJ0R+DBa9AlLymDx6tbL/lkEInqyF7sPlbRTLvNTWnxx+bRbAE0XyAC6yA/exFmKMNMnmJyebofNYowUlw2Wjb2pOojOUSkad5WQgYe5Ul0PM6kUz+TaPf47rWkARNMyrgJXtiIYEmudCmpM+g4qsFYWG/62TjGkwgQ98HN06R7FpvxGoJRp1cNFJmttIQ==" Dec 10 03:36:32 volumio go-librespot[11222]: time="2025-12-10T03:36:32-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:36:32 volumio go-librespot[11222]: time="2025-12-10T03:36:32-06:00" level=debug msg="completed keyexchange" Dec 10 03:36:32 volumio go-librespot[11222]: time="2025-12-10T03:36:32-06:00" level=debug msg="completed challenge" Dec 10 03:36:32 volumio go-librespot[11222]: time="2025-12-10T03:36:32-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:36:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:36:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:36:33 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:36:33 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:36:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 69. Dec 10 03:36:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:35 volumio go-librespot[11230]: go-librespot daemon starting... Dec 10 03:36:35 volumio go-librespot[11231]: time="2025-12-10T03:36:35-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:36:35 volumio go-librespot[11231]: time="2025-12-10T03:36:35-06:00" level=debug msg="app state loaded" Dec 10 03:36:35 volumio go-librespot[11231]: time="2025-12-10T03:36:35-06:00" level=debug msg="stored credentials not found" Dec 10 03:36:35 volumio go-librespot[11231]: time="2025-12-10T03:36:35-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:36:35 volumio go-librespot[11231]: time="2025-12-10T03:36:35-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:36:35 volumio go-librespot[11231]: time="2025-12-10T03:36:35-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:36:35 volumio go-librespot[11231]: time="2025-12-10T03:36:35-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:36:35 volumio go-librespot[11231]: time="2025-12-10T03:36:35-06:00" level=info msg="zeroconf server listening on port 38677" Dec 10 03:36:36 volumio go-librespot[11231]: time="2025-12-10T03:36:36-06:00" level=debug msg="obtained new client token: AABg9zWAfTuOqysrySd+/gc7Z3qq065yDhTrQnDB8o6ZPCBzeKg17t63t+n2ivvsNNo9cYqS3JZxlUUHxPGEdMvd4RIij9UsXKiEaZpMt5VbhCZUK3mdJNxeslnpH4QUU9oxJbsKvrxye1ClNuBvErgO0v4mv1ljTUq2qnRy8TIUUeu66TeHz+D8ER6q9KnBDMxmF1sayJHyj4+ECstQfhQWtWWxOPGKvx3r1PAvX0ZTj4bd6onU7q0=" Dec 10 03:36:36 volumio go-librespot[11231]: time="2025-12-10T03:36:36-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:36:36 volumio go-librespot[11231]: time="2025-12-10T03:36:36-06:00" level=debug msg="completed keyexchange" Dec 10 03:36:36 volumio go-librespot[11231]: time="2025-12-10T03:36:36-06:00" level=debug msg="completed challenge" Dec 10 03:36:36 volumio go-librespot[11231]: time="2025-12-10T03:36:36-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:36:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:36:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:36:36 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:36:36 volumio volumio[10381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:36:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 70. Dec 10 03:36:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:39 volumio go-librespot[11252]: go-librespot daemon starting... Dec 10 03:36:39 volumio go-librespot[11253]: time="2025-12-10T03:36:39-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:36:39 volumio go-librespot[11253]: time="2025-12-10T03:36:39-06:00" level=debug msg="app state loaded" Dec 10 03:36:39 volumio go-librespot[11253]: time="2025-12-10T03:36:39-06:00" level=debug msg="stored credentials not found" Dec 10 03:36:39 volumio go-librespot[11253]: time="2025-12-10T03:36:39-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:36:39 volumio volumio[10381]: info: Initializing connection to go-librespot Websocket Dec 10 03:36:39 volumio go-librespot[11253]: time="2025-12-10T03:36:39-06:00" level=debug msg="new websocket client" Dec 10 03:36:39 volumio volumio[10381]: info: Connection to go-librespot Websocket established Dec 10 03:36:39 volumio go-librespot[11253]: time="2025-12-10T03:36:39-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:36:39 volumio go-librespot[11253]: time="2025-12-10T03:36:39-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:36:39 volumio go-librespot[11253]: time="2025-12-10T03:36:39-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 03:36:39 volumio go-librespot[11253]: time="2025-12-10T03:36:39-06:00" level=info msg="zeroconf server listening on port 32809" Dec 10 03:36:39 volumio go-librespot[11253]: time="2025-12-10T03:36:39-06:00" level=debug msg="obtained new client token: AAC2T/CEyTNOFnlhidhCX4Dx/OMPXLySJLhJcyOqLNDVbO3biPWfgU4Uy8fml3OP0js4w2nUd81b4bbA2j8lbVL9ulAfBNd7rj/yOOX9H3qI15P5UPGo7ZCBvLKm2z2+kpHMNgcO03P09DjPVEjZbqduDqOwg9YwkuIxeODwXED7gQlskDC+PDx/+5cbj0Qcd7BtDHarFJMqQMzThq2gvh1ia8ntZYIVRk2G1V7d/JdnGvWfqzktGxjnHQ==" Dec 10 03:36:39 volumio go-librespot[11253]: time="2025-12-10T03:36:39-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 10 03:36:39 volumio go-librespot[11253]: time="2025-12-10T03:36:39-06:00" level=debug msg="completed keyexchange" Dec 10 03:36:39 volumio go-librespot[11253]: time="2025-12-10T03:36:39-06:00" level=debug msg="completed challenge" Dec 10 03:36:39 volumio go-librespot[11253]: time="2025-12-10T03:36:39-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 03:36:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 03:36:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 03:36:39 volumio volumio[10381]: info: Connection to go-librespot Websocket closed Dec 10 03:36:42 volumio volumio[10381]: info: Getting Spotify volume Dec 10 03:36:42 volumio volumio[10381]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 10 03:36:42 volumio volumio[10381]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 03:36:42 volumio volumio[10381]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 10 03:36:42 volumio volumio[10381]: errno: -111, Dec 10 03:36:42 volumio volumio[10381]: code: 'ECONNREFUSED', Dec 10 03:36:42 volumio volumio[10381]: syscall: 'connect', Dec 10 03:36:42 volumio volumio[10381]: address: '127.0.0.1', Dec 10 03:36:42 volumio volumio[10381]: port: 9879, Dec 10 03:36:42 volumio volumio[10381]: response: undefined Dec 10 03:36:42 volumio volumio[10381]: } Dec 10 03:36:42 volumio volumio[10381]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 10 03:36:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 71. Dec 10 03:36:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 03:36:43 volumio go-librespot[11272]: go-librespot daemon starting... Dec 10 03:36:43 volumio go-librespot[11273]: time="2025-12-10T03:36:43-06:00" level=info msg="running go-librespot 0.4.0" Dec 10 03:36:43 volumio go-librespot[11273]: time="2025-12-10T03:36:43-06:00" level=debug msg="app state loaded" Dec 10 03:36:43 volumio go-librespot[11273]: time="2025-12-10T03:36:43-06:00" level=debug msg="stored credentials not found" Dec 10 03:36:43 volumio go-librespot[11273]: time="2025-12-10T03:36:43-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 03:36:43 volumio sudo[11281]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-10 03:35' Dec 10 03:36:43 volumio sudo[11281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 03:36:43 volumio go-librespot[11273]: time="2025-12-10T03:36:43-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 03:36:43 volumio go-librespot[11273]: time="2025-12-10T03:36:43-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 03:36:43 volumio go-librespot[11273]: time="2025-12-10T03:36:43-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" 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="ac7dd5922ede329d1459d48b226ddc71f5209a2c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="3441cddd43405c36fe444484553f10f2f5bc830b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Nov 13 11:04:27 UTC 2025" VOLUMIO_VERSION="4.069" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="7da8d6d9f8baf8621af4ec2af5a00f00"