Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: Streaming services startup
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: Starting Streaming Daemon
Dec 15 11:16:00 gbvpi-bedroom sudo[22329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Dec 15 11:16:00 gbvpi-bedroom sudo[22329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Dec 15 11:16:00 gbvpi-bedroom sudo[22329]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: error: Cannot start Volumio Streaming Daemon
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: MyVolumio token set successfully
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: MYVOLUMIO: Adding device
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: MYVOLUMIO: Evaluating Server
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: MyVolumio Plan changed: premium
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Subscribed plan changed to premium
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: Removing browser output: myVolumio user plan is not superstar
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: Removing audio output:
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: MYVOLUMIO: Adding device
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: MYVOLUMIO: Evaluating Server
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: Remote config written successfully
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: Starting Tunnel 1
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: Starting Tunnel Connection Checker
Dec 15 11:16:00 gbvpi-bedroom volumio[22026]: info: Completed starting MyVolumio Plugin
Dec 15 11:16:01 gbvpi-bedroom volumio[22026]: info: MYVolumio Device enabled
Dec 15 11:16:01 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins...
Dec 15 11:16:01 gbvpi-bedroom volumio[22026]: info: MyVolumio status changed
Dec 15 11:16:01 gbvpi-bedroom volumio[22026]: info: Streaming services startup
Dec 15 11:16:01 gbvpi-bedroom volumio[22026]: info: Starting Streaming Daemon
Dec 15 11:16:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31.
Dec 15 11:16:01 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:01 gbvpi-bedroom sudo[22374]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Dec 15 11:16:01 gbvpi-bedroom sudo[22374]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 11:16:01 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid
Dec 15 11:16:01 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"...
Dec 15 11:16:01 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:01 gbvpi-bedroom go-librespot[22375]: go-librespot daemon starting...
Dec 15 11:16:01 gbvpi-bedroom go-librespot[22377]: time="2025-12-15T11:16:01-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:16:01 gbvpi-bedroom go-librespot[22377]: time="2025-12-15T11:16:01-05:00" level=debug msg="app state loaded"
Dec 15 11:16:01 gbvpi-bedroom sudo[22374]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:01 gbvpi-bedroom go-librespot[22377]: time="2025-12-15T11:16:01-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:16:01 gbvpi-bedroom volumio[22026]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart
Dec 15 11:16:01 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Loading plugin "multiroom"...
Dec 15 11:16:01 gbvpi-bedroom go-librespot[22377]: time="2025-12-15T11:16:01-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 15 11:16:01 gbvpi-bedroom go-librespot[22377]: time="2025-12-15T11:16:01-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 15 11:16:01 gbvpi-bedroom go-librespot[22377]: time="2025-12-15T11:16:01-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 15 11:16:01 gbvpi-bedroom go-librespot[22377]: time="2025-12-15T11:16:01-05:00" level=info msg="zeroconf server listening on port 41903"
Dec 15 11:16:01 gbvpi-bedroom go-librespot[22377]: time="2025-12-15T11:16:01-05:00" level=debug msg="obtained new client token: AABZlzBjnYAZkOFSCD9NObuB0JYF8jfG/g2em2ujS3Kx8iZmWXFY1NGa28ztBf9Ff6mSw7Hvqh3G/2XfwSMtBycNJiqvzvoUjvDRqW4crdTHaMmTxDL898v8OerMnG7AkkLJTneq+mvytFDM6bu4SlBufApUl4mI8Yi/yVRiKXZbpd/aBiAnj2wnFiTK6EKoGhlG5p9FA106zuhecnFBUujF2ukw4lHPl+RinHaorRojBCp66tLAD9rz+A=="
Dec 15 11:16:01 gbvpi-bedroom go-librespot[22377]: time="2025-12-15T11:16:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:16:01 gbvpi-bedroom go-librespot[22377]: time="2025-12-15T11:16:01-05:00" level=debug msg="completed keyexchange"
Dec 15 11:16:01 gbvpi-bedroom go-librespot[22377]: time="2025-12-15T11:16:01-05:00" level=debug msg="completed challenge"
Dec 15 11:16:01 gbvpi-bedroom go-librespot[22377]: time="2025-12-15T11:16:01-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 15 11:16:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:16:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom
Dec 15 11:16:02 gbvpi-bedroom sudo[22386]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom
Dec 15 11:16:02 gbvpi-bedroom sudo[22386]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 11:16:02 gbvpi-bedroom sudo[22386]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: MRS: MultiRoom plugin initialized
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: MRS: STOPPING SNAPCLIENT
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: MRS: Snap server stop
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: MRS: STOPPING volumioStreaming
Dec 15 11:16:02 gbvpi-bedroom sudo[22403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient
Dec 15 11:16:02 gbvpi-bedroom sudo[22403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 11:16:02 gbvpi-bedroom sudo[22405]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver
Dec 15 11:16:02 gbvpi-bedroom sudo[22405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 11:16:02 gbvpi-bedroom sudo[22407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming
Dec 15 11:16:02 gbvpi-bedroom sudo[22407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 11:16:02 gbvpi-bedroom sudo[22411]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/*
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"...
Dec 15 11:16:02 gbvpi-bedroom sudo[22411]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 11:16:02 gbvpi-bedroom sudo[22411]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Loading plugin "manifestui"...
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"...
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"...
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"...
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Loading plugin "tidal"...
Dec 15 11:16:02 gbvpi-bedroom sudo[22403]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Loading plugin "qobuz"...
Dec 15 11:16:02 gbvpi-bedroom sudo[22405]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:02 gbvpi-bedroom sudo[22407]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"...
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"...
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Preparing to generate the ALSA configuration file
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Setting Geolocation for MyVolumio to us1
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Reading ALSA contributions from plugins.
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: MRS: Removed streaming files
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: MRS: volumioStreaming STOPPED
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: MRS: SNAPSERVER STOPPED
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: MRS: SNAPCLIENT STOPPED
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: error: Cannot start Volumio Streaming Daemon
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Setting Geolocation for MyVolumio to us4
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Asound.conf file written
Dec 15 11:16:02 gbvpi-bedroom sudo[22417]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf
Dec 15 11:16:02 gbvpi-bedroom sudo[22417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 11:16:02 gbvpi-bedroom sudo[22417]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Output device has changed, restarting MPD
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Output device has changed, restarting Shairport Sync
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 11:16:02 gbvpi-bedroom sudo[22423]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 15 11:16:02 gbvpi-bedroom sudo[22423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 11:16:02 gbvpi-bedroom sudo[22423]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 15 11:16:02 gbvpi-bedroom sudo[22426]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Dec 15 11:16:02 gbvpi-bedroom sudo[22426]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: ------------------------------------ BT MESSAGE: [FUNC] onStart
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready.
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: MRS: Pushing multiroomSync output for this device
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: MRS: Pushing multiroomSync output
Dec 15 11:16:02 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon...
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Adding audio output:
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Adding audio output:
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 11:16:02 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully.
Dec 15 11:16:02 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon.
Dec 15 11:16:02 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.956s CPU time.
Dec 15 11:16:02 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully.
Dec 15 11:16:02 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Dec 15 11:16:02 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio
Dec 15 11:16:02 gbvpi-bedroom bluetoothd[763]: Path / reserved for Adv Monitor app :1.106098
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Adding METAVOLUMIO REST API Endpoints
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui
Dec 15 11:16:02 gbvpi-bedroom bluetoothd[763]: Adv Monitor app :1.106098 disconnected from D-Bus
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Preparing CD Folders
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Adding CD REST API Endpoints
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Starting UDEV Watcher for CD
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: Detecting CD presence with UDEV
Dec 15 11:16:02 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices
Dec 15 11:16:02 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Dec 15 11:16:02 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon...
Dec 15 11:16:02 gbvpi-bedroom sudo[22440]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Dec 15 11:16:02 gbvpi-bedroom sudo[22440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Dec 15 11:16:02 gbvpi-bedroom sudo[22440]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:03 gbvpi-bedroom mpd[22445]: 2025-12-15T11:16:03 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Dec 15 11:16:03 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon.
Dec 15 11:16:03 gbvpi-bedroom sudo[22426]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32.
Dec 15 11:16:04 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:05 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:05 gbvpi-bedroom go-librespot[22448]: go-librespot daemon starting...
Dec 15 11:16:05 gbvpi-bedroom go-librespot[22449]: time="2025-12-15T11:16:05-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:16:05 gbvpi-bedroom go-librespot[22449]: time="2025-12-15T11:16:05-05:00" level=debug msg="app state loaded"
Dec 15 11:16:05 gbvpi-bedroom go-librespot[22449]: time="2025-12-15T11:16:05-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:16:05 gbvpi-bedroom go-librespot[22449]: time="2025-12-15T11:16:05-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 15 11:16:05 gbvpi-bedroom go-librespot[22449]: time="2025-12-15T11:16:05-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 15 11:16:05 gbvpi-bedroom go-librespot[22449]: time="2025-12-15T11:16:05-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 15 11:16:05 gbvpi-bedroom go-librespot[22449]: time="2025-12-15T11:16:05-05:00" level=info msg="zeroconf server listening on port 43523"
Dec 15 11:16:05 gbvpi-bedroom go-librespot[22449]: time="2025-12-15T11:16:05-05:00" level=debug msg="obtained new client token: AABSwGySVdBUmO1zRoYcfmD5YVS06/UtUfw0AV0YZ0vaKTwdZEXQTvYmfWEmJMioW/5yHMWXsvkb5bpasCHoYRGsGq8///fND87BcGxx/Wh2VXXbnLpTba1dQVAfmN+xVTDwTV0aqZiwg/V4Rd64nxOST/TC/Q+31DLCDjxK9Xz+S61D6Gbdgy43Wk2UOqUrTQsp9LQNIK1/z/dk2HpLWxZU5rRE0dE4UUt+ggJpH5cy0L4vYWwXKrf3qA=="
Dec 15 11:16:05 gbvpi-bedroom go-librespot[22449]: time="2025-12-15T11:16:05-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:16:05 gbvpi-bedroom go-librespot[22449]: time="2025-12-15T11:16:05-05:00" level=debug msg="completed keyexchange"
Dec 15 11:16:05 gbvpi-bedroom go-librespot[22449]: time="2025-12-15T11:16:05-05:00" level=debug msg="completed challenge"
Dec 15 11:16:05 gbvpi-bedroom go-librespot[22449]: time="2025-12-15T11:16:05-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 15 11:16:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:16:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: warn: [cd-plugin] cdspeedctl: device or media not ready
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Adding inputs REST Endpoints
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Scanning Audio Inputs
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Checking against Known Cards name
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Adding Server instance for streaming
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: error: Hi Res Audio Failed Login: Missing Login Data
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Adding HIGHRESAUDIO REST API Endpoints
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect
Dec 15 11:16:07 gbvpi-bedroom sudo[22474]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Dec 15 11:16:07 gbvpi-bedroom sudo[22474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: QobuzConnect: Starting Qobuz Connect socket and service
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Adding TIDAL REST API Endpoints
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Stopping AccessToken refresher cron for QOBUZ
Dec 15 11:16:07 gbvpi-bedroom sudo[22481]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service
Dec 15 11:16:07 gbvpi-bedroom sudo[22481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 11:16:07 gbvpi-bedroom systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service...
Dec 15 11:16:07 gbvpi-bedroom systemd[1]: vtcs.service: Killing process 21909 (vtcs) with signal SIGKILL.
Dec 15 11:16:07 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully.
Dec 15 11:16:07 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service.
Dec 15 11:16:07 gbvpi-bedroom sudo[22474]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: AccessToken refresher cron started for QOBUZ
Dec 15 11:16:07 gbvpi-bedroom sudo[22481]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Adding QOBUZ REST API Endpoints
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: MRS: Getting audio outputs on start
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: MRS: Requesting all other devices output
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Updating MyVolumio device info
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Updating MyVolumio device info
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 11:16:07 gbvpi-bedroom sudo[22484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service
Dec 15 11:16:07 gbvpi-bedroom sudo[22484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 11:16:07 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service...
Dec 15 11:16:07 gbvpi-bedroom qobuz-connect[21872]: 20251215 11:16:07.804 [21872.21872] INFO SampleApp: Stopping Local configuration server
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Successfully Added MyVolumio device
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Successfully Added MyVolumio device
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: MPD Permissions set
Dec 15 11:16:07 gbvpi-bedroom sudo[22487]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service
Dec 15 11:16:07 gbvpi-bedroom sudo[22487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CorePlayQueue::getTrack 0
Dec 15 11:16:07 gbvpi-bedroom sudo[22487]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CorePlayQueue::getTrack 0
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: error: updateQueue error: null
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioStop
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreStateMachine::stop
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Starting Shairport Sync
Dec 15 11:16:07 gbvpi-bedroom sudo[22503]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service
Dec 15 11:16:07 gbvpi-bedroom sudo[22503]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: MRS: Found cast device: Google-Home-Mini-f209fa314cb426d40a59bcf66354ddc9
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Adding audio output:
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: MRS: Found cast device: SmartTV-4K-fe72c264393a59c76d38e27b8168114d
Dec 15 11:16:07 gbvpi-bedroom volumio[22026]: info: Adding audio output:
Dec 15 11:16:07 gbvpi-bedroom sudo[22505]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 15 11:16:08 gbvpi-bedroom sudo[22505]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 11:16:08 gbvpi-bedroom autossh[21853]: received signal to exit (15)
Dec 15 11:16:08 gbvpi-bedroom systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel...
Dec 15 11:16:08 gbvpi-bedroom systemd[1]: sshtunnel.service: Deactivated successfully.
Dec 15 11:16:08 gbvpi-bedroom systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel.
Dec 15 11:16:08 gbvpi-bedroom systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel.
Dec 15 11:16:08 gbvpi-bedroom sudo[22503]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:08 gbvpi-bedroom volumio[22026]: info: Remote SSH Started
Dec 15 11:16:08 gbvpi-bedroom autossh[22509]: port set to 0, monitoring disabled
Dec 15 11:16:08 gbvpi-bedroom autossh[22509]: starting ssh (count 1)
Dec 15 11:16:08 gbvpi-bedroom autossh[22509]: ssh child pid is 22512
Dec 15 11:16:08 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 15 11:16:08 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 15 11:16:08 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 15 11:16:08 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.623s CPU time.
Dec 15 11:16:08 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 15 11:16:08 gbvpi-bedroom sudo[22505]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:08 gbvpi-bedroom volumio[22026]: info: Successfully Updated MyVolumio device
Dec 15 11:16:08 gbvpi-bedroom volumio[22026]: info: Successfully Updated MyVolumio device
Dec 15 11:16:08 gbvpi-bedroom volumio[22026]: info: Shairport-Sync Started
Dec 15 11:16:08 gbvpi-bedroom volumio[22026]: 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 15 11:16:08 gbvpi-bedroom volumiossh-tunnel[22512]: Warning: Permanently added '[us4.myvolumio.org]:2222' (ED25519) to the list of known hosts.
Dec 15 11:16:08 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:08 gbvpi-bedroom volumio[22026]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status'
Dec 15 11:16:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33.
Dec 15 11:16:08 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:08 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:08 gbvpi-bedroom go-librespot[22528]: go-librespot daemon starting...
Dec 15 11:16:08 gbvpi-bedroom go-librespot[22529]: time="2025-12-15T11:16:08-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:16:08 gbvpi-bedroom go-librespot[22529]: time="2025-12-15T11:16:08-05:00" level=debug msg="app state loaded"
Dec 15 11:16:08 gbvpi-bedroom go-librespot[22529]: time="2025-12-15T11:16:08-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:16:08 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully.
Dec 15 11:16:08 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service.
Dec 15 11:16:08 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service.
Dec 15 11:16:08 gbvpi-bedroom sudo[22484]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:09 gbvpi-bedroom go-librespot[22529]: time="2025-12-15T11:16:09-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 15 11:16:09 gbvpi-bedroom go-librespot[22529]: time="2025-12-15T11:16:09-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 15 11:16:09 gbvpi-bedroom go-librespot[22529]: time="2025-12-15T11:16:09-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 15 11:16:09 gbvpi-bedroom go-librespot[22529]: time="2025-12-15T11:16:09-05:00" level=info msg="zeroconf server listening on port 44841"
Dec 15 11:16:09 gbvpi-bedroom volumio[22026]: info: Executing endpoint qc_getconfig
Dec 15 11:16:09 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig
Dec 15 11:16:09 gbvpi-bedroom qobuz-connect[22536]: 20251215 11:16:09.050 [22536.22536] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket
Dec 15 11:16:09 gbvpi-bedroom volumio[22026]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object]
Dec 15 11:16:09 gbvpi-bedroom volumio[22026]: info: QobuzConnect: QOBUZ Connect daemon connected
Dec 15 11:16:09 gbvpi-bedroom qobuz-connect[22536]: 20251215 11:16:09.054 [22536.22536] INFO VolumeManager: [0x28f588]: Setting new playback volume: 75
Dec 15 11:16:09 gbvpi-bedroom qobuz-connect[22536]: 20251215 11:16:09.054 [22536.22536] INFO VolumeManager: [0x28f588]: Setting new mute state: 0
Dec 15 11:16:09 gbvpi-bedroom qobuz-connect[22536]: 20251215 11:16:09.054 [22536.22536] INFO QobuzConnect: [0x28ff58]: Client initialized!
Dec 15 11:16:09 gbvpi-bedroom qobuz-connect[22536]: 20251215 11:16:09.054 [22536.22536] INFO SampleApp: Starting Avahi advertising, name: GBVPi-Bedroom, service name: _qobuz-connect._tcp
Dec 15 11:16:09 gbvpi-bedroom qobuz-connect[22536]: 20251215 11:16:09.065 [22536.22536] INFO LocalConfigManager: [0x28ee68]: Starting Local Configuration server
Dec 15 11:16:09 gbvpi-bedroom qobuz-connect[22536]: 20251215 11:16:09.065 [22536.22536] INFO SampleApp: Starting Local configuration server
Dec 15 11:16:09 gbvpi-bedroom qobuz-connect[22536]: 20251215 11:16:09.066 [22536.22536] INFO SampleApp: Connected to UNIX socket client 0x279818
Dec 15 11:16:09 gbvpi-bedroom go-librespot[22529]: time="2025-12-15T11:16:09-05:00" level=debug msg="obtained new client token: AAD7ORH6MGUzcgOEZBFbm5OmnvCuCDv3i58u+JWHQuoDkx3A0qs0b2hqvUVI90uM7KtQcbeKjs2wphL4iyRJxgRS+bRdpGi3f+CLtwjxssR9C4w74AQbHkbTJ1SZ+edjv7F8iuBAkZQyw9zNj89ORU1C4sUbGYUca5ys8BkAy4S3HEUkbIfP87Bo6Qxn4UCZ0DrI9az0uGeBIflX3/Ldu7masMsUYyBw9bGa+oelrh2ef/JEC4kp83E="
Dec 15 11:16:09 gbvpi-bedroom go-librespot[22529]: time="2025-12-15T11:16:09-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:16:09 gbvpi-bedroom qobuz-connect[22536]: 20251215 11:16:09.200 [22536.22536] INFO SampleApp: Playback volume changed: 75
Dec 15 11:16:09 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:09 gbvpi-bedroom go-librespot[22529]: time="2025-12-15T11:16:09-05:00" level=debug msg="completed keyexchange"
Dec 15 11:16:09 gbvpi-bedroom go-librespot[22529]: time="2025-12-15T11:16:09-05:00" level=debug msg="completed challenge"
Dec 15 11:16:09 gbvpi-bedroom go-librespot[22529]: time="2025-12-15T11:16:09-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 15 11:16:09 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:16:09 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:16:10 gbvpi-bedroom volumio[22026]: info: TidalConnect service stoped!
Dec 15 11:16:10 gbvpi-bedroom volumio[22026]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect
Dec 15 11:16:10 gbvpi-bedroom volumio[22026]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect
Dec 15 11:16:10 gbvpi-bedroom sudo[22552]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service
Dec 15 11:16:10 gbvpi-bedroom sudo[22552]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 11:16:10 gbvpi-bedroom sudo[22556]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 15 11:16:10 gbvpi-bedroom sudo[22556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 11:16:10 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:10 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:16:10 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service.
Dec 15 11:16:10 gbvpi-bedroom sudo[22552]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:10 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Dec 15 11:16:10 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully.
Dec 15 11:16:10 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Dec 15 11:16:10 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Dec 15 11:16:10 gbvpi-bedroom mpd_monitor.sh[22560]: MPD Monitor Service: Starting MPD Monitor Service
Dec 15 11:16:10 gbvpi-bedroom sudo[22556]: pam_unix(sudo:session): session closed for user root
Dec 15 11:16:10 gbvpi-bedroom volumio[22026]: info: Successfully started MPD Monitor
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: Executing endpoint tc_getconfig
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig
Dec 15 11:16:11 gbvpi-bedroom vtcs[22558]: STARTING TidalConnect services, version: 1.5.2.56
Dec 15 11:16:11 gbvpi-bedroom vtcs[22558]: STARTED TidalConnect services.
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: Executing endpoint tc_connect
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: Connecting to TidalConnect
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::servicePushState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreStateMachine::pushState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioPushState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: MRS: Pushing multiroomSync output update for this device
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: MRS: Pushing multiroomSync output
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CorePlayQueue::getTrack 0
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: 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 15 11:16:11 gbvpi-bedroom volumio[22026]: verbose: CURRENT POSITION 0
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreStateMachine::syncState stateService stop
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreStateMachine::syncState currentStatus stop
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreStateMachine::pushState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioPushState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: MRS: Pushing multiroomSync output update for this device
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: MRS: Pushing multiroomSync output
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: No code
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreStateMachine::pushState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioPushState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: MRS: Pushing multiroomSync output update for this device
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: MRS: Pushing multiroomSync output
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::servicePushState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreStateMachine::pushState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioPushState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: MRS: Pushing multiroomSync output update for this device
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: MRS: Pushing multiroomSync output
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CorePlayQueue::getTrack 0
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: 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 15 11:16:11 gbvpi-bedroom volumio[22026]: verbose: CURRENT POSITION 0
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreStateMachine::syncState stateService stop
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreStateMachine::syncState currentStatus stop
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreStateMachine::pushState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioPushState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: MRS: Pushing multiroomSync output update for this device
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: MRS: Pushing multiroomSync output
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: No code
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreStateMachine::pushState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioPushState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: MRS: Pushing multiroomSync output update for this device
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: MRS: Pushing multiroomSync output
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status'
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status'
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status'
Dec 15 11:16:11 gbvpi-bedroom volumio[22026]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status'
Dec 15 11:16:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34.
Dec 15 11:16:12 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:12 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:12 gbvpi-bedroom go-librespot[22578]: go-librespot daemon starting...
Dec 15 11:16:12 gbvpi-bedroom go-librespot[22579]: time="2025-12-15T11:16:12-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:16:12 gbvpi-bedroom go-librespot[22579]: time="2025-12-15T11:16:12-05:00" level=debug msg="app state loaded"
Dec 15 11:16:12 gbvpi-bedroom go-librespot[22579]: time="2025-12-15T11:16:12-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:16:12 gbvpi-bedroom go-librespot[22579]: time="2025-12-15T11:16:12-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 15 11:16:12 gbvpi-bedroom go-librespot[22579]: time="2025-12-15T11:16:12-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 15 11:16:12 gbvpi-bedroom go-librespot[22579]: time="2025-12-15T11:16:12-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 15 11:16:12 gbvpi-bedroom go-librespot[22579]: time="2025-12-15T11:16:12-05:00" level=info msg="zeroconf server listening on port 41581"
Dec 15 11:16:12 gbvpi-bedroom go-librespot[22579]: time="2025-12-15T11:16:12-05:00" level=debug msg="obtained new client token: AABTE/5wUGX7ZukkPkKjVAHn379sVvNNqZfy0n5qAoWI2bewtDv0kOsIG8fnTlYc7fwJuSF4rEhPKUMxFf8AMgVgbyDSs/YCzb7GT//IFZfgPicgPub2g/FfnGsNc15CPXVlFtCUmAziLqI7GRw7isQnVMhHTiRyGnarVRH5gE89CF5SRW7KXtNtnFMcU0pi5bI4GryuHjIVEPYZZ9n2j9zmhakR3F9JwAFKKWMlPRyuwElJfpWZvaZq+g=="
Dec 15 11:16:12 gbvpi-bedroom go-librespot[22579]: time="2025-12-15T11:16:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:16:12 gbvpi-bedroom go-librespot[22579]: time="2025-12-15T11:16:12-05:00" level=debug msg="completed keyexchange"
Dec 15 11:16:12 gbvpi-bedroom go-librespot[22579]: time="2025-12-15T11:16:12-05:00" level=debug msg="completed challenge"
Dec 15 11:16:13 gbvpi-bedroom go-librespot[22579]: time="2025-12-15T11:16:13-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 15 11:16:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:16:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:16:13 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:13 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:16:13 gbvpi-bedroom volumio[22026]: info: TidalConnect service started!
Dec 15 11:16:13 gbvpi-bedroom volumio[22026]: [Metrics] CommandRouter: 29s 444.79ms
Dec 15 11:16:13 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumiosetStartupVolume
Dec 15 11:16:13 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 11:16:13 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 11:16:13 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::Close All Modals sent
Dec 15 11:16:13 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::Close All Modals sent
Dec 15 11:16:14 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Dec 15 11:16:14 gbvpi-bedroom volumio[22026]: 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 15 11:16:14 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:14 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Dec 15 11:16:14 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Dec 15 11:16:14 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Dec 15 11:16:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35.
Dec 15 11:16:16 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:16 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:16 gbvpi-bedroom go-librespot[22603]: go-librespot daemon starting...
Dec 15 11:16:16 gbvpi-bedroom go-librespot[22604]: time="2025-12-15T11:16:16-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:16:16 gbvpi-bedroom go-librespot[22604]: time="2025-12-15T11:16:16-05:00" level=debug msg="app state loaded"
Dec 15 11:16:16 gbvpi-bedroom go-librespot[22604]: time="2025-12-15T11:16:16-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:16:16 gbvpi-bedroom go-librespot[22604]: time="2025-12-15T11:16:16-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 15 11:16:16 gbvpi-bedroom go-librespot[22604]: time="2025-12-15T11:16:16-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 15 11:16:16 gbvpi-bedroom go-librespot[22604]: time="2025-12-15T11:16:16-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 15 11:16:16 gbvpi-bedroom go-librespot[22604]: time="2025-12-15T11:16:16-05:00" level=info msg="zeroconf server listening on port 40301"
Dec 15 11:16:16 gbvpi-bedroom go-librespot[22604]: time="2025-12-15T11:16:16-05:00" level=debug msg="obtained new client token: AACIx8NPOdXtzmw5KvpmzjAd9JaUmBNju6stRGI3AUs8JvlWdxuExIEdJQJ3dssp91SQW9Ou5QVwpgEuFWV9Nf3pu9kBZEKR8+dh8sB1UcDYUxCadAMi27NWpFcZITvz1qZjO5K1x439CjHFEaHZmxWmKML3NCMVgnS4iv73yJvk8wd1TbeQiVFR+ftwA87HbhZDfk4zeez4Xo5JokD9yqCJdVDzNHzgea+QWS7pJk2I+mmuayI4lhwAkA=="
Dec 15 11:16:16 gbvpi-bedroom go-librespot[22604]: time="2025-12-15T11:16:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:16:16 gbvpi-bedroom go-librespot[22604]: time="2025-12-15T11:16:16-05:00" level=debug msg="completed keyexchange"
Dec 15 11:16:16 gbvpi-bedroom go-librespot[22604]: time="2025-12-15T11:16:16-05:00" level=debug msg="completed challenge"
Dec 15 11:16:16 gbvpi-bedroom go-librespot[22604]: time="2025-12-15T11:16:16-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 15 11:16:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:16:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:16:16 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:16 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:16:17 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:17 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:19 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 15 11:16:19 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 11:16:19 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Dec 15 11:16:19 gbvpi-bedroom volumio-remote-updater[775]: Test mode enabled
Dec 15 11:16:19 gbvpi-bedroom volumio-remote-updater[775]: Alpha mode disabled
Dec 15 11:16:19 gbvpi-bedroom volumio-remote-updater[775]: Alpha legacy test mode disabled
Dec 15 11:16:19 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Dec 15 11:16:19 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 11:16:19 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 11:16:19 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Dec 15 11:16:19 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Dec 15 11:16:19 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Dec 15 11:16:19 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetBrowseSources
Dec 15 11:16:19 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 15 11:16:19 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:19 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:16:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36.
Dec 15 11:16:19 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:20 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:20 gbvpi-bedroom go-librespot[22615]: go-librespot daemon starting...
Dec 15 11:16:20 gbvpi-bedroom go-librespot[22616]: time="2025-12-15T11:16:20-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:16:20 gbvpi-bedroom go-librespot[22616]: time="2025-12-15T11:16:20-05:00" level=debug msg="app state loaded"
Dec 15 11:16:20 gbvpi-bedroom go-librespot[22616]: time="2025-12-15T11:16:20-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:16:20 gbvpi-bedroom go-librespot[22616]: time="2025-12-15T11:16:20-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 15 11:16:20 gbvpi-bedroom go-librespot[22616]: time="2025-12-15T11:16:20-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 15 11:16:20 gbvpi-bedroom go-librespot[22616]: time="2025-12-15T11:16:20-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 15 11:16:20 gbvpi-bedroom go-librespot[22616]: time="2025-12-15T11:16:20-05:00" level=info msg="zeroconf server listening on port 45211"
Dec 15 11:16:20 gbvpi-bedroom go-librespot[22616]: time="2025-12-15T11:16:20-05:00" level=debug msg="obtained new client token: AADnaiIILvh4alP2r22HDuuY9t23juV8zsntH0zqgIXiWlqKiy9Ood+GXm/kfgZklFDfnR0aYvIgAu0ize0VnIOYPHN/AYxeW7Ldov3HVfFymAp3/2qjQK/z9NZfBYBHNxA4uaZO7n9vVhUDCTjuFfU2SrDYrCp9BWTQZkO7HgWij8sYn287CvQTU0VOUhjnMck437Dn3/77DqbCWi6HdM7ndBPNTL7qlasxPPLM3dUgC+4Eq5pLBeqgcQ=="
Dec 15 11:16:20 gbvpi-bedroom go-librespot[22616]: time="2025-12-15T11:16:20-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:16:20 gbvpi-bedroom go-librespot[22616]: time="2025-12-15T11:16:20-05:00" level=debug msg="completed keyexchange"
Dec 15 11:16:20 gbvpi-bedroom go-librespot[22616]: time="2025-12-15T11:16:20-05:00" level=debug msg="completed challenge"
Dec 15 11:16:20 gbvpi-bedroom volumio[22026]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"CAUTION
\n\n- This build may break your network
\n
\nFIX
\n\n- Wireless and network handling
\n
\n","title":"Update v4.080","updateavailable":true}
Dec 15 11:16:20 gbvpi-bedroom go-librespot[22616]: time="2025-12-15T11:16:20-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 15 11:16:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:16:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:16:20 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Dec 15 11:16:20 gbvpi-bedroom volumio[22026]: info: BOOT COMPLETED
Dec 15 11:16:22 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:22 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:16:23 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37.
Dec 15 11:16:23 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:23 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:23 gbvpi-bedroom go-librespot[22623]: go-librespot daemon starting...
Dec 15 11:16:23 gbvpi-bedroom go-librespot[22624]: time="2025-12-15T11:16:23-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:16:23 gbvpi-bedroom go-librespot[22624]: time="2025-12-15T11:16:23-05:00" level=debug msg="app state loaded"
Dec 15 11:16:23 gbvpi-bedroom go-librespot[22624]: time="2025-12-15T11:16:23-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:16:23 gbvpi-bedroom go-librespot[22624]: time="2025-12-15T11:16:23-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 15 11:16:23 gbvpi-bedroom go-librespot[22624]: time="2025-12-15T11:16:23-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 15 11:16:23 gbvpi-bedroom go-librespot[22624]: time="2025-12-15T11:16:23-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 15 11:16:23 gbvpi-bedroom go-librespot[22624]: time="2025-12-15T11:16:23-05:00" level=info msg="zeroconf server listening on port 42029"
Dec 15 11:16:24 gbvpi-bedroom go-librespot[22624]: time="2025-12-15T11:16:24-05:00" level=debug msg="obtained new client token: AACctrHlSKVmlNLWusoM5MC76U3/WVn7woQ5eBD7jgaQPMJLns3pBSqF2qKhthVjAFg5mFFxCQC0XRP0eq2y4ksCASL1VaD9Xr17zSCa6RGDw53bgazlVKX0Rzf6+88hp7g0274c0QXro5+5XNk/n2DpudGt7b45P41MK+Cidn0g8r3hEQ1Pq38LQDY9REBrnC5TiEDOTNgzTEx/gj1H0+VINc9yIwduszd8PbV7M3zn/zIWMW6os1E="
Dec 15 11:16:24 gbvpi-bedroom go-librespot[22624]: time="2025-12-15T11:16:24-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:16:24 gbvpi-bedroom go-librespot[22624]: time="2025-12-15T11:16:24-05:00" level=debug msg="completed keyexchange"
Dec 15 11:16:24 gbvpi-bedroom go-librespot[22624]: time="2025-12-15T11:16:24-05:00" level=debug msg="completed challenge"
Dec 15 11:16:24 gbvpi-bedroom go-librespot[22624]: time="2025-12-15T11:16:24-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 15 11:16:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:16:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:16:25 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:25 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:16:27 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38.
Dec 15 11:16:27 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:27 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:27 gbvpi-bedroom go-librespot[22645]: go-librespot daemon starting...
Dec 15 11:16:27 gbvpi-bedroom go-librespot[22646]: time="2025-12-15T11:16:27-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:16:27 gbvpi-bedroom go-librespot[22646]: time="2025-12-15T11:16:27-05:00" level=debug msg="app state loaded"
Dec 15 11:16:27 gbvpi-bedroom go-librespot[22646]: time="2025-12-15T11:16:27-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:16:27 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:27 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:27 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:16:27 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:16:27 gbvpi-bedroom go-librespot[22646]: time="2025-12-15T11:16:27-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 15 11:16:27 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:16:27 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:16:27 gbvpi-bedroom go-librespot[22646]: time="2025-12-15T11:16:27-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 15 11:16:27 gbvpi-bedroom go-librespot[22646]: time="2025-12-15T11:16:27-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 15 11:16:27 gbvpi-bedroom go-librespot[22646]: time="2025-12-15T11:16:27-05:00" level=info msg="zeroconf server listening on port 46861"
Dec 15 11:16:27 gbvpi-bedroom go-librespot[22646]: time="2025-12-15T11:16:27-05:00" level=debug msg="obtained new client token: AADn7yJhgFLtANqRNBYU3i4FySOClXpotGziB1NDCfsnE7XdRc9EnDHA0dIUPXNCKWD9YKQa8obvfISwBAmLFUhmi39N59cuBNt3FkgNeJXuokFMpbfACLsaShwvXa8G4bGaIBA8sSZnmyq7XSlaaL6xGhjw/N27YUJR48d3BmgRqCQVSt0e4u/VJPzC+VKkh+0upguSzhHD+lC2x2xNE+Hx2KBYVieSic/iAbFoFwcb3FSRuGkDsVwo9Q=="
Dec 15 11:16:27 gbvpi-bedroom go-librespot[22646]: time="2025-12-15T11:16:27-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:16:27 gbvpi-bedroom go-librespot[22646]: time="2025-12-15T11:16:27-05:00" level=debug msg="completed keyexchange"
Dec 15 11:16:27 gbvpi-bedroom go-librespot[22646]: time="2025-12-15T11:16:27-05:00" level=debug msg="completed challenge"
Dec 15 11:16:28 gbvpi-bedroom go-librespot[22646]: time="2025-12-15T11:16:28-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 15 11:16:28 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:16:28 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:16:28 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:28 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:16:31 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39.
Dec 15 11:16:31 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:31 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:31 gbvpi-bedroom go-librespot[22657]: go-librespot daemon starting...
Dec 15 11:16:31 gbvpi-bedroom go-librespot[22658]: time="2025-12-15T11:16:31-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:16:31 gbvpi-bedroom go-librespot[22658]: time="2025-12-15T11:16:31-05:00" level=debug msg="app state loaded"
Dec 15 11:16:31 gbvpi-bedroom go-librespot[22658]: time="2025-12-15T11:16:31-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:16:31 gbvpi-bedroom go-librespot[22658]: time="2025-12-15T11:16:31-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 15 11:16:31 gbvpi-bedroom go-librespot[22658]: time="2025-12-15T11:16:31-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 15 11:16:31 gbvpi-bedroom go-librespot[22658]: time="2025-12-15T11:16:31-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 15 11:16:31 gbvpi-bedroom go-librespot[22658]: time="2025-12-15T11:16:31-05:00" level=info msg="zeroconf server listening on port 45213"
Dec 15 11:16:31 gbvpi-bedroom go-librespot[22658]: time="2025-12-15T11:16:31-05:00" level=debug msg="obtained new client token: AACVjbJtNqziYBL3xN1wPgxgvkxAnOp9Du4+GZE81lmY3lpM5lGDrmhM21Uakkx3Rodsq/LvEdgcIjlPAWfRs6E/oJI7i1vk3tpS0/GT6NOqOP7JHc9WReW2jb0iTtv5uPFHAjL9tPQiVK9sXpr7GFcx93sNn9zyOdrAKK6VqMQ3+B4QPIQM0xGuswhXZ5Q4NY5Qn9pILUvdYisZJpViJ6RyevnNF99mt47e+99Lo/VdH/goHyUc31pNjg=="
Dec 15 11:16:31 gbvpi-bedroom go-librespot[22658]: time="2025-12-15T11:16:31-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:16:31 gbvpi-bedroom go-librespot[22658]: time="2025-12-15T11:16:31-05:00" level=debug msg="completed keyexchange"
Dec 15 11:16:31 gbvpi-bedroom go-librespot[22658]: time="2025-12-15T11:16:31-05:00" level=debug msg="completed challenge"
Dec 15 11:16:31 gbvpi-bedroom go-librespot[22658]: time="2025-12-15T11:16:31-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 15 11:16:31 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:16:31 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:16:31 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:31 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:16:34 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:34 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:16:34 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40.
Dec 15 11:16:34 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:35 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:35 gbvpi-bedroom go-librespot[22665]: go-librespot daemon starting...
Dec 15 11:16:35 gbvpi-bedroom go-librespot[22666]: time="2025-12-15T11:16:35-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:16:35 gbvpi-bedroom go-librespot[22666]: time="2025-12-15T11:16:35-05:00" level=debug msg="app state loaded"
Dec 15 11:16:35 gbvpi-bedroom go-librespot[22666]: time="2025-12-15T11:16:35-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:16:35 gbvpi-bedroom go-librespot[22666]: time="2025-12-15T11:16:35-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 15 11:16:35 gbvpi-bedroom go-librespot[22666]: time="2025-12-15T11:16:35-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 15 11:16:35 gbvpi-bedroom go-librespot[22666]: time="2025-12-15T11:16:35-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 15 11:16:35 gbvpi-bedroom go-librespot[22666]: time="2025-12-15T11:16:35-05:00" level=info msg="zeroconf server listening on port 37659"
Dec 15 11:16:35 gbvpi-bedroom go-librespot[22666]: time="2025-12-15T11:16:35-05:00" level=debug msg="obtained new client token: AACHVHXLe8+S8NQrFPmDK8h3bK5xbxUIS1by7z3QCd9b1T2db6/InJV0bcAQ+IanfnhurVVz8r/xlOOIFxKbMDEsCBkwSmJf4z02Gz/UBG3w46tVRscengrB2Wp3qUSz2QqTlgKKgVyd1BMNDczcDnAIkh7FP8iyY6P/hMCGBWFajrh8dCsDN0ZwGZrqbCNFAaorTzFvx0WmMhSWHtikg9y/chX8HIZTuSaDhrzw91EmSX3ep3X+Ufojjg=="
Dec 15 11:16:35 gbvpi-bedroom go-librespot[22666]: time="2025-12-15T11:16:35-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:16:35 gbvpi-bedroom go-librespot[22666]: time="2025-12-15T11:16:35-05:00" level=debug msg="completed keyexchange"
Dec 15 11:16:35 gbvpi-bedroom go-librespot[22666]: time="2025-12-15T11:16:35-05:00" level=debug msg="completed challenge"
Dec 15 11:16:35 gbvpi-bedroom go-librespot[22666]: time="2025-12-15T11:16:35-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 15 11:16:35 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:16:35 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:16:37 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:37 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:37 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:37 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:16:38 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41.
Dec 15 11:16:38 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:38 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:38 gbvpi-bedroom go-librespot[22687]: go-librespot daemon starting...
Dec 15 11:16:38 gbvpi-bedroom go-librespot[22688]: time="2025-12-15T11:16:38-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:16:38 gbvpi-bedroom go-librespot[22688]: time="2025-12-15T11:16:38-05:00" level=debug msg="app state loaded"
Dec 15 11:16:38 gbvpi-bedroom go-librespot[22688]: time="2025-12-15T11:16:38-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:16:38 gbvpi-bedroom go-librespot[22688]: time="2025-12-15T11:16:38-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 15 11:16:38 gbvpi-bedroom go-librespot[22688]: time="2025-12-15T11:16:38-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 15 11:16:38 gbvpi-bedroom go-librespot[22688]: time="2025-12-15T11:16:38-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 15 11:16:38 gbvpi-bedroom go-librespot[22688]: time="2025-12-15T11:16:38-05:00" level=info msg="zeroconf server listening on port 37455"
Dec 15 11:16:39 gbvpi-bedroom go-librespot[22688]: time="2025-12-15T11:16:39-05:00" level=debug msg="obtained new client token: AADeplUxWp/7HgMOS1P6cbgtXSwKtgZOIGFbVQ2Zf0d1IR+zJf5qjTEIuAVhoErKw4FJa8/XTtaWmGwNxj207nsowiOuP2KmRO8QNJBRJ7l2n7OjRR5a2gc/0fhosCWpA7oozpX3wAYB1jPi5lPRw9h8kquFTj38C3weRLbSjUZbGnEkTWOQSAwU81QTkaKNuOQPEDnQYhqcYIIlkK30TnPIYeP1FvfRdVqeEXiPyEYr6JHfNPrHonA="
Dec 15 11:16:39 gbvpi-bedroom go-librespot[22688]: time="2025-12-15T11:16:39-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:16:39 gbvpi-bedroom go-librespot[22688]: time="2025-12-15T11:16:39-05:00" level=debug msg="completed keyexchange"
Dec 15 11:16:39 gbvpi-bedroom go-librespot[22688]: time="2025-12-15T11:16:39-05:00" level=debug msg="completed challenge"
Dec 15 11:16:39 gbvpi-bedroom go-librespot[22688]: time="2025-12-15T11:16:39-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 15 11:16:39 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:16:39 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:16:40 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:40 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:16:42 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42.
Dec 15 11:16:42 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:42 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:42 gbvpi-bedroom go-librespot[22695]: go-librespot daemon starting...
Dec 15 11:16:42 gbvpi-bedroom go-librespot[22696]: time="2025-12-15T11:16:42-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:16:42 gbvpi-bedroom go-librespot[22696]: time="2025-12-15T11:16:42-05:00" level=debug msg="app state loaded"
Dec 15 11:16:42 gbvpi-bedroom go-librespot[22696]: time="2025-12-15T11:16:42-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:16:42 gbvpi-bedroom go-librespot[22696]: time="2025-12-15T11:16:42-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 15 11:16:42 gbvpi-bedroom go-librespot[22696]: time="2025-12-15T11:16:42-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 15 11:16:42 gbvpi-bedroom go-librespot[22696]: time="2025-12-15T11:16:42-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 15 11:16:42 gbvpi-bedroom go-librespot[22696]: time="2025-12-15T11:16:42-05:00" level=info msg="zeroconf server listening on port 41771"
Dec 15 11:16:42 gbvpi-bedroom go-librespot[22696]: time="2025-12-15T11:16:42-05:00" level=debug msg="obtained new client token: AAAY0Napi2xwRn5LmF+7jOZ7Z542JSHN0zYbFFfyn7wVVIwsOQbbI7fROeEQT402DRidcJ3lIZwwKrrDV9MTbKTkBsToSB1+lqnr1XqjzuqRHDk1pfllgssRUG9Mz87OCOPCxfIPbnAdUGV8y/ZXaQWACaiX7VGFeqsZz+AkvF+93r7QlSJAoI/L29fQW4Wr5k38iU4GX4szNWwDUDEI3FognTPfk5T68Qy74hHcQDvzyqna/Hm/Lf02Lw=="
Dec 15 11:16:42 gbvpi-bedroom go-librespot[22696]: time="2025-12-15T11:16:42-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:16:42 gbvpi-bedroom go-librespot[22696]: time="2025-12-15T11:16:42-05:00" level=debug msg="completed keyexchange"
Dec 15 11:16:42 gbvpi-bedroom go-librespot[22696]: time="2025-12-15T11:16:42-05:00" level=debug msg="completed challenge"
Dec 15 11:16:42 gbvpi-bedroom go-librespot[22696]: time="2025-12-15T11:16:42-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 15 11:16:42 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:16:42 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:16:43 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:43 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:16:46 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43.
Dec 15 11:16:46 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:46 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:46 gbvpi-bedroom go-librespot[22717]: go-librespot daemon starting...
Dec 15 11:16:46 gbvpi-bedroom systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service...
Dec 15 11:16:46 gbvpi-bedroom go-librespot[22718]: time="2025-12-15T11:16:46-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:16:46 gbvpi-bedroom go-librespot[22718]: time="2025-12-15T11:16:46-05:00" level=debug msg="app state loaded"
Dec 15 11:16:46 gbvpi-bedroom go-librespot[22718]: time="2025-12-15T11:16:46-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:16:46 gbvpi-bedroom go-librespot[22718]: time="2025-12-15T11:16:46-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 15 11:16:46 gbvpi-bedroom go-librespot[22718]: time="2025-12-15T11:16:46-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 15 11:16:46 gbvpi-bedroom go-librespot[22718]: time="2025-12-15T11:16:46-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 15 11:16:46 gbvpi-bedroom go-librespot[22718]: time="2025-12-15T11:16:46-05:00" level=info msg="zeroconf server listening on port 38815"
Dec 15 11:16:46 gbvpi-bedroom go-librespot[22718]: time="2025-12-15T11:16:46-05:00" level=debug msg="obtained new client token: AADRWSMh+zW1ICIWb+7vhole6z3eCgey5rpVwFYbad+F5352Lz+Al7LElh1T2XNGVBf8q5jfXRC1AbVIJy3ogTPJn8eKmWdrP1M5SuS3SU1XNVzDBlphBxmYMNzP4mU6NeOttfxTlJ0QzVUhI4kGt20DPNiKFnqCNhQOux6cYdJZPPwy3P1Mie0mpEVnJkXU5d+ck/qO6QHrkoId/5KalrBHADl/kdT9oQJhzTStVEdSrTLG4EyHDTC+Ww=="
Dec 15 11:16:46 gbvpi-bedroom go-librespot[22718]: time="2025-12-15T11:16:46-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:16:46 gbvpi-bedroom go-librespot[22718]: time="2025-12-15T11:16:46-05:00" level=debug msg="completed keyexchange"
Dec 15 11:16:46 gbvpi-bedroom go-librespot[22718]: time="2025-12-15T11:16:46-05:00" level=debug msg="completed challenge"
Dec 15 11:16:46 gbvpi-bedroom systemd[1]: setdatetime-helper.service: Deactivated successfully.
Dec 15 11:16:46 gbvpi-bedroom systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service.
Dec 15 11:16:46 gbvpi-bedroom go-librespot[22718]: time="2025-12-15T11:16:46-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 15 11:16:46 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:16:46 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:16:46 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:46 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:16:47 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:47 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:47 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:16:47 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:16:47 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:16:47 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:16:49 gbvpi-bedroom volumio[22026]: info: UPDATER: Scheduling automatic update
Dec 15 11:16:49 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStartTime
Dec 15 11:16:49 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStopTime
Dec 15 11:16:49 gbvpi-bedroom volumio[22026]: info: UPDATER: Auto update will take place at: Tue Dec 16 2025 05:50:55 GMT-0500 (Eastern Standard Time)
Dec 15 11:16:49 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:49 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:16:49 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44.
Dec 15 11:16:49 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:50 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:50 gbvpi-bedroom go-librespot[22752]: go-librespot daemon starting...
Dec 15 11:16:50 gbvpi-bedroom go-librespot[22753]: time="2025-12-15T11:16:50-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:16:50 gbvpi-bedroom go-librespot[22753]: time="2025-12-15T11:16:50-05:00" level=debug msg="app state loaded"
Dec 15 11:16:50 gbvpi-bedroom go-librespot[22753]: time="2025-12-15T11:16:50-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:16:50 gbvpi-bedroom go-librespot[22753]: time="2025-12-15T11:16:50-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 15 11:16:50 gbvpi-bedroom go-librespot[22753]: time="2025-12-15T11:16:50-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 15 11:16:50 gbvpi-bedroom go-librespot[22753]: time="2025-12-15T11:16:50-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 15 11:16:50 gbvpi-bedroom go-librespot[22753]: time="2025-12-15T11:16:50-05:00" level=info msg="zeroconf server listening on port 41935"
Dec 15 11:16:50 gbvpi-bedroom go-librespot[22753]: time="2025-12-15T11:16:50-05:00" level=debug msg="obtained new client token: AACU2cZatT4DAOscMp/jKafy912GVMOptUxsYZvsD9Z0c7EgV3oWhxwF2nde/3CFFneu1ytoTCq5MlCQAiWCUFw1DN5AYeaimNuOik/DhS2mjoU7oQi5Ag15i36UBwwIHM6udi86Yw/LjGKvg37tfAVxxlWX+nmgesLb1ZvqRdo0HYvz25xMSBbop3JskRYN1zAr7Kxpav1N93reSxvh8W+Z82kS+pw+fEVMm7F0Kdi0UJjiuyyXyiw48Q=="
Dec 15 11:16:50 gbvpi-bedroom go-librespot[22753]: time="2025-12-15T11:16:50-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:16:50 gbvpi-bedroom go-librespot[22753]: time="2025-12-15T11:16:50-05:00" level=debug msg="completed keyexchange"
Dec 15 11:16:50 gbvpi-bedroom go-librespot[22753]: time="2025-12-15T11:16:50-05:00" level=debug msg="completed challenge"
Dec 15 11:16:50 gbvpi-bedroom go-librespot[22753]: time="2025-12-15T11:16:50-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 15 11:16:50 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:16:50 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:16:52 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:52 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:16:53 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45.
Dec 15 11:16:53 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:53 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:53 gbvpi-bedroom go-librespot[22763]: go-librespot daemon starting...
Dec 15 11:16:53 gbvpi-bedroom go-librespot[22764]: time="2025-12-15T11:16:53-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:16:53 gbvpi-bedroom go-librespot[22764]: time="2025-12-15T11:16:53-05:00" level=debug msg="app state loaded"
Dec 15 11:16:53 gbvpi-bedroom go-librespot[22764]: time="2025-12-15T11:16:53-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:16:53 gbvpi-bedroom go-librespot[22764]: time="2025-12-15T11:16:53-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 15 11:16:53 gbvpi-bedroom go-librespot[22764]: time="2025-12-15T11:16:53-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 15 11:16:53 gbvpi-bedroom go-librespot[22764]: time="2025-12-15T11:16:53-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 15 11:16:53 gbvpi-bedroom go-librespot[22764]: time="2025-12-15T11:16:53-05:00" level=info msg="zeroconf server listening on port 33919"
Dec 15 11:16:54 gbvpi-bedroom go-librespot[22764]: time="2025-12-15T11:16:54-05:00" level=debug msg="obtained new client token: AADel4/EmvuRu2c/L4uGLOxHDubRYOVaeoMQh3J5dQVK3TgOpvcdnJaINNm2yzmNrEkP4OmvJyYRUmmtarH/37z0Q/1DMTqOsZn2RK6/HYdWIN/IwDPIUQnx6rhnhLv4tr57e6w6CEuaO9Xfnl2nG9mDoETSU9jnWRn6SQeT/2WNvKULsfH0ooOq/0R1DDV/n9JVLGFKLr0FDq4Qc04d4gaYvFIyefvI1sTq363zCFWF+iBdYbU9y5s="
Dec 15 11:16:54 gbvpi-bedroom go-librespot[22764]: time="2025-12-15T11:16:54-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:16:54 gbvpi-bedroom go-librespot[22764]: time="2025-12-15T11:16:54-05:00" level=debug msg="completed keyexchange"
Dec 15 11:16:54 gbvpi-bedroom go-librespot[22764]: time="2025-12-15T11:16:54-05:00" level=debug msg="completed challenge"
Dec 15 11:16:54 gbvpi-bedroom go-librespot[22764]: time="2025-12-15T11:16:54-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 15 11:16:54 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:16:54 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:16:55 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:55 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:16:57 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46.
Dec 15 11:16:57 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:57 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:16:57 gbvpi-bedroom go-librespot[22785]: go-librespot daemon starting...
Dec 15 11:16:57 gbvpi-bedroom go-librespot[22786]: time="2025-12-15T11:16:57-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:16:57 gbvpi-bedroom go-librespot[22786]: time="2025-12-15T11:16:57-05:00" level=debug msg="app state loaded"
Dec 15 11:16:57 gbvpi-bedroom go-librespot[22786]: time="2025-12-15T11:16:57-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:16:57 gbvpi-bedroom go-librespot[22786]: time="2025-12-15T11:16:57-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 15 11:16:57 gbvpi-bedroom go-librespot[22786]: time="2025-12-15T11:16:57-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 15 11:16:57 gbvpi-bedroom go-librespot[22786]: time="2025-12-15T11:16:57-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 15 11:16:57 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:57 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:16:57 gbvpi-bedroom go-librespot[22786]: time="2025-12-15T11:16:57-05:00" level=info msg="zeroconf server listening on port 45769"
Dec 15 11:16:57 gbvpi-bedroom go-librespot[22786]: time="2025-12-15T11:16:57-05:00" level=debug msg="obtained new client token: AABxYK1MwMXZBsx5/Altw+EZNDBbaBJ/VzAAZlVQGGF4ZUrdMLBClIgb5QDUCD0xVjJftuiGDwl8lxi0oPWQFkKwhHNlXyVBL9LYnO9sUlF65BKNga29oUGJRza/J7kelRC9rU5uJM83nD8E7uCxP3pY1M9cfVfzL56xVBWLtccxqjCq2XayJI+Czl1c+6FOyRpBPg44f41pmvKhZEDvUylAqRMWOzp0LKi26BVnr5+3vSCQAXXZU2i7bQ=="
Dec 15 11:16:57 gbvpi-bedroom go-librespot[22786]: time="2025-12-15T11:16:57-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:16:57 gbvpi-bedroom go-librespot[22786]: time="2025-12-15T11:16:57-05:00" level=debug msg="completed keyexchange"
Dec 15 11:16:57 gbvpi-bedroom go-librespot[22786]: time="2025-12-15T11:16:57-05:00" level=debug msg="completed challenge"
Dec 15 11:16:58 gbvpi-bedroom go-librespot[22786]: time="2025-12-15T11:16:58-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 15 11:16:58 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:16:58 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:16:58 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:16:58 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:17:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47.
Dec 15 11:17:01 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:01 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:01 gbvpi-bedroom go-librespot[22793]: go-librespot daemon starting...
Dec 15 11:17:01 gbvpi-bedroom go-librespot[22794]: time="2025-12-15T11:17:01-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:17:01 gbvpi-bedroom go-librespot[22794]: time="2025-12-15T11:17:01-05:00" level=debug msg="app state loaded"
Dec 15 11:17:01 gbvpi-bedroom go-librespot[22794]: time="2025-12-15T11:17:01-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:17:01 gbvpi-bedroom go-librespot[22794]: time="2025-12-15T11:17:01-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 15 11:17:01 gbvpi-bedroom go-librespot[22794]: time="2025-12-15T11:17:01-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 15 11:17:01 gbvpi-bedroom go-librespot[22794]: time="2025-12-15T11:17:01-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 15 11:17:01 gbvpi-bedroom go-librespot[22794]: time="2025-12-15T11:17:01-05:00" level=info msg="zeroconf server listening on port 42025"
Dec 15 11:17:01 gbvpi-bedroom go-librespot[22794]: time="2025-12-15T11:17:01-05:00" level=debug msg="obtained new client token: AABDQKAYR8crcUUYTCD2nAru6vVPOuIXtlUbXgzqAqUE0rIkQmKIa/vjuXVMD0DaUHGo2aABaZ7Z2Y0rmBYbHs8mt4KsIsWwThqEi4msMs7UhcaUbexLodkQuHtO2iyqgK8pvVuG3C7jKctB9fJB5793+943AL1QX+lie5/49JtOgjMrULl4WxZwH8VT5NNvojtLC8f2OZ0WoMfbSunKGT2KYo/cVyDTGQSaZQGT5vs+X4tnZGCB35ta+g=="
Dec 15 11:17:01 gbvpi-bedroom go-librespot[22794]: time="2025-12-15T11:17:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:17:01 gbvpi-bedroom go-librespot[22794]: time="2025-12-15T11:17:01-05:00" level=debug msg="completed keyexchange"
Dec 15 11:17:01 gbvpi-bedroom go-librespot[22794]: time="2025-12-15T11:17:01-05:00" level=debug msg="completed challenge"
Dec 15 11:17:01 gbvpi-bedroom go-librespot[22794]: time="2025-12-15T11:17:01-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 15 11:17:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:17:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:17:01 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:17:01 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:17:04 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:17:04 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:17:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48.
Dec 15 11:17:04 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:05 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:05 gbvpi-bedroom go-librespot[22801]: go-librespot daemon starting...
Dec 15 11:17:05 gbvpi-bedroom go-librespot[22802]: time="2025-12-15T11:17:05-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:17:05 gbvpi-bedroom go-librespot[22802]: time="2025-12-15T11:17:05-05:00" level=debug msg="app state loaded"
Dec 15 11:17:05 gbvpi-bedroom go-librespot[22802]: time="2025-12-15T11:17:05-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:17:05 gbvpi-bedroom go-librespot[22802]: time="2025-12-15T11:17:05-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 15 11:17:05 gbvpi-bedroom go-librespot[22802]: time="2025-12-15T11:17:05-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 15 11:17:05 gbvpi-bedroom go-librespot[22802]: time="2025-12-15T11:17:05-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 15 11:17:05 gbvpi-bedroom go-librespot[22802]: time="2025-12-15T11:17:05-05:00" level=info msg="zeroconf server listening on port 35047"
Dec 15 11:17:05 gbvpi-bedroom go-librespot[22802]: time="2025-12-15T11:17:05-05:00" level=debug msg="obtained new client token: AAC9WVrJ/OxlI7jQVOP3NEckDEptzX8aFKSYGT7gc4j60lDxNPvW6+gQNg7k1680j/kWXpNfkiA8zdRqoyRHQWsGpKcsmSrdLm4iyzg/LpNfVlVUBHqVxUc1pGRZgXSte9hVyrO7zqw6IJzGicqgiSVMwbBpm0LrLdyiOzpX95m5jxJ8h7rb7p3zYZty+8s3os8FOqDFx/0XNi+u41crnOnTBpRAjuqg0XLpXP7KLegTUWbn0RysM8TwvQ=="
Dec 15 11:17:05 gbvpi-bedroom go-librespot[22802]: time="2025-12-15T11:17:05-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:17:05 gbvpi-bedroom go-librespot[22802]: time="2025-12-15T11:17:05-05:00" level=debug msg="completed keyexchange"
Dec 15 11:17:05 gbvpi-bedroom go-librespot[22802]: time="2025-12-15T11:17:05-05:00" level=debug msg="completed challenge"
Dec 15 11:17:05 gbvpi-bedroom go-librespot[22802]: time="2025-12-15T11:17:05-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 15 11:17:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:17:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:17:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:17:07 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:17:07 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:17:07 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:17:07 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:17:07 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:17:07 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:17:07 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:17:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49.
Dec 15 11:17:08 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:08 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:08 gbvpi-bedroom go-librespot[22823]: go-librespot daemon starting...
Dec 15 11:17:08 gbvpi-bedroom go-librespot[22824]: time="2025-12-15T11:17:08-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:17:08 gbvpi-bedroom go-librespot[22824]: time="2025-12-15T11:17:08-05:00" level=debug msg="app state loaded"
Dec 15 11:17:08 gbvpi-bedroom go-librespot[22824]: time="2025-12-15T11:17:08-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:17:08 gbvpi-bedroom go-librespot[22824]: time="2025-12-15T11:17:08-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 15 11:17:08 gbvpi-bedroom go-librespot[22824]: time="2025-12-15T11:17:08-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 15 11:17:08 gbvpi-bedroom go-librespot[22824]: time="2025-12-15T11:17:08-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 15 11:17:08 gbvpi-bedroom go-librespot[22824]: time="2025-12-15T11:17:08-05:00" level=info msg="zeroconf server listening on port 46015"
Dec 15 11:17:09 gbvpi-bedroom go-librespot[22824]: time="2025-12-15T11:17:09-05:00" level=debug msg="obtained new client token: AAD04pjH319htCchrtGQ4pEXeRtslJqtoYIOrF+ApEbb7swG5aerv3oi7AAEccEgauPdrKB0wcCY9f6sip8eH0J5VK5jLifEGYb7fb9Wa7W8GrtLDMLzWjC4sLDjK1FS4hb1SbESF2HKS2RxyLnTz9uOx7D5ToKd6OXh2RzRoSI4bHgiw4DBEbqIlgvZDHM/dPcdk9g7Y5v3BA/VhUHGAOYyRntbtoGO5nzfYvcCBv9nR7oLLgOVWT0="
Dec 15 11:17:09 gbvpi-bedroom go-librespot[22824]: time="2025-12-15T11:17:09-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:17:09 gbvpi-bedroom go-librespot[22824]: time="2025-12-15T11:17:09-05:00" level=debug msg="completed keyexchange"
Dec 15 11:17:09 gbvpi-bedroom go-librespot[22824]: time="2025-12-15T11:17:09-05:00" level=debug msg="completed challenge"
Dec 15 11:17:09 gbvpi-bedroom go-librespot[22824]: time="2025-12-15T11:17:09-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 15 11:17:09 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:17:09 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:17:10 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:17:10 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:17:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50.
Dec 15 11:17:12 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:12 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:12 gbvpi-bedroom go-librespot[22835]: go-librespot daemon starting...
Dec 15 11:17:12 gbvpi-bedroom go-librespot[22836]: time="2025-12-15T11:17:12-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:17:12 gbvpi-bedroom go-librespot[22836]: time="2025-12-15T11:17:12-05:00" level=debug msg="app state loaded"
Dec 15 11:17:12 gbvpi-bedroom go-librespot[22836]: time="2025-12-15T11:17:12-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:17:12 gbvpi-bedroom go-librespot[22836]: time="2025-12-15T11:17:12-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 15 11:17:12 gbvpi-bedroom go-librespot[22836]: time="2025-12-15T11:17:12-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 15 11:17:12 gbvpi-bedroom go-librespot[22836]: time="2025-12-15T11:17:12-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 15 11:17:12 gbvpi-bedroom go-librespot[22836]: time="2025-12-15T11:17:12-05:00" level=info msg="zeroconf server listening on port 33081"
Dec 15 11:17:12 gbvpi-bedroom go-librespot[22836]: time="2025-12-15T11:17:12-05:00" level=debug msg="obtained new client token: AACcPErbBnd6ISyxTNkOiWUPI1p2QMNFzj4IIlZF1FXbixC7OvQL2sVA9Eb6ShP9jDXDUEzyjhNkGKzGMyue7PMg4EyulQm+9fT+Pl4DevYSH0yWXTjBv7EHDcGDiO9jMoXZvV3mzbhOBcGx7nL1vt/QeF++l4pZW8+WccOUsIAfw0P8GUq7njGHJSqQc2QK1L5fwl+2K64H5C1hy6hFLnuj41rdfWm4iFVtF5K3vPxedyOa+DPK7iDY6Q=="
Dec 15 11:17:12 gbvpi-bedroom go-librespot[22836]: time="2025-12-15T11:17:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:17:12 gbvpi-bedroom go-librespot[22836]: time="2025-12-15T11:17:12-05:00" level=debug msg="completed keyexchange"
Dec 15 11:17:12 gbvpi-bedroom go-librespot[22836]: time="2025-12-15T11:17:12-05:00" level=debug msg="completed challenge"
Dec 15 11:17:13 gbvpi-bedroom go-librespot[22836]: time="2025-12-15T11:17:13-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 15 11:17:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:17:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:17:13 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:17:13 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:17:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51.
Dec 15 11:17:16 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:16 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:16 gbvpi-bedroom go-librespot[22858]: go-librespot daemon starting...
Dec 15 11:17:16 gbvpi-bedroom go-librespot[22859]: time="2025-12-15T11:17:16-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:17:16 gbvpi-bedroom go-librespot[22859]: time="2025-12-15T11:17:16-05:00" level=debug msg="app state loaded"
Dec 15 11:17:16 gbvpi-bedroom go-librespot[22859]: time="2025-12-15T11:17:16-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:17:16 gbvpi-bedroom go-librespot[22859]: time="2025-12-15T11:17:16-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 15 11:17:16 gbvpi-bedroom go-librespot[22859]: time="2025-12-15T11:17:16-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 15 11:17:16 gbvpi-bedroom go-librespot[22859]: time="2025-12-15T11:17:16-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 15 11:17:16 gbvpi-bedroom go-librespot[22859]: time="2025-12-15T11:17:16-05:00" level=info msg="zeroconf server listening on port 41919"
Dec 15 11:17:16 gbvpi-bedroom go-librespot[22859]: time="2025-12-15T11:17:16-05:00" level=debug msg="obtained new client token: AADo0MWe/R8Udsixv47j82cLbThfezAQT6apdMX1Q0WGIOVmkOWEUCoOkNIMjXL6Tu+v2Fj1pdXhTpA84QHyWbXkit3PDYyeY7mY1YVEsIB/Ne7p0IgLMYA519EBwBW/4vB61PZYnYpolagNBkt+Rbtblfi8D8lZAJz9+XomHeUfF1fsNeaKKtNu0s75gsvRdc8axhlkFZGbOL5U7O6BdRxBzjP5Yx6NK2naEUY842IFeF61WZcrCPi3gA=="
Dec 15 11:17:16 gbvpi-bedroom go-librespot[22859]: time="2025-12-15T11:17:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:17:16 gbvpi-bedroom go-librespot[22859]: time="2025-12-15T11:17:16-05:00" level=debug msg="completed keyexchange"
Dec 15 11:17:16 gbvpi-bedroom go-librespot[22859]: time="2025-12-15T11:17:16-05:00" level=debug msg="completed challenge"
Dec 15 11:17:16 gbvpi-bedroom go-librespot[22859]: time="2025-12-15T11:17:16-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 15 11:17:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:17:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:17:16 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:17:16 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:17:17 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:17:17 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:17:19 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:17:19 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:17:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52.
Dec 15 11:17:19 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:20 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:20 gbvpi-bedroom go-librespot[22866]: go-librespot daemon starting...
Dec 15 11:17:20 gbvpi-bedroom go-librespot[22867]: time="2025-12-15T11:17:20-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:17:20 gbvpi-bedroom go-librespot[22867]: time="2025-12-15T11:17:20-05:00" level=debug msg="app state loaded"
Dec 15 11:17:20 gbvpi-bedroom go-librespot[22867]: time="2025-12-15T11:17:20-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:17:20 gbvpi-bedroom go-librespot[22867]: time="2025-12-15T11:17:20-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 15 11:17:20 gbvpi-bedroom go-librespot[22867]: time="2025-12-15T11:17:20-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 15 11:17:20 gbvpi-bedroom go-librespot[22867]: time="2025-12-15T11:17:20-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 15 11:17:20 gbvpi-bedroom go-librespot[22867]: time="2025-12-15T11:17:20-05:00" level=info msg="zeroconf server listening on port 40367"
Dec 15 11:17:20 gbvpi-bedroom go-librespot[22867]: time="2025-12-15T11:17:20-05:00" level=debug msg="obtained new client token: AADYxvJZD2WdS8TCaz+E8JP7wp5zOi8SeacSlhrORffTCuGfrU0aW13YYtF2fGFPql88KF5RPCzJmONy5H7c9qyIIAm+g67BeD0qhInVNS3h3ynhJVVWfxWSa6RXwX0jAA0YaxzWIquSbDHSVvNeAFsRH2DI73WTYRr18scwpabLxj5sssWhWKoEaxjgqpCOnAwwf+VdtGkuMHSTFY4vZxJYiprwiNgaSChRlsdznsmi0bf9P+myxTJi2A=="
Dec 15 11:17:20 gbvpi-bedroom go-librespot[22867]: time="2025-12-15T11:17:20-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:17:20 gbvpi-bedroom go-librespot[22867]: time="2025-12-15T11:17:20-05:00" level=debug msg="completed keyexchange"
Dec 15 11:17:20 gbvpi-bedroom go-librespot[22867]: time="2025-12-15T11:17:20-05:00" level=debug msg="completed challenge"
Dec 15 11:17:20 gbvpi-bedroom go-librespot[22867]: time="2025-12-15T11:17:20-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 15 11:17:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:17:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:17:22 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:17:22 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:17:23 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53.
Dec 15 11:17:23 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:23 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:23 gbvpi-bedroom go-librespot[22874]: go-librespot daemon starting...
Dec 15 11:17:23 gbvpi-bedroom go-librespot[22875]: time="2025-12-15T11:17:23-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:17:23 gbvpi-bedroom go-librespot[22875]: time="2025-12-15T11:17:23-05:00" level=debug msg="app state loaded"
Dec 15 11:17:23 gbvpi-bedroom go-librespot[22875]: time="2025-12-15T11:17:23-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:17:23 gbvpi-bedroom go-librespot[22875]: time="2025-12-15T11:17:23-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 15 11:17:23 gbvpi-bedroom go-librespot[22875]: time="2025-12-15T11:17:23-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 15 11:17:23 gbvpi-bedroom go-librespot[22875]: time="2025-12-15T11:17:23-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 15 11:17:23 gbvpi-bedroom go-librespot[22875]: time="2025-12-15T11:17:23-05:00" level=info msg="zeroconf server listening on port 34755"
Dec 15 11:17:24 gbvpi-bedroom go-librespot[22875]: time="2025-12-15T11:17:24-05:00" level=debug msg="obtained new client token: AACsvvtYyUV3qFJQ+83ImfEWXK+7/j/QS8nUVgHde3rWZwYDAL3WeqzgLH3GCa5yiqV9D2SHRWzXCfJ4Xh1GTdGKdHSsNqcAAEd0blGDrwaeilFngCLff2RDrwoXZgCWlpj8y9z0cYmuH68dcwZbH8zbsxEx34naAIez8mZJfstVIvMCtzWpTVs2dKN1+X0CMdt/gEHFAZA1bpHFEFmzQo8abXzFETbhE6qa4vCftYx8NK2drN8ywV0="
Dec 15 11:17:24 gbvpi-bedroom go-librespot[22875]: time="2025-12-15T11:17:24-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:17:24 gbvpi-bedroom go-librespot[22875]: time="2025-12-15T11:17:24-05:00" level=debug msg="completed keyexchange"
Dec 15 11:17:24 gbvpi-bedroom go-librespot[22875]: time="2025-12-15T11:17:24-05:00" level=debug msg="completed challenge"
Dec 15 11:17:24 gbvpi-bedroom go-librespot[22875]: time="2025-12-15T11:17:24-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 15 11:17:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:17:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:17:25 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:17:25 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:17:27 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54.
Dec 15 11:17:27 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:27 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:27 gbvpi-bedroom go-librespot[22896]: go-librespot daemon starting...
Dec 15 11:17:27 gbvpi-bedroom go-librespot[22897]: time="2025-12-15T11:17:27-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:17:27 gbvpi-bedroom go-librespot[22897]: time="2025-12-15T11:17:27-05:00" level=debug msg="app state loaded"
Dec 15 11:17:27 gbvpi-bedroom go-librespot[22897]: time="2025-12-15T11:17:27-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:17:27 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:17:27 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:17:27 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:17:27 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:17:27 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:17:27 gbvpi-bedroom volumio[22026]: info: Listing playlists
Dec 15 11:17:27 gbvpi-bedroom go-librespot[22897]: time="2025-12-15T11:17:27-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 15 11:17:27 gbvpi-bedroom go-librespot[22897]: time="2025-12-15T11:17:27-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 15 11:17:27 gbvpi-bedroom go-librespot[22897]: time="2025-12-15T11:17:27-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 15 11:17:27 gbvpi-bedroom go-librespot[22897]: time="2025-12-15T11:17:27-05:00" level=info msg="zeroconf server listening on port 45717"
Dec 15 11:17:27 gbvpi-bedroom go-librespot[22897]: time="2025-12-15T11:17:27-05:00" level=debug msg="obtained new client token: AADMnNEdmbp97DQHCWJ34Q2djT4suhEZcQmhiYBY4QFhIcuoAuGhTEdfzdtf3tqq1kI9M05qjogbUjWs1hclvO2KYpg5KSUAOShHMpgQ5yuKcg4ph5j5wKv3sXUS7q/kBPVUiMMc21vrfdbhEvK54WqpUI5cjgFAnJ8J8MYTEUa7WaWFx24j+yWjJkqGz7DGR5sDWpM4Ja5m6zr4Y3DJs0X7n81oErBkN1gZZOkL47TfHzMgz80DgzaMcg=="
Dec 15 11:17:27 gbvpi-bedroom go-librespot[22897]: time="2025-12-15T11:17:27-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:17:27 gbvpi-bedroom go-librespot[22897]: time="2025-12-15T11:17:27-05:00" level=debug msg="completed keyexchange"
Dec 15 11:17:27 gbvpi-bedroom go-librespot[22897]: time="2025-12-15T11:17:27-05:00" level=debug msg="completed challenge"
Dec 15 11:17:28 gbvpi-bedroom go-librespot[22897]: time="2025-12-15T11:17:28-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 15 11:17:28 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:17:28 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:17:28 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:17:28 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:17:31 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55.
Dec 15 11:17:31 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:31 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:31 gbvpi-bedroom go-librespot[22907]: go-librespot daemon starting...
Dec 15 11:17:31 gbvpi-bedroom go-librespot[22908]: time="2025-12-15T11:17:31-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:17:31 gbvpi-bedroom go-librespot[22908]: time="2025-12-15T11:17:31-05:00" level=debug msg="app state loaded"
Dec 15 11:17:31 gbvpi-bedroom go-librespot[22908]: time="2025-12-15T11:17:31-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:17:31 gbvpi-bedroom go-librespot[22908]: time="2025-12-15T11:17:31-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 15 11:17:31 gbvpi-bedroom go-librespot[22908]: time="2025-12-15T11:17:31-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 15 11:17:31 gbvpi-bedroom go-librespot[22908]: time="2025-12-15T11:17:31-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 15 11:17:31 gbvpi-bedroom go-librespot[22908]: time="2025-12-15T11:17:31-05:00" level=info msg="zeroconf server listening on port 46455"
Dec 15 11:17:31 gbvpi-bedroom go-librespot[22908]: time="2025-12-15T11:17:31-05:00" level=debug msg="obtained new client token: AAA0Lg89x8+8BcmyW9BkrdZemZj5zGK2Qrm8ZxFQ3+bwuHgHd4OYAItv/W0g9RBsKSIVhXSptJCfmfJDmy1o+qAXoQ5xNdS22/EiyMSVYuXetybi4NkDbLiW0SQR//PYXWigmeCgyPGJpp0bgj0y+AJFNXpL99hpyjpC/s4+8FL8ZaDjNdyilAcjEJj5M9JzKhrxEQoBAiZAu+jtB8QupqyXRgUq9/qrRPapbfwuZbUwQojNwluqEHww2A=="
Dec 15 11:17:31 gbvpi-bedroom go-librespot[22908]: time="2025-12-15T11:17:31-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 11:17:31 gbvpi-bedroom go-librespot[22908]: time="2025-12-15T11:17:31-05:00" level=debug msg="completed keyexchange"
Dec 15 11:17:31 gbvpi-bedroom go-librespot[22908]: time="2025-12-15T11:17:31-05:00" level=debug msg="completed challenge"
Dec 15 11:17:31 gbvpi-bedroom go-librespot[22908]: time="2025-12-15T11:17:31-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 15 11:17:31 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:17:31 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:17:31 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:17:31 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:17:34 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56.
Dec 15 11:17:34 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:34 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:17:34 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:17:35 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:35 gbvpi-bedroom go-librespot[22916]: go-librespot daemon starting...
Dec 15 11:17:35 gbvpi-bedroom go-librespot[22917]: time="2025-12-15T11:17:35-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:17:35 gbvpi-bedroom go-librespot[22917]: time="2025-12-15T11:17:35-05:00" level=debug msg="app state loaded"
Dec 15 11:17:35 gbvpi-bedroom go-librespot[22917]: time="2025-12-15T11:17:35-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:17:35 gbvpi-bedroom go-librespot[22917]: time="2025-12-15T11:17:35-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 15 11:17:35 gbvpi-bedroom go-librespot[22917]: time="2025-12-15T11:17:35-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 15 11:17:35 gbvpi-bedroom go-librespot[22917]: time="2025-12-15T11:17:35-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 15 11:17:35 gbvpi-bedroom go-librespot[22917]: time="2025-12-15T11:17:35-05:00" level=info msg="zeroconf server listening on port 35775"
Dec 15 11:17:35 gbvpi-bedroom go-librespot[22917]: time="2025-12-15T11:17:35-05:00" level=debug msg="obtained new client token: AABUxQ59MfDZwRfuuZ4j7LkxiD7tyoWRADpF6Zcrmcr+iOwLpphmoWBz/iuMaJpTtx2e3Zk9qWZRuNP49zOHMHNqUyALlXSLEWlMfns3A9I36RoAKsuJkVHuL6F/kZpUUgO9g6kGbGpP8vdhPTb2Ae9TcCtyS3hFXw3JIFn5DFwJnonB9Roek6xTPINpPOi0+ZLT9o6FimYq0nLzjYc1ZUgj1sdBqYjtAlfEWzPKCTLKRyl2HbLb1dS80A=="
Dec 15 11:17:35 gbvpi-bedroom go-librespot[22917]: time="2025-12-15T11:17:35-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 15 11:17:35 gbvpi-bedroom go-librespot[22917]: time="2025-12-15T11:17:35-05:00" level=debug msg="connected to ap-gue1.spotify.com:443"
Dec 15 11:17:35 gbvpi-bedroom go-librespot[22917]: time="2025-12-15T11:17:35-05:00" level=debug msg="completed keyexchange"
Dec 15 11:17:35 gbvpi-bedroom go-librespot[22917]: time="2025-12-15T11:17:35-05:00" level=debug msg="completed challenge"
Dec 15 11:17:35 gbvpi-bedroom go-librespot[22917]: time="2025-12-15T11:17:35-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 15 11:17:35 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:17:35 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:17:37 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:17:37 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:17:37 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:17:37 gbvpi-bedroom volumio[22026]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 11:17:38 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57.
Dec 15 11:17:38 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:38 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 11:17:38 gbvpi-bedroom go-librespot[22938]: go-librespot daemon starting...
Dec 15 11:17:38 gbvpi-bedroom go-librespot[22939]: time="2025-12-15T11:17:38-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 11:17:38 gbvpi-bedroom go-librespot[22939]: time="2025-12-15T11:17:38-05:00" level=debug msg="app state loaded"
Dec 15 11:17:38 gbvpi-bedroom go-librespot[22939]: time="2025-12-15T11:17:38-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 11:17:38 gbvpi-bedroom go-librespot[22939]: time="2025-12-15T11:17:38-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 15 11:17:38 gbvpi-bedroom go-librespot[22939]: time="2025-12-15T11:17:38-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 15 11:17:38 gbvpi-bedroom go-librespot[22939]: time="2025-12-15T11:17:38-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 15 11:17:38 gbvpi-bedroom go-librespot[22939]: time="2025-12-15T11:17:38-05:00" level=info msg="zeroconf server listening on port 46315"
Dec 15 11:17:39 gbvpi-bedroom go-librespot[22939]: time="2025-12-15T11:17:39-05:00" level=debug msg="obtained new client token: AAAm1w+ZC96tSAtJHcMcg8BuKsdGbXss1sEF9cd11m/Sx8/aguSPuWFbdW9sqHjSaUtiE9C6fj0fZX9bNeE/WnF7iKUfBWBo66SeJIhmK8o1VSIdnHoRO3zO/Xj+qRqee56TTaL5TwPgp67ONWDvRb6b28l0lwPjNn6l1ZVG5iEkIGRm+TUTTiPQoqQM8GmCVZvL6fp6pmzG12aBRddGSMvTQqn+UjlAPlYqsu0dl/pws+RCSL507lM="
Dec 15 11:17:39 gbvpi-bedroom go-librespot[22939]: time="2025-12-15T11:17:39-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 15 11:17:40 gbvpi-bedroom volumio[22026]: info: Initializing connection to go-librespot Websocket
Dec 15 11:17:40 gbvpi-bedroom go-librespot[22939]: time="2025-12-15T11:17:40-05:00" level=debug msg="new websocket client"
Dec 15 11:17:40 gbvpi-bedroom volumio[22026]: info: Connection to go-librespot Websocket established
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: info: Getting Spotify volume
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: SPOTIFY: SPOTIFY VOLUME undefined
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: SPOTIFY: VOLUMIO VOLUME 91
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: info: Aligning Spotify Volume to Volumio Volume
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: info: CoreCommandRouter::volumioGetState
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: info: Setting Spotify Volume from Volumio: 91
Dec 15 11:17:44 gbvpi-bedroom go-librespot[22939]: time="2025-12-15T11:17:44-05:00" level=debug msg="connected to ap-gue1.spotify.com:443"
Dec 15 11:17:44 gbvpi-bedroom go-librespot[22939]: time="2025-12-15T11:17:44-05:00" level=debug msg="completed keyexchange"
Dec 15 11:17:44 gbvpi-bedroom go-librespot[22939]: time="2025-12-15T11:17:44-05:00" level=debug msg="completed challenge"
Dec 15 11:17:44 gbvpi-bedroom go-librespot[22939]: time="2025-12-15T11:17: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 15 11:17:44 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 11:17:44 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: Error: socket hang up
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: at connResetException (node:internal/errors:720:14)
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: at Socket.socketOnEnd (node:_http_client:519:23)
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: at Socket.emit (node:events:526:35)
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: at endReadableNT (node:internal/streams/readable:1376:12)
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: code: 'ECONNRESET',
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: response: undefined
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: }
Dec 15 11:17:44 gbvpi-bedroom volumio[22026]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 15 11:17:44 gbvpi-bedroom sudo[22961]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 11:16'
Dec 15 11:17:44 gbvpi-bedroom sudo[22961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)"
NAME="Raspbian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="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"