Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 13 10:55:00 gbvpi-bedroom sudo[26918]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 13 10:55:00 gbvpi-bedroom sudo[26918]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 10:55:00 gbvpi-bedroom sudo[26918]: pam_unix(sudo:session): session closed for user root Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: MRS: MultiRoom plugin initialized Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: MRS: STOPPING SNAPCLIENT Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: MRS: Snap server stop Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: MRS: STOPPING volumioStreaming Dec 13 10:55:00 gbvpi-bedroom sudo[26935]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 13 10:55:00 gbvpi-bedroom sudo[26935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 13 10:55:00 gbvpi-bedroom sudo[26937]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 13 10:55:00 gbvpi-bedroom sudo[26937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 10:55:00 gbvpi-bedroom sudo[26939]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 13 10:55:00 gbvpi-bedroom sudo[26939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 13 10:55:00 gbvpi-bedroom sudo[26944]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 13 10:55:00 gbvpi-bedroom sudo[26944]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 10:55:00 gbvpi-bedroom sudo[26944]: pam_unix(sudo:session): session closed for user root Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 13 10:55:00 gbvpi-bedroom sudo[26937]: pam_unix(sudo:session): session closed for user root Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 13 10:55:00 gbvpi-bedroom sudo[26935]: pam_unix(sudo:session): session closed for user root Dec 13 10:55:00 gbvpi-bedroom sudo[26939]: pam_unix(sudo:session): session closed for user root Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: Preparing to generate the ALSA configuration file Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: Setting Geolocation for MyVolumio to us1 Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: Setting Geolocation for MyVolumio to us4 Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: Reading ALSA contributions from plugins. Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: MRS: Removed streaming files Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: MRS: volumioStreaming STOPPED Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: MRS: SNAPSERVER STOPPED Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: MRS: SNAPCLIENT STOPPED Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: error: Cannot start Volumio Streaming Daemon Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 13 10:55:00 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: Asound.conf file written Dec 13 10:55:01 gbvpi-bedroom sudo[26948]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 13 10:55:01 gbvpi-bedroom sudo[26948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 10:55:01 gbvpi-bedroom sudo[26948]: pam_unix(sudo:session): session closed for user root Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: Output device has changed, restarting MPD Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: Output device has changed, restarting Shairport Sync Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 10:55:01 gbvpi-bedroom sudo[26954]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 13 10:55:01 gbvpi-bedroom sudo[26954]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 10:55:01 gbvpi-bedroom sudo[26954]: pam_unix(sudo:session): session closed for user root Dec 13 10:55:01 gbvpi-bedroom sudo[26956]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 13 10:55:01 gbvpi-bedroom sudo[26956]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 13 10:55:01 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: MRS: Pushing multiroomSync output for this device Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: MRS: Pushing multiroomSync output Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: Adding audio output: Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: Adding audio output: Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 10:55:01 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 13 10:55:01 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 13 10:55:01 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.909s CPU time. Dec 13 10:55:01 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 13 10:55:01 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 13 10:55:01 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: Adding METAVOLUMIO REST API Endpoints Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 13 10:55:01 gbvpi-bedroom bluetoothd[763]: Path / reserved for Adv Monitor app :1.63596 Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: Preparing CD Folders Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: Adding CD REST API Endpoints Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: Starting UDEV Watcher for CD Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: Detecting CD presence with UDEV Dec 13 10:55:01 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 13 10:55:01 gbvpi-bedroom bluetoothd[763]: Adv Monitor app :1.63596 disconnected from D-Bus Dec 13 10:55:01 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 13 10:55:01 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 13 10:55:01 gbvpi-bedroom sudo[26975]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 13 10:55:01 gbvpi-bedroom sudo[26975]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 13 10:55:01 gbvpi-bedroom sudo[26975]: pam_unix(sudo:session): session closed for user root Dec 13 10:55:02 gbvpi-bedroom mpd[26977]: 2025-12-13T10:55:02 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 13 10:55:02 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 13 10:55:02 gbvpi-bedroom sudo[26956]: pam_unix(sudo:session): session closed for user root Dec 13 10:55:02 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 80. Dec 13 10:55:02 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:03 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:03 gbvpi-bedroom go-librespot[26980]: go-librespot daemon starting... Dec 13 10:55:03 gbvpi-bedroom go-librespot[26981]: time="2025-12-13T10:55:03-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:55:03 gbvpi-bedroom go-librespot[26981]: time="2025-12-13T10:55:03-05:00" level=debug msg="app state loaded" Dec 13 10:55:03 gbvpi-bedroom go-librespot[26981]: time="2025-12-13T10:55:03-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:55:03 gbvpi-bedroom go-librespot[26981]: time="2025-12-13T10:55:03-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 13 10:55:03 gbvpi-bedroom go-librespot[26981]: time="2025-12-13T10:55:03-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 13 10:55:03 gbvpi-bedroom go-librespot[26981]: time="2025-12-13T10:55:03-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 13 10:55:03 gbvpi-bedroom go-librespot[26981]: time="2025-12-13T10:55:03-05:00" level=info msg="zeroconf server listening on port 38867" Dec 13 10:55:03 gbvpi-bedroom go-librespot[26981]: time="2025-12-13T10:55:03-05:00" level=debug msg="obtained new client token: AADt5Z/LbmN4g61X79ae3MCo8KY5PV7RtLMl+RJbuYM8poUUsot7Fz++Z+170VhZ4vIE+5E11kDhndUk61Vjf5pxM4pKaETOu5nsISd5CAmwixjb3lmYUvQUq7ViVKJtNXB0YUlJZSZi0LLy16CgAql3JNBcKc8WZj9huiDwfQUKzWzmGJrhPM3SmvJf2NKSDpN35jdXooN7MyAqBd/aUqPd/RxC+TdttgvosPJVhxfjC/NbwSxc1jtCXw==" Dec 13 10:55:03 gbvpi-bedroom go-librespot[26981]: time="2025-12-13T10:55:03-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:55:03 gbvpi-bedroom go-librespot[26981]: time="2025-12-13T10:55:03-05:00" level=debug msg="completed keyexchange" Dec 13 10:55:03 gbvpi-bedroom go-librespot[26981]: time="2025-12-13T10:55:03-05:00" level=debug msg="completed challenge" Dec 13 10:55:03 gbvpi-bedroom go-librespot[26981]: time="2025-12-13T10:55:03-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:55:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:55:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Adding inputs REST Endpoints Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Scanning Audio Inputs Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Checking against Known Cards name Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Adding Server instance for streaming Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: error: Hi Res Audio Failed Login: Missing Login Data Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 13 10:55:06 gbvpi-bedroom sudo[27006]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 13 10:55:06 gbvpi-bedroom sudo[27006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Adding TIDAL REST API Endpoints Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Stopping AccessToken refresher cron for QOBUZ Dec 13 10:55:06 gbvpi-bedroom sudo[27013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 13 10:55:06 gbvpi-bedroom sudo[27013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 10:55:06 gbvpi-bedroom systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Dec 13 10:55:06 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully. Dec 13 10:55:06 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 13 10:55:06 gbvpi-bedroom sudo[27006]: pam_unix(sudo:session): session closed for user root Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: AccessToken refresher cron started for QOBUZ Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Adding QOBUZ REST API Endpoints Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Updating MyVolumio device info Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Updating MyVolumio device info Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 10:55:06 gbvpi-bedroom sudo[27013]: pam_unix(sudo:session): session closed for user root Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: MRS: Getting audio outputs on start Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: MRS: Requesting all other devices output Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:06 gbvpi-bedroom sudo[27016]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 13 10:55:06 gbvpi-bedroom sudo[27016]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Successfully Added MyVolumio device Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Successfully Added MyVolumio device Dec 13 10:55:06 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 13 10:55:06 gbvpi-bedroom qobuz-connect[25301]: 20251213 10:55:06.352 [25301.25301] INFO SampleApp: Stopping Local configuration server Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: MPD Permissions set Dec 13 10:55:06 gbvpi-bedroom sudo[27020]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 13 10:55:06 gbvpi-bedroom sudo[27020]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CorePlayQueue::getTrack 0 Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 10:55:06 gbvpi-bedroom sudo[27020]: pam_unix(sudo:session): session closed for user root Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: error: updateQueue error: null Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CorePlayQueue::getTrack 0 Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:55:06 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 81. Dec 13 10:55:06 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioStop Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreStateMachine::stop Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Starting Shairport Sync Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: MRS: Found cast device: Google-Home-Mini-f209fa314cb426d40a59bcf66354ddc9 Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Adding audio output: Dec 13 10:55:06 gbvpi-bedroom sudo[27037]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: MRS: Found cast device: SmartTV-4K-fe72c264393a59c76d38e27b8168114d Dec 13 10:55:06 gbvpi-bedroom sudo[27037]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Adding audio output: Dec 13 10:55:06 gbvpi-bedroom sudo[27039]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 13 10:55:06 gbvpi-bedroom sudo[27039]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 10:55:06 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:06 gbvpi-bedroom go-librespot[27035]: go-librespot daemon starting... Dec 13 10:55:06 gbvpi-bedroom go-librespot[27042]: time="2025-12-13T10:55:06-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:55:06 gbvpi-bedroom go-librespot[27042]: time="2025-12-13T10:55:06-05:00" level=debug msg="app state loaded" Dec 13 10:55:06 gbvpi-bedroom go-librespot[27042]: time="2025-12-13T10:55:06-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Successfully Updated MyVolumio device Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Successfully Updated MyVolumio device Dec 13 10:55:06 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 13 10:55:06 gbvpi-bedroom autossh[25274]: received signal to exit (15) Dec 13 10:55:06 gbvpi-bedroom systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Dec 13 10:55:06 gbvpi-bedroom systemd[1]: sshtunnel.service: Deactivated successfully. Dec 13 10:55:06 gbvpi-bedroom systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 13 10:55:06 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 13 10:55:06 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 13 10:55:06 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.619s CPU time. Dec 13 10:55:06 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 13 10:55:06 gbvpi-bedroom sudo[27039]: pam_unix(sudo:session): session closed for user root Dec 13 10:55:06 gbvpi-bedroom systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 13 10:55:06 gbvpi-bedroom sudo[27037]: pam_unix(sudo:session): session closed for user root Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Shairport-Sync Started Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Remote SSH Started Dec 13 10:55:06 gbvpi-bedroom autossh[27050]: port set to 0, monitoring disabled Dec 13 10:55:06 gbvpi-bedroom autossh[27050]: starting ssh (count 1) Dec 13 10:55:06 gbvpi-bedroom autossh[27050]: ssh child pid is 27065 Dec 13 10:55:06 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 13 10:55:06 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 13 10:55:06 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 13 10:55:06 gbvpi-bedroom sudo[27016]: pam_unix(sudo:session): session closed for user root Dec 13 10:55:06 gbvpi-bedroom volumiossh-tunnel[27065]: Warning: Permanently added '[us4.myvolumio.org]:2222' (ED25519) to the list of known hosts. Dec 13 10:55:06 gbvpi-bedroom go-librespot[27042]: time="2025-12-13T10:55:06-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 13 10:55:06 gbvpi-bedroom go-librespot[27042]: time="2025-12-13T10:55:06-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 13 10:55:06 gbvpi-bedroom go-librespot[27042]: time="2025-12-13T10:55:06-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 13 10:55:06 gbvpi-bedroom go-librespot[27042]: time="2025-12-13T10:55:06-05:00" level=info msg="zeroconf server listening on port 36921" Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: Executing endpoint qc_getconfig Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 13 10:55:06 gbvpi-bedroom qobuz-connect[27067]: 20251213 10:55:06.894 [27067.27067] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 13 10:55:06 gbvpi-bedroom qobuz-connect[27067]: 20251213 10:55:06.897 [27067.27067] INFO VolumeManager: [0xf70588]: Setting new playback volume: 75 Dec 13 10:55:06 gbvpi-bedroom qobuz-connect[27067]: 20251213 10:55:06.897 [27067.27067] INFO VolumeManager: [0xf70588]: Setting new mute state: 0 Dec 13 10:55:06 gbvpi-bedroom qobuz-connect[27067]: 20251213 10:55:06.897 [27067.27067] INFO QobuzConnect: [0xf70f58]: Client initialized! Dec 13 10:55:06 gbvpi-bedroom qobuz-connect[27067]: 20251213 10:55:06.897 [27067.27067] INFO SampleApp: Starting Avahi advertising, name: GBVPi-Bedroom, service name: _qobuz-connect._tcp Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: 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 13 10:55:06 gbvpi-bedroom qobuz-connect[27067]: 20251213 10:55:06.918 [27067.27067] INFO LocalConfigManager: [0xf6fe68]: Starting Local Configuration server Dec 13 10:55:06 gbvpi-bedroom qobuz-connect[27067]: 20251213 10:55:06.919 [27067.27067] INFO SampleApp: Starting Local configuration server Dec 13 10:55:06 gbvpi-bedroom qobuz-connect[27067]: 20251213 10:55:06.919 [27067.27067] INFO SampleApp: Connected to UNIX socket client 0xf5a818 Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:06 gbvpi-bedroom volumio[26553]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 13 10:55:06 gbvpi-bedroom go-librespot[27042]: time="2025-12-13T10:55:06-05:00" level=debug msg="obtained new client token: AAA69WPHlQR3booyN2LvUbxN8Fa9y0M02z0T8Zb1d2sl0deRwFgRIqYMrPmJnN4wGr9O5JUevGKimq/dJzF8Ad2odkdhfiJGMyOYSzIY7bU8tqQ0y62MTzfO+h/M3l4nDmdzCkeUp3GnXrPf8xPGohs3NYxW+1aMiO7uEeNsnu+sxbGhdpDDMm0v4iY5TzMQ/nfuWd/Ub1/ruYHyMvUs8TBldWm/nUWUYHAOku0krHX4JK9ErvYBJLAXRg==" Dec 13 10:55:07 gbvpi-bedroom go-librespot[27042]: time="2025-12-13T10:55:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:55:07 gbvpi-bedroom qobuz-connect[27067]: 20251213 10:55:07.044 [27067.27067] INFO SampleApp: Playback volume changed: 75 Dec 13 10:55:07 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:07 gbvpi-bedroom go-librespot[27042]: time="2025-12-13T10:55:07-05:00" level=debug msg="completed keyexchange" Dec 13 10:55:07 gbvpi-bedroom go-librespot[27042]: time="2025-12-13T10:55:07-05:00" level=debug msg="completed challenge" Dec 13 10:55:07 gbvpi-bedroom go-librespot[27042]: time="2025-12-13T10:55:07-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:55:07 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:55:07 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: TidalConnect service stoped! Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 13 10:55:09 gbvpi-bedroom sudo[27086]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 13 10:55:09 gbvpi-bedroom sudo[27086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:09 gbvpi-bedroom sudo[27090]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 13 10:55:09 gbvpi-bedroom sudo[27090]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:09 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 13 10:55:09 gbvpi-bedroom sudo[27086]: pam_unix(sudo:session): session closed for user root Dec 13 10:55:09 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 13 10:55:09 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 13 10:55:09 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 13 10:55:09 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 13 10:55:09 gbvpi-bedroom sudo[27090]: pam_unix(sudo:session): session closed for user root Dec 13 10:55:09 gbvpi-bedroom mpd_monitor.sh[27094]: MPD Monitor Service: Starting MPD Monitor Service Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: Successfully started MPD Monitor Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: Executing endpoint tc_getconfig Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 13 10:55:09 gbvpi-bedroom vtcs[27092]: STARTING TidalConnect services, version: 1.5.2.56 Dec 13 10:55:09 gbvpi-bedroom vtcs[27092]: STARTED TidalConnect services. Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: Executing endpoint tc_connect Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: Connecting to TidalConnect Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::servicePushState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreStateMachine::pushState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioPushState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: MRS: Pushing multiroomSync output update for this device Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: MRS: Pushing multiroomSync output Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CorePlayQueue::getTrack 0 Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: verbose: CURRENT POSITION 0 Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreStateMachine::syncState stateService stop Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreStateMachine::syncState currentStatus stop Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreStateMachine::pushState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioPushState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: MRS: Pushing multiroomSync output update for this device Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: MRS: Pushing multiroomSync output Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: No code Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreStateMachine::pushState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioPushState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: MRS: Pushing multiroomSync output update for this device Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: MRS: Pushing multiroomSync output Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::servicePushState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreStateMachine::pushState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioPushState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: MRS: Pushing multiroomSync output update for this device Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: MRS: Pushing multiroomSync output Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CorePlayQueue::getTrack 0 Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: verbose: CURRENT POSITION 0 Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreStateMachine::syncState stateService stop Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreStateMachine::syncState currentStatus stop Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreStateMachine::pushState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioPushState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: MRS: Pushing multiroomSync output update for this device Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: MRS: Pushing multiroomSync output Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: No code Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreStateMachine::pushState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioPushState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: MRS: Pushing multiroomSync output update for this device Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: MRS: Pushing multiroomSync output Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 13 10:55:09 gbvpi-bedroom volumio[26553]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 13 10:55:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 82. Dec 13 10:55:10 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:10 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:10 gbvpi-bedroom go-librespot[27112]: go-librespot daemon starting... Dec 13 10:55:10 gbvpi-bedroom go-librespot[27113]: time="2025-12-13T10:55:10-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:55:10 gbvpi-bedroom go-librespot[27113]: time="2025-12-13T10:55:10-05:00" level=debug msg="app state loaded" Dec 13 10:55:10 gbvpi-bedroom go-librespot[27113]: time="2025-12-13T10:55:10-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:55:10 gbvpi-bedroom go-librespot[27113]: time="2025-12-13T10:55:10-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 13 10:55:10 gbvpi-bedroom go-librespot[27113]: time="2025-12-13T10:55:10-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 13 10:55:10 gbvpi-bedroom go-librespot[27113]: time="2025-12-13T10:55:10-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 13 10:55:10 gbvpi-bedroom go-librespot[27113]: time="2025-12-13T10:55:10-05:00" level=info msg="zeroconf server listening on port 38003" Dec 13 10:55:10 gbvpi-bedroom go-librespot[27113]: time="2025-12-13T10:55:10-05:00" level=debug msg="obtained new client token: AAC4ofPyAejY/eP4Fyxyy6BWhiZ1kAhrYuAOJiiaRAAjjoKDx65oMI8TLLVRORWw9sV3S79Hj+8bUUIIbn+fvX71OVJRtUQNGoTMrX9mZqiQwFm9sF1qHptuPSTFiMQXsBTIcJV5lbnFN/W+/kGRAjQ0/j0QdyW8oDlSfOmDmfnC5Vlrao/QDwu6dqt9GloHjSIW5DiAvwlaXEJiCYCKjgumy5xiaDewtPWbsFM+RH9P9yDVnnC0qzo1zA==" Dec 13 10:55:10 gbvpi-bedroom go-librespot[27113]: time="2025-12-13T10:55:10-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Dec 13 10:55:10 gbvpi-bedroom go-librespot[27113]: time="2025-12-13T10:55:10-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Dec 13 10:55:10 gbvpi-bedroom go-librespot[27113]: time="2025-12-13T10:55:10-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Dec 13 10:55:10 gbvpi-bedroom go-librespot[27113]: time="2025-12-13T10:55:10-05:00" level=debug msg="completed keyexchange" Dec 13 10:55:10 gbvpi-bedroom go-librespot[27113]: time="2025-12-13T10:55:10-05:00" level=debug msg="completed challenge" Dec 13 10:55:10 gbvpi-bedroom go-librespot[27113]: time="2025-12-13T10:55:10-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:55:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:55:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:55:12 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:12 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:12 gbvpi-bedroom volumio[26553]: info: TidalConnect service started! Dec 13 10:55:12 gbvpi-bedroom volumio[26553]: [Metrics] CommandRouter: 29s 394.69ms Dec 13 10:55:12 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumiosetStartupVolume Dec 13 10:55:12 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 10:55:12 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 10:55:12 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::Close All Modals sent Dec 13 10:55:12 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::Close All Modals sent Dec 13 10:55:13 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:13 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:13 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 13 10:55:13 gbvpi-bedroom volumio[26553]: 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 13 10:55:13 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:13 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 13 10:55:13 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 13 10:55:13 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 13 10:55:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 83. Dec 13 10:55:13 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:14 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:14 gbvpi-bedroom go-librespot[27124]: go-librespot daemon starting... Dec 13 10:55:14 gbvpi-bedroom go-librespot[27125]: time="2025-12-13T10:55:14-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:55:14 gbvpi-bedroom go-librespot[27125]: time="2025-12-13T10:55:14-05:00" level=debug msg="app state loaded" Dec 13 10:55:14 gbvpi-bedroom go-librespot[27125]: time="2025-12-13T10:55:14-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:55:14 gbvpi-bedroom go-librespot[27125]: time="2025-12-13T10:55:14-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 13 10:55:14 gbvpi-bedroom go-librespot[27125]: time="2025-12-13T10:55:14-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 13 10:55:14 gbvpi-bedroom go-librespot[27125]: time="2025-12-13T10:55:14-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 13 10:55:14 gbvpi-bedroom go-librespot[27125]: time="2025-12-13T10:55:14-05:00" level=info msg="zeroconf server listening on port 43417" Dec 13 10:55:14 gbvpi-bedroom go-librespot[27125]: time="2025-12-13T10:55:14-05:00" level=debug msg="obtained new client token: AABVKY/CzzzJS/ucr4RUDnzBCkOTV0epERPsrwz0Z+ea9597D7CUbKdjMlkPFC+DNge3K93ZlEzdb2fAS6Ur4ez6THM4P7UjLxkVXHfceVtnmLy80tbhDb4LCRFOl052q0KOH2oWLipDpjW+nzh4ag+snJQCLrCDE7eVjNhShoPVGEKXwV6hLyKiPX/43ELpvD+eotsJNChNIu5kYLr5AyScy8qu1mI184UNrY59NZdpqh4q7ldxpPliug==" Dec 13 10:55:14 gbvpi-bedroom go-librespot[27125]: time="2025-12-13T10:55:14-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:55:14 gbvpi-bedroom go-librespot[27125]: time="2025-12-13T10:55:14-05:00" level=debug msg="completed keyexchange" Dec 13 10:55:14 gbvpi-bedroom go-librespot[27125]: time="2025-12-13T10:55:14-05:00" level=debug msg="completed challenge" Dec 13 10:55:14 gbvpi-bedroom go-librespot[27125]: time="2025-12-13T10:55:14-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:55:14 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:55:14 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:55:15 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:15 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:17 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 13 10:55:17 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 10:55:17 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 13 10:55:17 gbvpi-bedroom volumio-remote-updater[775]: Test mode enabled Dec 13 10:55:17 gbvpi-bedroom volumio-remote-updater[775]: Alpha mode disabled Dec 13 10:55:17 gbvpi-bedroom volumio-remote-updater[775]: Alpha legacy test mode disabled Dec 13 10:55:17 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 13 10:55:17 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 84. Dec 13 10:55:17 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:17 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:17 gbvpi-bedroom go-librespot[27150]: go-librespot daemon starting... Dec 13 10:55:17 gbvpi-bedroom go-librespot[27151]: time="2025-12-13T10:55:17-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:55:17 gbvpi-bedroom go-librespot[27151]: time="2025-12-13T10:55:17-05:00" level=debug msg="app state loaded" Dec 13 10:55:17 gbvpi-bedroom go-librespot[27151]: time="2025-12-13T10:55:17-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:55:17 gbvpi-bedroom volumio[26553]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

CAUTION

\n
    \n
  • This build may break your network
    • \n
\n

FIX

\n
    \n
  • Wireless and network handling
    • \n
\n","title":"Update v4.080","updateavailable":true} Dec 13 10:55:17 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 13 10:55:17 gbvpi-bedroom go-librespot[27151]: time="2025-12-13T10:55:17-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 13 10:55:17 gbvpi-bedroom go-librespot[27151]: time="2025-12-13T10:55:17-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 13 10:55:17 gbvpi-bedroom go-librespot[27151]: time="2025-12-13T10:55:17-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 13 10:55:17 gbvpi-bedroom go-librespot[27151]: time="2025-12-13T10:55:17-05:00" level=info msg="zeroconf server listening on port 37163" Dec 13 10:55:18 gbvpi-bedroom go-librespot[27151]: time="2025-12-13T10:55:18-05:00" level=debug msg="obtained new client token: AACp3cKpU47/vMTAYbhppk5j8nW01wZHp1X5v25h3VY5HLfWsAFPJ43IYrjXSqtLTh1mUAfllYXJ9lLiHcn6zzvf7CvzFH77SEvuZgmr6aVJnQW/MYpGS/wy7YNcHhZ/WWl64tTcCNrlo7BP/+Bv/0ERTlo4rECwwVE8HdBnjDr0epWpUYLtUnwss3LG/xP5tCeHTxCt9MZ9bU4dqq8ryc2KfzxHVQiU8UPKEUFGFO4wuuFEpcGy8Fw=" Dec 13 10:55:18 gbvpi-bedroom go-librespot[27151]: time="2025-12-13T10:55:18-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:55:18 gbvpi-bedroom go-librespot[27151]: time="2025-12-13T10:55:18-05:00" level=debug msg="completed keyexchange" Dec 13 10:55:18 gbvpi-bedroom go-librespot[27151]: time="2025-12-13T10:55:18-05:00" level=debug msg="completed challenge" Dec 13 10:55:18 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 10:55:18 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 10:55:18 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 13 10:55:18 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 13 10:55:18 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 13 10:55:18 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetBrowseSources Dec 13 10:55:18 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 13 10:55:18 gbvpi-bedroom go-librespot[27151]: time="2025-12-13T10:55:18-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:55:18 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:55:18 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:55:18 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:18 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:19 gbvpi-bedroom volumio[26553]: info: BOOT COMPLETED Dec 13 10:55:21 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:21 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 85. Dec 13 10:55:21 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:21 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:21 gbvpi-bedroom go-librespot[27159]: go-librespot daemon starting... Dec 13 10:55:21 gbvpi-bedroom go-librespot[27160]: time="2025-12-13T10:55:21-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:55:21 gbvpi-bedroom go-librespot[27160]: time="2025-12-13T10:55:21-05:00" level=debug msg="app state loaded" Dec 13 10:55:21 gbvpi-bedroom go-librespot[27160]: time="2025-12-13T10:55:21-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:55:21 gbvpi-bedroom go-librespot[27160]: time="2025-12-13T10:55:21-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 13 10:55:21 gbvpi-bedroom go-librespot[27160]: time="2025-12-13T10:55:21-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 13 10:55:21 gbvpi-bedroom go-librespot[27160]: time="2025-12-13T10:55:21-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 13 10:55:21 gbvpi-bedroom go-librespot[27160]: time="2025-12-13T10:55:21-05:00" level=info msg="zeroconf server listening on port 40085" Dec 13 10:55:21 gbvpi-bedroom go-librespot[27160]: time="2025-12-13T10:55:21-05:00" level=debug msg="obtained new client token: AADKtNrKPL4+PEskldqs08C6Fu6wLSEClwEjPkDuhPbxIqREW6GKMKpkw3DCSE5GpEC4IiVOXQOYmedg2TJFGd0vy9imKzVZ9bWWX7abUKl4C4PObNExvrpbzk4tbi2BWWppKnVgaIBCfvH2mxLnz2hFD8GWbLssG0Oom45y3+2piN8xIM9hsHtxXlMV1F2wDjhqsk8fT8PLsoBcSv+2l8WFqQhqNt/Ys/V+/tNdLeBt0UEPuE8sd5asYQ==" Dec 13 10:55:21 gbvpi-bedroom go-librespot[27160]: time="2025-12-13T10:55:21-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:55:21 gbvpi-bedroom go-librespot[27160]: time="2025-12-13T10:55:21-05:00" level=debug msg="completed keyexchange" Dec 13 10:55:21 gbvpi-bedroom go-librespot[27160]: time="2025-12-13T10:55:21-05:00" level=debug msg="completed challenge" Dec 13 10:55:22 gbvpi-bedroom go-librespot[27160]: time="2025-12-13T10:55:22-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:55:22 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:55:22 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:55:23 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:23 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:23 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:55:23 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:55:23 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:55:23 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:55:24 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:24 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:25 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 86. Dec 13 10:55:25 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:25 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:25 gbvpi-bedroom go-librespot[27182]: go-librespot daemon starting... Dec 13 10:55:25 gbvpi-bedroom go-librespot[27183]: time="2025-12-13T10:55:25-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:55:25 gbvpi-bedroom go-librespot[27183]: time="2025-12-13T10:55:25-05:00" level=debug msg="app state loaded" Dec 13 10:55:25 gbvpi-bedroom go-librespot[27183]: time="2025-12-13T10:55:25-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:55:25 gbvpi-bedroom go-librespot[27183]: time="2025-12-13T10:55:25-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 13 10:55:25 gbvpi-bedroom go-librespot[27183]: time="2025-12-13T10:55:25-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 13 10:55:25 gbvpi-bedroom go-librespot[27183]: time="2025-12-13T10:55:25-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 13 10:55:25 gbvpi-bedroom go-librespot[27183]: time="2025-12-13T10:55:25-05:00" level=info msg="zeroconf server listening on port 42601" Dec 13 10:55:25 gbvpi-bedroom go-librespot[27183]: time="2025-12-13T10:55:25-05:00" level=debug msg="obtained new client token: AABcfRVm4WryRCaVAh9JTrsQ3Qnif+38eHfkULy1WLwW+HYEWq8TgYIrA0ErJVuQ3ErEBk4kjgDdEX3fFP1kLMAnfm+B1B85hcTGmkJ82nI/cn32dXJPgkZ3tn5gEp4tU9RHt2zT/tD/aeka84SnKf4TJ8ngdqZVjJc13dhxBSrj5yoctglpuEPiwKKAqj2hVQUng+DLIb18+LqhY633OUEhYmWiH+0M+7PIjXaZjMcZzLWWUEuLQqly4A==" Dec 13 10:55:25 gbvpi-bedroom go-librespot[27183]: time="2025-12-13T10:55:25-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:55:25 gbvpi-bedroom go-librespot[27183]: time="2025-12-13T10:55:25-05:00" level=debug msg="completed keyexchange" Dec 13 10:55:25 gbvpi-bedroom go-librespot[27183]: time="2025-12-13T10:55:25-05:00" level=debug msg="completed challenge" Dec 13 10:55:25 gbvpi-bedroom go-librespot[27183]: time="2025-12-13T10:55:25-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:55:25 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:55:25 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:55:27 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:27 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:28 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87. Dec 13 10:55:28 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:29 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:29 gbvpi-bedroom go-librespot[27192]: go-librespot daemon starting... Dec 13 10:55:29 gbvpi-bedroom go-librespot[27193]: time="2025-12-13T10:55:29-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:55:29 gbvpi-bedroom go-librespot[27193]: time="2025-12-13T10:55:29-05:00" level=debug msg="app state loaded" Dec 13 10:55:29 gbvpi-bedroom go-librespot[27193]: time="2025-12-13T10:55:29-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:55:29 gbvpi-bedroom go-librespot[27193]: time="2025-12-13T10:55:29-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 13 10:55:29 gbvpi-bedroom go-librespot[27193]: time="2025-12-13T10:55:29-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 13 10:55:29 gbvpi-bedroom go-librespot[27193]: time="2025-12-13T10:55:29-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 13 10:55:29 gbvpi-bedroom go-librespot[27193]: time="2025-12-13T10:55:29-05:00" level=info msg="zeroconf server listening on port 40089" Dec 13 10:55:29 gbvpi-bedroom go-librespot[27193]: time="2025-12-13T10:55:29-05:00" level=debug msg="obtained new client token: AAALyE6A4ba7HLBSFc9ooMSDSLgpa7lRdbdzwSe+DvK1XSv9AVIdDahH0dSBRjh6N8OEv2GCUvOmbC4UJsbn1qDUi9n6Gj5hvCvS0uWNlPv00Jwx1usY8lPk5rma09AvzRDXlLT/GIixm5hqwN2drk/mrhVLtwF/XLPnfLG/+0Y9evc1JA42pDce7gxKyXhAZWLdc1hHOCV1oi8w/ZREetfJBEDAx5rzC1rJlIGQ3UNaEcPCiKaeGDYTuQ==" Dec 13 10:55:29 gbvpi-bedroom go-librespot[27193]: time="2025-12-13T10:55:29-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:55:29 gbvpi-bedroom go-librespot[27193]: time="2025-12-13T10:55:29-05:00" level=debug msg="completed keyexchange" Dec 13 10:55:29 gbvpi-bedroom go-librespot[27193]: time="2025-12-13T10:55:29-05:00" level=debug msg="completed challenge" Dec 13 10:55:29 gbvpi-bedroom go-librespot[27193]: time="2025-12-13T10:55:29-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:55:29 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:55:29 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:55:30 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:30 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:32 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 88. Dec 13 10:55:32 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:32 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:32 gbvpi-bedroom go-librespot[27203]: go-librespot daemon starting... Dec 13 10:55:32 gbvpi-bedroom go-librespot[27204]: time="2025-12-13T10:55:32-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:55:32 gbvpi-bedroom go-librespot[27204]: time="2025-12-13T10:55:32-05:00" level=debug msg="app state loaded" Dec 13 10:55:32 gbvpi-bedroom go-librespot[27204]: time="2025-12-13T10:55:32-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:55:32 gbvpi-bedroom go-librespot[27204]: time="2025-12-13T10:55:32-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 13 10:55:32 gbvpi-bedroom go-librespot[27204]: time="2025-12-13T10:55:32-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 13 10:55:32 gbvpi-bedroom go-librespot[27204]: time="2025-12-13T10:55:32-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 13 10:55:32 gbvpi-bedroom go-librespot[27204]: time="2025-12-13T10:55:32-05:00" level=info msg="zeroconf server listening on port 36765" Dec 13 10:55:33 gbvpi-bedroom go-librespot[27204]: time="2025-12-13T10:55:33-05:00" level=debug msg="obtained new client token: AAA+e+Idr3umZr09K8bSf/cAJeZhqLLi2Mku07lGHEl4XpHDVmU9PkQM8sumx27VZvABR2mqvTb1ARj1kpAN7kez+hNKYiBH5fTb0G6pXvNyFnELQOfRKayqXepJmr7TNCOmroDfsi8qyQdxw9t7ZhlnrfpIufWPjx5n1K6fpqOPrb9GuU1Syk85F0gajYA/NJQUSR8Va5UrHkFaBOYg0v4/er80xnUgdqWviK0JVN1wUzV/f67BFt8=" Dec 13 10:55:33 gbvpi-bedroom go-librespot[27204]: time="2025-12-13T10:55:33-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:55:33 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:33 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:33 gbvpi-bedroom go-librespot[27204]: time="2025-12-13T10:55:33-05:00" level=debug msg="completed keyexchange" Dec 13 10:55:33 gbvpi-bedroom go-librespot[27204]: time="2025-12-13T10:55:33-05:00" level=debug msg="completed challenge" Dec 13 10:55:33 gbvpi-bedroom go-librespot[27204]: time="2025-12-13T10:55:33-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:55:33 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:55:33 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:55:33 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:33 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:36 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:36 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:36 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 89. Dec 13 10:55:36 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:36 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:36 gbvpi-bedroom go-librespot[27225]: go-librespot daemon starting... Dec 13 10:55:36 gbvpi-bedroom go-librespot[27226]: time="2025-12-13T10:55:36-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:55:36 gbvpi-bedroom go-librespot[27226]: time="2025-12-13T10:55:36-05:00" level=debug msg="app state loaded" Dec 13 10:55:36 gbvpi-bedroom go-librespot[27226]: time="2025-12-13T10:55:36-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:55:36 gbvpi-bedroom go-librespot[27226]: time="2025-12-13T10:55:36-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 13 10:55:36 gbvpi-bedroom go-librespot[27226]: time="2025-12-13T10:55:36-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 13 10:55:36 gbvpi-bedroom go-librespot[27226]: time="2025-12-13T10:55:36-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 13 10:55:36 gbvpi-bedroom go-librespot[27226]: time="2025-12-13T10:55:36-05:00" level=info msg="zeroconf server listening on port 37303" Dec 13 10:55:36 gbvpi-bedroom go-librespot[27226]: time="2025-12-13T10:55:36-05:00" level=debug msg="obtained new client token: AAC3HghU368ayVuGq+BoYwLWJewzU2oIdhbZk0Gila+oFLIQ3HDwUo3qmhB7JMLXWh5MBq2I07vKuHq/FCEE2uxL1JKkHyuCn6Zos+jc9G5tV3AQIcZb1to5rjN7G3v6ESsdcA0TV2K38vWNIDXPUdpqKs0O3m8cstuzGX/QygUGPQDxUIBKDijE2UpZCE9Svhm+jJNkmYPT/dBMV/f/sbRX2R9sWGtfADUCwgcg1ZVClPFzAMjrWrrULg==" Dec 13 10:55:36 gbvpi-bedroom go-librespot[27226]: time="2025-12-13T10:55:36-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:55:36 gbvpi-bedroom go-librespot[27226]: time="2025-12-13T10:55:36-05:00" level=debug msg="completed keyexchange" Dec 13 10:55:36 gbvpi-bedroom go-librespot[27226]: time="2025-12-13T10:55:36-05:00" level=debug msg="completed challenge" Dec 13 10:55:36 gbvpi-bedroom go-librespot[27226]: time="2025-12-13T10:55:36-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:55:36 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:55:36 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:55:39 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:39 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:40 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 90. Dec 13 10:55:40 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:40 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:40 gbvpi-bedroom go-librespot[27234]: go-librespot daemon starting... Dec 13 10:55:40 gbvpi-bedroom go-librespot[27235]: time="2025-12-13T10:55:40-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:55:40 gbvpi-bedroom go-librespot[27235]: time="2025-12-13T10:55:40-05:00" level=debug msg="app state loaded" Dec 13 10:55:40 gbvpi-bedroom go-librespot[27235]: time="2025-12-13T10:55:40-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:55:40 gbvpi-bedroom go-librespot[27235]: time="2025-12-13T10:55:40-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 13 10:55:40 gbvpi-bedroom go-librespot[27235]: time="2025-12-13T10:55:40-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 13 10:55:40 gbvpi-bedroom go-librespot[27235]: time="2025-12-13T10:55:40-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 13 10:55:40 gbvpi-bedroom go-librespot[27235]: time="2025-12-13T10:55:40-05:00" level=info msg="zeroconf server listening on port 33113" Dec 13 10:55:40 gbvpi-bedroom go-librespot[27235]: time="2025-12-13T10:55:40-05:00" level=debug msg="obtained new client token: AADMzFQnpKkFPsYvRAJfyztX84kx5UW2B7MEf2oxnFmyPq9KD0uzVLRsgnlR0+1opvwYgT9JAstxLs7Nm5uWkD46LPlxzkm8ZDzbPROR7p3+wjTwkbY/OWyZKpxzwK0qjqSXAohEpdnQumzty2XVxN3bzRKr54wgISeWlnPyWqFpqy5KNralEXVTZjr1i+sEmTcfQCt+LpUXb7dpeED+VJU2XHpGdhuOdQLFgPdtRQ65xjt6Z1HA45yDkw==" Dec 13 10:55:40 gbvpi-bedroom go-librespot[27235]: time="2025-12-13T10:55:40-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:55:40 gbvpi-bedroom go-librespot[27235]: time="2025-12-13T10:55:40-05:00" level=debug msg="completed keyexchange" Dec 13 10:55:40 gbvpi-bedroom go-librespot[27235]: time="2025-12-13T10:55:40-05:00" level=debug msg="completed challenge" Dec 13 10:55:40 gbvpi-bedroom go-librespot[27235]: time="2025-12-13T10:55:40-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:55:40 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:55:40 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:55:42 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:42 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:43 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:43 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:43 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:55:43 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:55:43 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:55:43 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:55:43 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 91. Dec 13 10:55:43 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:44 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:44 gbvpi-bedroom go-librespot[27242]: go-librespot daemon starting... Dec 13 10:55:44 gbvpi-bedroom go-librespot[27243]: time="2025-12-13T10:55:44-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:55:44 gbvpi-bedroom go-librespot[27243]: time="2025-12-13T10:55:44-05:00" level=debug msg="app state loaded" Dec 13 10:55:44 gbvpi-bedroom go-librespot[27243]: time="2025-12-13T10:55:44-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:55:44 gbvpi-bedroom go-librespot[27243]: time="2025-12-13T10:55:44-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 13 10:55:44 gbvpi-bedroom go-librespot[27243]: time="2025-12-13T10:55:44-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 13 10:55:44 gbvpi-bedroom go-librespot[27243]: time="2025-12-13T10:55:44-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 13 10:55:44 gbvpi-bedroom go-librespot[27243]: time="2025-12-13T10:55:44-05:00" level=info msg="zeroconf server listening on port 35541" Dec 13 10:55:44 gbvpi-bedroom go-librespot[27243]: time="2025-12-13T10:55:44-05:00" level=debug msg="obtained new client token: AADNFxmkHTue2WBT+ctLO6KEFsgoDXDVyGnggK6aenYC6p/yUihSR+skhdjrc1v/2P9H32Zx16j23zuMHeoiMpgxuHXt5/GGHVrc24bv8KnOsEeQoNBy8N/8fSJPrY/Q4fXOIAc/fd/Kv4sfnREKDsKpqzsR9HzI+yhHaEDsyoFdEgjMIejXO0MRuR6WRbZgvvRACDIAHhprGPH1uNIMEdjOktQ9n59T/vW4W28wNUHxBonyoF4vaihtrQ==" Dec 13 10:55:44 gbvpi-bedroom go-librespot[27243]: time="2025-12-13T10:55:44-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:55:44 gbvpi-bedroom go-librespot[27243]: time="2025-12-13T10:55:44-05:00" level=debug msg="completed keyexchange" Dec 13 10:55:44 gbvpi-bedroom go-librespot[27243]: time="2025-12-13T10:55:44-05:00" level=debug msg="completed challenge" Dec 13 10:55:44 gbvpi-bedroom go-librespot[27243]: time="2025-12-13T10:55:44-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:55:44 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:55:44 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:55:45 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:45 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:47 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 92. Dec 13 10:55:47 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:47 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:47 gbvpi-bedroom go-librespot[27264]: go-librespot daemon starting... Dec 13 10:55:47 gbvpi-bedroom volumio[26553]: info: UPDATER: Scheduling automatic update Dec 13 10:55:47 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStartTime Dec 13 10:55:47 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStopTime Dec 13 10:55:47 gbvpi-bedroom volumio[26553]: info: UPDATER: Auto update will take place at: Sun Dec 14 2025 04:14:35 GMT-0500 (Eastern Standard Time) Dec 13 10:55:47 gbvpi-bedroom go-librespot[27265]: time="2025-12-13T10:55:47-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:55:47 gbvpi-bedroom go-librespot[27265]: time="2025-12-13T10:55:47-05:00" level=debug msg="app state loaded" Dec 13 10:55:47 gbvpi-bedroom go-librespot[27265]: time="2025-12-13T10:55:47-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:55:47 gbvpi-bedroom go-librespot[27265]: time="2025-12-13T10:55:47-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 13 10:55:47 gbvpi-bedroom go-librespot[27265]: time="2025-12-13T10:55:47-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 13 10:55:47 gbvpi-bedroom go-librespot[27265]: time="2025-12-13T10:55:47-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 13 10:55:47 gbvpi-bedroom go-librespot[27265]: time="2025-12-13T10:55:47-05:00" level=info msg="zeroconf server listening on port 39379" Dec 13 10:55:48 gbvpi-bedroom go-librespot[27265]: time="2025-12-13T10:55:48-05:00" level=debug msg="obtained new client token: AAC7ErzlC9E22uz3eXz29ikZZVLB3WkCmz42Knv/4MQP9+zozRzmnkSMMD1tb2b9ak2sUySKlVGIVGeW2QkqcWjObsIa9o7Akeb/c/3ZobHIFBcl7RkL7eAg/AMvJavHYImgPQlkvgUj3Nh2ZcjDdW2sn97TJ3VPOU1wAovEJqMqc1b7lf2X11AoyQBmAh8d+AehP5+JO5Oand7SNzqaAkTZBj+VKhwq7BwzWDCJlwX2e9Xe2lh5Mc8=" Dec 13 10:55:48 gbvpi-bedroom go-librespot[27265]: time="2025-12-13T10:55:48-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:55:48 gbvpi-bedroom go-librespot[27265]: time="2025-12-13T10:55:48-05:00" level=debug msg="completed keyexchange" Dec 13 10:55:48 gbvpi-bedroom go-librespot[27265]: time="2025-12-13T10:55:48-05:00" level=debug msg="completed challenge" Dec 13 10:55:48 gbvpi-bedroom go-librespot[27265]: time="2025-12-13T10:55:48-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:55:48 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:55:48 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:55:48 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:48 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:51 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:51 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:51 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93. Dec 13 10:55:51 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:51 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:51 gbvpi-bedroom go-librespot[27276]: go-librespot daemon starting... Dec 13 10:55:51 gbvpi-bedroom go-librespot[27277]: time="2025-12-13T10:55:51-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:55:51 gbvpi-bedroom go-librespot[27277]: time="2025-12-13T10:55:51-05:00" level=debug msg="app state loaded" Dec 13 10:55:51 gbvpi-bedroom go-librespot[27277]: time="2025-12-13T10:55:51-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:55:51 gbvpi-bedroom go-librespot[27277]: time="2025-12-13T10:55:51-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 13 10:55:51 gbvpi-bedroom go-librespot[27277]: time="2025-12-13T10:55:51-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 13 10:55:51 gbvpi-bedroom go-librespot[27277]: time="2025-12-13T10:55:51-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 13 10:55:51 gbvpi-bedroom go-librespot[27277]: time="2025-12-13T10:55:51-05:00" level=info msg="zeroconf server listening on port 46387" Dec 13 10:55:51 gbvpi-bedroom go-librespot[27277]: time="2025-12-13T10:55:51-05:00" level=debug msg="obtained new client token: AADHz9bIxRWjQr4ktUBJgs0wQyXuGZpaQHqKN8mssQTlA2wScdcj2PHdkDqM8APuKUoDgZB+04iO06j6VI7Ia6DQj1lSl3DJymQTP9LlMJ1bGzYnoQCbhlM+SA7/Yo/8qmWb+IPIIolPGs5e/+eiJm059mlGBgBmOitPLt43B/hSCoCjBuuznsmrBIwptwIoiB9HiQ1V+I6969Kauv6CLu3W065esFk/3hwz8wZ7mpgfdXAj7LFe/QX1Vg==" Dec 13 10:55:51 gbvpi-bedroom go-librespot[27277]: time="2025-12-13T10:55:51-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Dec 13 10:55:51 gbvpi-bedroom go-librespot[27277]: time="2025-12-13T10:55:51-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Dec 13 10:55:51 gbvpi-bedroom go-librespot[27277]: time="2025-12-13T10:55:51-05:00" level=debug msg="completed keyexchange" Dec 13 10:55:51 gbvpi-bedroom go-librespot[27277]: time="2025-12-13T10:55:51-05:00" level=debug msg="completed challenge" Dec 13 10:55:52 gbvpi-bedroom go-librespot[27277]: time="2025-12-13T10:55:52-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:55:52 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:55:52 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:55:53 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:53 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:55:54 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:54 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:55 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 94. Dec 13 10:55:55 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:55 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:55 gbvpi-bedroom go-librespot[27299]: go-librespot daemon starting... Dec 13 10:55:55 gbvpi-bedroom go-librespot[27300]: time="2025-12-13T10:55:55-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:55:55 gbvpi-bedroom go-librespot[27300]: time="2025-12-13T10:55:55-05:00" level=debug msg="app state loaded" Dec 13 10:55:55 gbvpi-bedroom go-librespot[27300]: time="2025-12-13T10:55:55-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:55:55 gbvpi-bedroom go-librespot[27300]: time="2025-12-13T10:55:55-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 13 10:55:55 gbvpi-bedroom go-librespot[27300]: time="2025-12-13T10:55:55-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 13 10:55:55 gbvpi-bedroom go-librespot[27300]: time="2025-12-13T10:55:55-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 13 10:55:55 gbvpi-bedroom go-librespot[27300]: time="2025-12-13T10:55:55-05:00" level=info msg="zeroconf server listening on port 38871" Dec 13 10:55:55 gbvpi-bedroom go-librespot[27300]: time="2025-12-13T10:55:55-05:00" level=debug msg="obtained new client token: AAAmthNEKfwjd5zS1CvaeB/a6La1Rmez+Huow4cWu7QQ7yx1cyAyFB6gtPaxUaGRLrtZ7StlRFfiZhAFrAgrAvkj+C4c2MNnQwj4S1iU0x+Gn0hNdJKppiL29AaFKnK9hGAvP35htpSh/RhshqZ0icRydNYTUh74bz2kmal+hNcx9dtvJLfETf4IRuygTawQJ03RwIxHMK4lsl5GyaPihny0zlenF55A1vZn7pUpeAY6FjvxU2XBpb62EQ==" Dec 13 10:55:55 gbvpi-bedroom go-librespot[27300]: time="2025-12-13T10:55:55-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:55:55 gbvpi-bedroom go-librespot[27300]: time="2025-12-13T10:55:55-05:00" level=debug msg="completed keyexchange" Dec 13 10:55:55 gbvpi-bedroom go-librespot[27300]: time="2025-12-13T10:55:55-05:00" level=debug msg="completed challenge" Dec 13 10:55:55 gbvpi-bedroom go-librespot[27300]: time="2025-12-13T10:55:55-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:55:55 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:55:55 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:55:57 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:55:57 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:55:58 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 95. Dec 13 10:55:58 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:59 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:55:59 gbvpi-bedroom go-librespot[27309]: go-librespot daemon starting... Dec 13 10:55:59 gbvpi-bedroom go-librespot[27310]: time="2025-12-13T10:55:59-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:55:59 gbvpi-bedroom go-librespot[27310]: time="2025-12-13T10:55:59-05:00" level=debug msg="app state loaded" Dec 13 10:55:59 gbvpi-bedroom go-librespot[27310]: time="2025-12-13T10:55:59-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:55:59 gbvpi-bedroom go-librespot[27310]: time="2025-12-13T10:55:59-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 13 10:55:59 gbvpi-bedroom go-librespot[27310]: time="2025-12-13T10:55:59-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 13 10:55:59 gbvpi-bedroom go-librespot[27310]: time="2025-12-13T10:55:59-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 13 10:55:59 gbvpi-bedroom go-librespot[27310]: time="2025-12-13T10:55:59-05:00" level=info msg="zeroconf server listening on port 46481" Dec 13 10:55:59 gbvpi-bedroom go-librespot[27310]: time="2025-12-13T10:55:59-05:00" level=debug msg="obtained new client token: AACbaeMm3IIaypXCVXGsTDGeXxuqXlZFEEn8J/2fOLr9T03Wg15q/ddjCmF2cKn034Ribs/GLnh2Lam6MVwUpe8nepZiF5crQjfK6ycUiyvOKawGYfWdH8FkJZuIWWkFql3v15JDylef7/C9l77cyX92snAz+tZaHE0+Fcm7jLMfbCQkbDfMgukm4YhOyH7WpesK5tM56fYkZOdccy1bzCRR0wy4BGlUMqNxMIGQocpw805BidlSIpIJjw==" Dec 13 10:55:59 gbvpi-bedroom go-librespot[27310]: time="2025-12-13T10:55:59-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:55:59 gbvpi-bedroom go-librespot[27310]: time="2025-12-13T10:55:59-05:00" level=debug msg="completed keyexchange" Dec 13 10:55:59 gbvpi-bedroom go-librespot[27310]: time="2025-12-13T10:55:59-05:00" level=debug msg="completed challenge" Dec 13 10:55:59 gbvpi-bedroom go-librespot[27310]: time="2025-12-13T10:55:59-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:55:59 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:55:59 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:56:00 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:56:00 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:56:02 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 96. Dec 13 10:56:02 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:56:02 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:56:02 gbvpi-bedroom go-librespot[27317]: go-librespot daemon starting... Dec 13 10:56:02 gbvpi-bedroom go-librespot[27318]: time="2025-12-13T10:56:02-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:56:02 gbvpi-bedroom go-librespot[27318]: time="2025-12-13T10:56:02-05:00" level=debug msg="app state loaded" Dec 13 10:56:02 gbvpi-bedroom go-librespot[27318]: time="2025-12-13T10:56:02-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:56:02 gbvpi-bedroom go-librespot[27318]: time="2025-12-13T10:56:02-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 13 10:56:02 gbvpi-bedroom go-librespot[27318]: time="2025-12-13T10:56:02-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 13 10:56:02 gbvpi-bedroom go-librespot[27318]: time="2025-12-13T10:56:02-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 13 10:56:02 gbvpi-bedroom go-librespot[27318]: time="2025-12-13T10:56:02-05:00" level=info msg="zeroconf server listening on port 40747" Dec 13 10:56:03 gbvpi-bedroom go-librespot[27318]: time="2025-12-13T10:56:03-05:00" level=debug msg="obtained new client token: AABmRbVzbcL3pyprg2vv9BcPLojISESmCAsEnbwlJfb/HtoXmkDK9zVFIH0Dt+5jz2CGE62mvD9VYOm9SsQpX+5PgVr8Z053kybWnP9C5FMr52kYumLSN+dtAOEMJ8jRutpMNbqqI4n96iH7rUWgn7zDvsdqb6fKV2BDAu4YIlks+wUuyu0HJId7pLgCL6+xhwcdQnUiJb6Wjy8wXOce8lpoyPV8Cu/2Hp4b9zyKjzPKJgsecdTX6ao=" Dec 13 10:56:03 gbvpi-bedroom go-librespot[27318]: time="2025-12-13T10:56:03-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:56:03 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:56:03 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:56:03 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:56:03 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:56:03 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:56:03 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:56:03 gbvpi-bedroom go-librespot[27318]: time="2025-12-13T10:56:03-05:00" level=debug msg="completed keyexchange" Dec 13 10:56:03 gbvpi-bedroom go-librespot[27318]: time="2025-12-13T10:56:03-05:00" level=debug msg="completed challenge" Dec 13 10:56:03 gbvpi-bedroom go-librespot[27318]: time="2025-12-13T10:56:03-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:56:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:56:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:56:03 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:56:03 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:56:06 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:56:06 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:56:06 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 97. Dec 13 10:56:06 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:56:06 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:56:06 gbvpi-bedroom go-librespot[27339]: go-librespot daemon starting... Dec 13 10:56:06 gbvpi-bedroom go-librespot[27340]: time="2025-12-13T10:56:06-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:56:06 gbvpi-bedroom go-librespot[27340]: time="2025-12-13T10:56:06-05:00" level=debug msg="app state loaded" Dec 13 10:56:06 gbvpi-bedroom go-librespot[27340]: time="2025-12-13T10:56:06-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:56:06 gbvpi-bedroom go-librespot[27340]: time="2025-12-13T10:56:06-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 13 10:56:06 gbvpi-bedroom go-librespot[27340]: time="2025-12-13T10:56:06-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 13 10:56:06 gbvpi-bedroom go-librespot[27340]: time="2025-12-13T10:56:06-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 13 10:56:06 gbvpi-bedroom go-librespot[27340]: time="2025-12-13T10:56:06-05:00" level=info msg="zeroconf server listening on port 35829" Dec 13 10:56:06 gbvpi-bedroom go-librespot[27340]: time="2025-12-13T10:56:06-05:00" level=debug msg="obtained new client token: AAAmdqOHw45u4JOVopk3W3qEzfTmRWPFI2F0jyDxq47eG3fp1gwG3XZRk+bO0p68lz3C8XzIhEnj1PfIQ5aEgEDLjn15KAODrTsMBRvBkdgxIAtFmA4mB8qllgAHjNxKpa6vcrNZEeL4Q9eGW6ZYEEnh9OwXhLStQy2Ry1CH4N6h0yjH1WNB6rCrU+BJLKHKs34fv7q13fduWuZFfxnuziTDw1No7ARLn4P/tdMw5uBmpub1opSk96UP1Q==" Dec 13 10:56:06 gbvpi-bedroom go-librespot[27340]: time="2025-12-13T10:56:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:56:06 gbvpi-bedroom go-librespot[27340]: time="2025-12-13T10:56:06-05:00" level=debug msg="completed keyexchange" Dec 13 10:56:06 gbvpi-bedroom go-librespot[27340]: time="2025-12-13T10:56:06-05:00" level=debug msg="completed challenge" Dec 13 10:56:06 gbvpi-bedroom go-librespot[27340]: time="2025-12-13T10:56:06-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:56:07 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:56:07 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:56:09 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:56:09 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:56:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 98. Dec 13 10:56:10 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:56:10 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:56:10 gbvpi-bedroom go-librespot[27350]: go-librespot daemon starting... Dec 13 10:56:10 gbvpi-bedroom go-librespot[27351]: time="2025-12-13T10:56:10-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:56:10 gbvpi-bedroom go-librespot[27351]: time="2025-12-13T10:56:10-05:00" level=debug msg="app state loaded" Dec 13 10:56:10 gbvpi-bedroom go-librespot[27351]: time="2025-12-13T10:56:10-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:56:10 gbvpi-bedroom go-librespot[27351]: time="2025-12-13T10:56:10-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 13 10:56:10 gbvpi-bedroom go-librespot[27351]: time="2025-12-13T10:56:10-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 13 10:56:10 gbvpi-bedroom go-librespot[27351]: time="2025-12-13T10:56:10-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 13 10:56:10 gbvpi-bedroom go-librespot[27351]: time="2025-12-13T10:56:10-05:00" level=info msg="zeroconf server listening on port 33299" Dec 13 10:56:10 gbvpi-bedroom go-librespot[27351]: time="2025-12-13T10:56:10-05:00" level=debug msg="obtained new client token: AABZ+ofscGcwza7h+QpR9CbBYPIij6FUM7GwUlndIMG1+CTmaKeuATfqAOZwP/5jkmvtUFdCSwMP3yWAN9OestnYjH/jGGoeFDj0aN59+8KRw1cBfQ9EBU6sgclr9A072LeX9YentIYb5qFH+z61bpIScTMlZu9zASdY09i5y2kYzWBty6u7hCGCgNoAtxk9Dijch65c+TMZQmssFngO9hWsG6fKOto3bWkaqrgYAbScqZYBBqaZAttAwg==" Dec 13 10:56:10 gbvpi-bedroom go-librespot[27351]: time="2025-12-13T10:56:10-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:56:10 gbvpi-bedroom go-librespot[27351]: time="2025-12-13T10:56:10-05:00" level=debug msg="completed keyexchange" Dec 13 10:56:10 gbvpi-bedroom go-librespot[27351]: time="2025-12-13T10:56:10-05:00" level=debug msg="completed challenge" Dec 13 10:56:10 gbvpi-bedroom go-librespot[27351]: time="2025-12-13T10:56:10-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:56:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:56:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:56:12 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:56:12 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:56:13 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:56:13 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:56:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99. Dec 13 10:56:13 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:56:14 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:56:14 gbvpi-bedroom go-librespot[27361]: go-librespot daemon starting... Dec 13 10:56:14 gbvpi-bedroom go-librespot[27362]: time="2025-12-13T10:56:14-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:56:14 gbvpi-bedroom go-librespot[27362]: time="2025-12-13T10:56:14-05:00" level=debug msg="app state loaded" Dec 13 10:56:14 gbvpi-bedroom go-librespot[27362]: time="2025-12-13T10:56:14-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:56:14 gbvpi-bedroom go-librespot[27362]: time="2025-12-13T10:56:14-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 13 10:56:14 gbvpi-bedroom go-librespot[27362]: time="2025-12-13T10:56:14-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 13 10:56:14 gbvpi-bedroom go-librespot[27362]: time="2025-12-13T10:56:14-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 13 10:56:14 gbvpi-bedroom go-librespot[27362]: time="2025-12-13T10:56:14-05:00" level=info msg="zeroconf server listening on port 36219" Dec 13 10:56:14 gbvpi-bedroom go-librespot[27362]: time="2025-12-13T10:56:14-05:00" level=debug msg="obtained new client token: AACLqiIBSKPBfsDAZ5z89prGD7/7xzsXg71N+JWV54oozJb3+/CUalYSGKPtwH1spFU2eiQRiWKiZYEA61REQBnqvj62kfx8GuZPBnyZk7+h/jJ0e06LTEnvI3lcvSeuPyLYemsa13iVxf0AevNJEBUnKcw+qpwgl7Xt3y91mG85xhmlT0dzEd3e22uj5d25blnSMdTiCe43lQRpu2s++A4kWDf7Euzb0hLIx/DYBet7R+sKksobVcQQwQ==" Dec 13 10:56:14 gbvpi-bedroom go-librespot[27362]: time="2025-12-13T10:56:14-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Dec 13 10:56:14 gbvpi-bedroom go-librespot[27362]: time="2025-12-13T10:56:14-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Dec 13 10:56:14 gbvpi-bedroom go-librespot[27362]: time="2025-12-13T10:56:14-05:00" level=debug msg="completed keyexchange" Dec 13 10:56:14 gbvpi-bedroom go-librespot[27362]: time="2025-12-13T10:56:14-05:00" level=debug msg="completed challenge" Dec 13 10:56:14 gbvpi-bedroom go-librespot[27362]: time="2025-12-13T10:56:14-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:56:14 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:56:14 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:56:15 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:56:15 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:56:17 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 100. Dec 13 10:56:17 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:56:17 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:56:17 gbvpi-bedroom go-librespot[27383]: go-librespot daemon starting... Dec 13 10:56:17 gbvpi-bedroom go-librespot[27384]: time="2025-12-13T10:56:17-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:56:17 gbvpi-bedroom go-librespot[27384]: time="2025-12-13T10:56:17-05:00" level=debug msg="app state loaded" Dec 13 10:56:17 gbvpi-bedroom go-librespot[27384]: time="2025-12-13T10:56:17-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:56:17 gbvpi-bedroom go-librespot[27384]: time="2025-12-13T10:56:17-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 13 10:56:17 gbvpi-bedroom go-librespot[27384]: time="2025-12-13T10:56:17-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 13 10:56:17 gbvpi-bedroom go-librespot[27384]: time="2025-12-13T10:56:17-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 13 10:56:17 gbvpi-bedroom go-librespot[27384]: time="2025-12-13T10:56:17-05:00" level=info msg="zeroconf server listening on port 46307" Dec 13 10:56:18 gbvpi-bedroom go-librespot[27384]: time="2025-12-13T10:56:18-05:00" level=debug msg="obtained new client token: AABcMI3EnpBe0Zy7P79w+TitTRhzhDCZz0wRnG4XFL9phKENAUvviciCGvlK7HaOmufxPvDRCrfOo6gNhfjPzYLhjN/Rx8mSFsmCvPlknFUCnz6R/L8SzDt8Ez7mnP0geRAetxNT2gTkhNaOZFOcDINHfgJvHx5rwkWONzXL2G9FCiM3gi2Iv9GtkVp84+QbBei5pU7M1gwQgRc3SuDcMUOXzhZjhZLmZ5zyx1kZsGNSnz+mfhE+oqQ=" Dec 13 10:56:18 gbvpi-bedroom go-librespot[27384]: time="2025-12-13T10:56:18-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:56:18 gbvpi-bedroom go-librespot[27384]: time="2025-12-13T10:56:18-05:00" level=debug msg="completed keyexchange" Dec 13 10:56:18 gbvpi-bedroom go-librespot[27384]: time="2025-12-13T10:56:18-05:00" level=debug msg="completed challenge" Dec 13 10:56:18 gbvpi-bedroom go-librespot[27384]: time="2025-12-13T10:56:18-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:56:18 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:56:18 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:56:18 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:56:18 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:56:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 101. Dec 13 10:56:21 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:56:21 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:56:21 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:56:21 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:56:21 gbvpi-bedroom go-librespot[27392]: go-librespot daemon starting... Dec 13 10:56:21 gbvpi-bedroom go-librespot[27393]: time="2025-12-13T10:56:21-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:56:21 gbvpi-bedroom go-librespot[27393]: time="2025-12-13T10:56:21-05:00" level=debug msg="app state loaded" Dec 13 10:56:21 gbvpi-bedroom go-librespot[27393]: time="2025-12-13T10:56:21-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:56:21 gbvpi-bedroom go-librespot[27393]: time="2025-12-13T10:56:21-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 13 10:56:21 gbvpi-bedroom go-librespot[27393]: time="2025-12-13T10:56:21-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 13 10:56:21 gbvpi-bedroom go-librespot[27393]: time="2025-12-13T10:56:21-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 13 10:56:21 gbvpi-bedroom go-librespot[27393]: time="2025-12-13T10:56:21-05:00" level=info msg="zeroconf server listening on port 34581" Dec 13 10:56:21 gbvpi-bedroom go-librespot[27393]: time="2025-12-13T10:56:21-05:00" level=debug msg="obtained new client token: AADdONglkGQVVdP4MbtKuKcFHldCEnJQHVPaanny3Qfx07cuZ5DzMPwDPKkCUZTlQ2JPeZ41zUtam2VoZ+34rO/ATy4obKTpjyyuoG0uyjVi6tnCGs1NMr/4XfqBEl6do+wljZGMLv12vAbnaXruIasv99w31O/7DCaibJ4m2qDuF7qKmz2CylA7B9pooPfG3cxHTthIBIPLyyJBWbW52m7Lm/QAs+odbIqxxR3YQSrmX4asgkoOuNX3dw==" Dec 13 10:56:21 gbvpi-bedroom go-librespot[27393]: time="2025-12-13T10:56:21-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 13 10:56:21 gbvpi-bedroom go-librespot[27393]: time="2025-12-13T10:56:21-05:00" level=debug msg="completed keyexchange" Dec 13 10:56:21 gbvpi-bedroom go-librespot[27393]: time="2025-12-13T10:56:21-05:00" level=debug msg="completed challenge" Dec 13 10:56:21 gbvpi-bedroom go-librespot[27393]: time="2025-12-13T10:56:21-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:56:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:56:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:56:23 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:56:23 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:56:23 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:56:23 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:56:23 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:56:23 gbvpi-bedroom volumio[26553]: info: Listing playlists Dec 13 10:56:24 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:56:24 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:56:25 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 102. Dec 13 10:56:25 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:56:25 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:56:25 gbvpi-bedroom go-librespot[27414]: go-librespot daemon starting... Dec 13 10:56:25 gbvpi-bedroom go-librespot[27415]: time="2025-12-13T10:56:25-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:56:25 gbvpi-bedroom go-librespot[27415]: time="2025-12-13T10:56:25-05:00" level=debug msg="app state loaded" Dec 13 10:56:25 gbvpi-bedroom go-librespot[27415]: time="2025-12-13T10:56:25-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:56:25 gbvpi-bedroom go-librespot[27415]: time="2025-12-13T10:56:25-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 13 10:56:25 gbvpi-bedroom go-librespot[27415]: time="2025-12-13T10:56:25-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 13 10:56:25 gbvpi-bedroom go-librespot[27415]: time="2025-12-13T10:56:25-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 13 10:56:25 gbvpi-bedroom go-librespot[27415]: time="2025-12-13T10:56:25-05:00" level=info msg="zeroconf server listening on port 36023" Dec 13 10:56:26 gbvpi-bedroom go-librespot[27415]: time="2025-12-13T10:56:26-05:00" level=debug msg="obtained new client token: AAC5OpWVuU4bJKP0tqm3EiIkTAyXiwWJDsvhGFA5u6WnnWbjQSHi3nyvksGG/mdUh8AqVxKIjK8gzMxaClYhnlNx1LNLghQJ4wOthRzE/MD88Re/a2QK5ijbLIRGiW78rTDifJ6JVg6wL2+V6GpVYfPLM/Nlv7p5i6QQ0FQN1A71KRUUOzd+rvVw0Rq2jOn7KGMhekBDqx0VUCTbJ50QpZLEEZuLokji8q7+gGUYJsMDeFGA7MUTRI4efQ==" Dec 13 10:56:26 gbvpi-bedroom go-librespot[27415]: time="2025-12-13T10:56:26-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Dec 13 10:56:26 gbvpi-bedroom go-librespot[27415]: time="2025-12-13T10:56:26-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Dec 13 10:56:26 gbvpi-bedroom go-librespot[27415]: time="2025-12-13T10:56:26-05:00" level=debug msg="completed keyexchange" Dec 13 10:56:26 gbvpi-bedroom go-librespot[27415]: time="2025-12-13T10:56:26-05:00" level=debug msg="completed challenge" Dec 13 10:56:26 gbvpi-bedroom go-librespot[27415]: time="2025-12-13T10:56:26-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:56:26 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:56:26 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:56:27 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:56:27 gbvpi-bedroom volumio[26553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:56:29 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 103. Dec 13 10:56:29 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:56:30 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:56:30 gbvpi-bedroom go-librespot[27425]: go-librespot daemon starting... Dec 13 10:56:30 gbvpi-bedroom go-librespot[27426]: time="2025-12-13T10:56:30-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:56:30 gbvpi-bedroom go-librespot[27426]: time="2025-12-13T10:56:30-05:00" level=debug msg="app state loaded" Dec 13 10:56:30 gbvpi-bedroom go-librespot[27426]: time="2025-12-13T10:56:30-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:56:30 gbvpi-bedroom go-librespot[27426]: time="2025-12-13T10:56:30-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 13 10:56:30 gbvpi-bedroom go-librespot[27426]: time="2025-12-13T10:56:30-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 13 10:56:30 gbvpi-bedroom go-librespot[27426]: time="2025-12-13T10:56:30-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 13 10:56:30 gbvpi-bedroom go-librespot[27426]: time="2025-12-13T10:56:30-05:00" level=info msg="zeroconf server listening on port 35071" Dec 13 10:56:30 gbvpi-bedroom go-librespot[27426]: time="2025-12-13T10:56:30-05:00" level=debug msg="obtained new client token: AAA3un+y7qOVHgYBuSDN5+WBJrLVI1DITTIdR1JzcHFu3jrvKhl5BRDDZKhDY/PLhCZ80LzGcbSLBDCWxPOzHvk+cSNMJL9NNdUYNNFrSJjVAtx7s8eo886PieB5FWLmOLaOgmFwgVGsjGu6HTp7Wc815OiMwig4gx0aPQXOKJCyy2cn5nF3589qWvgNi60ycEkoMmAjz6WeGxezOAMt/a86Mo9J5iDKundUKgubE2+pvoD4r77xJJcAJA==" Dec 13 10:56:30 gbvpi-bedroom go-librespot[27426]: time="2025-12-13T10:56:30-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Dec 13 10:56:30 gbvpi-bedroom go-librespot[27426]: time="2025-12-13T10:56:30-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Dec 13 10:56:30 gbvpi-bedroom go-librespot[27426]: time="2025-12-13T10:56:30-05:00" level=debug msg="completed keyexchange" Dec 13 10:56:30 gbvpi-bedroom go-librespot[27426]: time="2025-12-13T10:56:30-05:00" level=debug msg="completed challenge" Dec 13 10:56:30 gbvpi-bedroom volumio[26553]: info: Initializing connection to go-librespot Websocket Dec 13 10:56:30 gbvpi-bedroom go-librespot[27426]: time="2025-12-13T10:56:30-05:00" level=debug msg="new websocket client" Dec 13 10:56:30 gbvpi-bedroom volumio[26553]: info: Connection to go-librespot Websocket established Dec 13 10:56:30 gbvpi-bedroom go-librespot[27426]: time="2025-12-13T10:56:30-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 13 10:56:30 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 10:56:30 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 10:56:30 gbvpi-bedroom volumio[26553]: info: Connection to go-librespot Websocket closed Dec 13 10:56:33 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:56:33 gbvpi-bedroom volumio[26553]: info: CoreCommandRouter::volumioGetState Dec 13 10:56:33 gbvpi-bedroom volumio[26553]: info: Getting Spotify volume Dec 13 10:56:33 gbvpi-bedroom volumio[26553]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 13 10:56:33 gbvpi-bedroom volumio[26553]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 10:56:33 gbvpi-bedroom volumio[26553]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 13 10:56:33 gbvpi-bedroom volumio[26553]: errno: -111, Dec 13 10:56:33 gbvpi-bedroom volumio[26553]: code: 'ECONNREFUSED', Dec 13 10:56:33 gbvpi-bedroom volumio[26553]: syscall: 'connect', Dec 13 10:56:33 gbvpi-bedroom volumio[26553]: address: '127.0.0.1', Dec 13 10:56:33 gbvpi-bedroom volumio[26553]: port: 9879, Dec 13 10:56:33 gbvpi-bedroom volumio[26553]: response: undefined Dec 13 10:56:33 gbvpi-bedroom volumio[26553]: } Dec 13 10:56:33 gbvpi-bedroom volumio[26553]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 13 10:56:33 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 104. Dec 13 10:56:33 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:56:33 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 10:56:33 gbvpi-bedroom go-librespot[27445]: go-librespot daemon starting... Dec 13 10:56:33 gbvpi-bedroom go-librespot[27446]: time="2025-12-13T10:56:33-05:00" level=info msg="running go-librespot 0.4.0" Dec 13 10:56:33 gbvpi-bedroom go-librespot[27446]: time="2025-12-13T10:56:33-05:00" level=debug msg="app state loaded" Dec 13 10:56:33 gbvpi-bedroom go-librespot[27446]: time="2025-12-13T10:56:33-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 10:56:33 gbvpi-bedroom sudo[27454]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-13 10:55' Dec 13 10:56:33 gbvpi-bedroom sudo[27454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 10:56:33 gbvpi-bedroom go-librespot[27446]: time="2025-12-13T10:56:33-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 13 10:56:33 gbvpi-bedroom go-librespot[27446]: time="2025-12-13T10:56:33-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 13 10:56:33 gbvpi-bedroom go-librespot[27446]: time="2025-12-13T10:56:33-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-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="6a0bffa825dc2af90b21170949f5219ba5ab5701" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed Dec 10 09:27:23 UTC 2025" VOLUMIO_VERSION="4.075" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4bd01f93a654c7068f4553fbd69478e2"