Dec 15 04:16:00 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Dec 15 04:16:00 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:00 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:00 gbvpi-bedroom go-librespot[30495]: go-librespot daemon starting...
Dec 15 04:16:00 gbvpi-bedroom go-librespot[30496]: time="2025-12-15T04:16:00-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 04:16:00 gbvpi-bedroom go-librespot[30496]: time="2025-12-15T04:16:00-05:00" level=debug msg="app state loaded"
Dec 15 04:16:00 gbvpi-bedroom go-librespot[30496]: time="2025-12-15T04:16:00-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 04:16:00 gbvpi-bedroom go-librespot[30496]: time="2025-12-15T04:16:00-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 04:16:00 gbvpi-bedroom go-librespot[30496]: time="2025-12-15T04:16:00-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 04:16:00 gbvpi-bedroom go-librespot[30496]: time="2025-12-15T04:16:00-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 04:16:00 gbvpi-bedroom go-librespot[30496]: time="2025-12-15T04:16:00-05:00" level=info msg="zeroconf server listening on port 39441"
Dec 15 04:16:00 gbvpi-bedroom go-librespot[30496]: time="2025-12-15T04:16:00-05:00" level=debug msg="obtained new client token: AACYSMDlfOsMLr1a4H6yPPzQzO1Wy9PagSwpBxbstG/sLn+z5ibD3dPJ5Z2jcyi0xAXmUvPQd16QE0G0P3h6gwa0AV+VV5sgzcJmZ8C1lSuUrCnK7QmhCXDRs/2RgKlxQkX2/BE1nRfV+8ouZ7Uzw6kd4auL9GwMmx31FjHgiYvWPXu+0uy1KkLe+kkceVK7oR0zXD0EmsT1QDhAYMfUdZbhr0l3R+3PvUUGh6aDN6L9t4RrHidCF8X1XQ=="
Dec 15 04:16:00 gbvpi-bedroom go-librespot[30496]: time="2025-12-15T04:16:00-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 04:16:00 gbvpi-bedroom go-librespot[30496]: time="2025-12-15T04:16:00-05:00" level=debug msg="completed keyexchange"
Dec 15 04:16:00 gbvpi-bedroom go-librespot[30496]: time="2025-12-15T04:16:00-05:00" level=debug msg="completed challenge"
Dec 15 04:16:00 gbvpi-bedroom go-librespot[30496]: time="2025-12-15T04:16:00-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 04:16:00 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 04:16:00 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 04:16:01 gbvpi-bedroom systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 4.
Dec 15 04:16:01 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service.
Dec 15 04:16:01 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service.
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: warn: [cd-plugin] cdspeedctl: device or media not ready
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Adding inputs REST Endpoints
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Scanning Audio Inputs
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Checking against Known Cards name
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Adding Server instance for streaming
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: error: Hi Res Audio Failed Login: Missing Login Data
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Adding HIGHRESAUDIO REST API Endpoints
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect
Dec 15 04:16:03 gbvpi-bedroom sudo[30522]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: QobuzConnect: Starting Qobuz Connect socket and service
Dec 15 04:16:03 gbvpi-bedroom sudo[30522]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Adding TIDAL REST API Endpoints
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Stopping AccessToken refresher cron for QOBUZ
Dec 15 04:16:03 gbvpi-bedroom sudo[30529]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service
Dec 15 04:16:03 gbvpi-bedroom sudo[30529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 04:16:03 gbvpi-bedroom sudo[30522]: pam_unix(sudo:session): session closed for user root
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: AccessToken refresher cron started for QOBUZ
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Adding QOBUZ REST API Endpoints
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CorePlayQueue::getTrack 0
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Updating MyVolumio device info
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 04:16:03 gbvpi-bedroom sudo[30529]: pam_unix(sudo:session): session closed for user root
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Updating MyVolumio device info
Dec 15 04:16:03 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: MRS: Getting audio outputs on start
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: MRS: Requesting all other devices output
Dec 15 04:16:03 gbvpi-bedroom sudo[30532]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service
Dec 15 04:16:03 gbvpi-bedroom sudo[30532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Successfully Added MyVolumio device
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Successfully Added MyVolumio device
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: MPD Permissions set
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Listing playlists
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Listing playlists
Dec 15 04:16:03 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:03 gbvpi-bedroom go-librespot[30533]: go-librespot daemon starting...
Dec 15 04:16:03 gbvpi-bedroom sudo[30537]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service
Dec 15 04:16:03 gbvpi-bedroom sudo[30537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Executing endpoint qc_getconfig
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig
Dec 15 04:16:03 gbvpi-bedroom go-librespot[30538]: time="2025-12-15T04:16:03-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 04:16:03 gbvpi-bedroom go-librespot[30538]: time="2025-12-15T04:16:03-05:00" level=debug msg="app state loaded"
Dec 15 04:16:03 gbvpi-bedroom go-librespot[30538]: time="2025-12-15T04:16:03-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 04:16:03 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service...
Dec 15 04:16:03 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully.
Dec 15 04:16:03 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service.
Dec 15 04:16:03 gbvpi-bedroom sudo[30537]: pam_unix(sudo:session): session closed for user root
Dec 15 04:16:03 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service.
Dec 15 04:16:03 gbvpi-bedroom sudo[30532]: pam_unix(sudo:session): session closed for user root
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioStop
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreStateMachine::stop
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: error: updateQueue error: null
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: Executing endpoint qc_getconfig
Dec 15 04:16:03 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig
Dec 15 04:16:04 gbvpi-bedroom qobuz-connect[30548]: 20251215 04:16:04.010 [30548.30548] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket
Dec 15 04:16:04 gbvpi-bedroom qobuz-connect[30548]: 20251215 04:16:04.014 [30548.30548] INFO VolumeManager: [0x1e92588]: Setting new playback volume: 75
Dec 15 04:16:04 gbvpi-bedroom qobuz-connect[30548]: 20251215 04:16:04.014 [30548.30548] INFO VolumeManager: [0x1e92588]: Setting new mute state: 0
Dec 15 04:16:04 gbvpi-bedroom qobuz-connect[30548]: 20251215 04:16:04.014 [30548.30548] INFO QobuzConnect: [0x1e92f58]: Client initialized!
Dec 15 04:16:04 gbvpi-bedroom qobuz-connect[30548]: 20251215 04:16:04.014 [30548.30548] INFO SampleApp: Starting Avahi advertising, name: GBVPi-Bedroom, service name: _qobuz-connect._tcp
Dec 15 04:16:04 gbvpi-bedroom volumio[30072]: info: Successfully Updated MyVolumio device
Dec 15 04:16:04 gbvpi-bedroom qobuz-connect[30548]: 20251215 04:16:04.030 [30548.30548] INFO LocalConfigManager: [0x1e91e68]: Starting Local Configuration server
Dec 15 04:16:04 gbvpi-bedroom qobuz-connect[30548]: 20251215 04:16:04.030 [30548.30548] INFO SampleApp: Starting Local configuration server
Dec 15 04:16:04 gbvpi-bedroom qobuz-connect[30548]: 20251215 04:16:04.030 [30548.30548] INFO SampleApp: Connected to UNIX socket client 0x1e7c818
Dec 15 04:16:04 gbvpi-bedroom go-librespot[30538]: time="2025-12-15T04:16:04-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 04:16:04 gbvpi-bedroom go-librespot[30538]: time="2025-12-15T04:16:04-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 04:16:04 gbvpi-bedroom go-librespot[30538]: time="2025-12-15T04:16:04-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 04:16:04 gbvpi-bedroom volumio[30072]: info: Successfully Updated MyVolumio device
Dec 15 04:16:04 gbvpi-bedroom volumio[30072]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object]
Dec 15 04:16:04 gbvpi-bedroom volumio[30072]: info: QobuzConnect: QOBUZ Connect daemon connected
Dec 15 04:16:04 gbvpi-bedroom go-librespot[30538]: time="2025-12-15T04:16:04-05:00" level=info msg="zeroconf server listening on port 38761"
Dec 15 04:16:04 gbvpi-bedroom sudo[30566]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service
Dec 15 04:16:04 gbvpi-bedroom sudo[30566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 04:16:04 gbvpi-bedroom volumio[30072]: info: Starting Shairport Sync
Dec 15 04:16:04 gbvpi-bedroom volumio[30072]: info: MRS: Found cast device: Google-Home-Mini-f209fa314cb426d40a59bcf66354ddc9
Dec 15 04:16:04 gbvpi-bedroom volumio[30072]: info: Adding audio output:
Dec 15 04:16:04 gbvpi-bedroom systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel...
Dec 15 04:16:04 gbvpi-bedroom autossh[28731]: received signal to exit (15)
Dec 15 04:16:04 gbvpi-bedroom systemd[1]: sshtunnel.service: Deactivated successfully.
Dec 15 04:16:04 gbvpi-bedroom systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel.
Dec 15 04:16:04 gbvpi-bedroom sudo[30571]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 15 04:16:04 gbvpi-bedroom sudo[30571]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 04:16:04 gbvpi-bedroom volumio[30072]: info: MRS: Found cast device: SmartTV-4K-fe72c264393a59c76d38e27b8168114d
Dec 15 04:16:04 gbvpi-bedroom volumio[30072]: info: Adding audio output:
Dec 15 04:16:04 gbvpi-bedroom systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel.
Dec 15 04:16:04 gbvpi-bedroom sudo[30566]: pam_unix(sudo:session): session closed for user root
Dec 15 04:16:04 gbvpi-bedroom go-librespot[30538]: time="2025-12-15T04:16:04-05:00" level=debug msg="obtained new client token: AAAKzRAZ51XpTVUl2NGoWmuiy4Y6I/ccOeLa4xqpT0uyn5okqhE7utgXLqlUSpAVaILCBicm9d4vrXU+Vjk2mcx0/O4Y4p/gvvFZhBghCzwMK/xdpfZheqqmu+DmdCbwNve8Ujwh8vjgvhLqzBzkXZSnPf/Qz1vh8M56SrhBqec0WThJ0FqmIbTsRYbIj0HzgmsXspEDvAmXHm4ERDBjEe4fwINeLdqhyW49cPgLgw3+0XeWsOOzwMY="
Dec 15 04:16:04 gbvpi-bedroom autossh[30574]: port set to 0, monitoring disabled
Dec 15 04:16:04 gbvpi-bedroom autossh[30574]: starting ssh (count 1)
Dec 15 04:16:04 gbvpi-bedroom autossh[30574]: ssh child pid is 30577
Dec 15 04:16:04 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 15 04:16:04 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 15 04:16:04 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 15 04:16:04 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.632s CPU time.
Dec 15 04:16:04 gbvpi-bedroom qobuz-connect[30548]: 20251215 04:16:04.160 [30548.30548] INFO SampleApp: Playback volume changed: 75
Dec 15 04:16:04 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 15 04:16:04 gbvpi-bedroom sudo[30571]: pam_unix(sudo:session): session closed for user root
Dec 15 04:16:04 gbvpi-bedroom volumio[30072]: info: Remote SSH Started
Dec 15 04:16:04 gbvpi-bedroom go-librespot[30538]: time="2025-12-15T04:16:04-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 04:16:04 gbvpi-bedroom go-librespot[30538]: time="2025-12-15T04:16:04-05:00" level=debug msg="completed keyexchange"
Dec 15 04:16:04 gbvpi-bedroom go-librespot[30538]: time="2025-12-15T04:16:04-05:00" level=debug msg="completed challenge"
Dec 15 04:16:04 gbvpi-bedroom volumiossh-tunnel[30577]: Warning: Permanently added '[us1.myvolumio.org]:2222' (RSA) to the list of known hosts.
Dec 15 04:16:04 gbvpi-bedroom go-librespot[30538]: time="2025-12-15T04:16:04-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 04:16:04 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:04 gbvpi-bedroom volumio[30072]: info: Shairport-Sync Started
Dec 15 04:16:04 gbvpi-bedroom volumio[30072]: 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 04:16:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 04:16:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 04:16:04 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:04 gbvpi-bedroom volumio[30072]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status'
Dec 15 04:16:06 gbvpi-bedroom volumio[30072]: info: TidalConnect service stoped!
Dec 15 04:16:06 gbvpi-bedroom volumio[30072]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect
Dec 15 04:16:06 gbvpi-bedroom volumio[30072]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect
Dec 15 04:16:06 gbvpi-bedroom sudo[30602]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service
Dec 15 04:16:06 gbvpi-bedroom sudo[30602]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 04:16:06 gbvpi-bedroom sudo[30606]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 15 04:16:06 gbvpi-bedroom sudo[30606]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 04:16:06 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:06 gbvpi-bedroom volumio[30072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:16:06 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service.
Dec 15 04:16:06 gbvpi-bedroom sudo[30602]: pam_unix(sudo:session): session closed for user root
Dec 15 04:16:06 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Dec 15 04:16:06 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully.
Dec 15 04:16:06 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Dec 15 04:16:06 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Dec 15 04:16:06 gbvpi-bedroom sudo[30606]: pam_unix(sudo:session): session closed for user root
Dec 15 04:16:06 gbvpi-bedroom volumio[30072]: info: Successfully started MPD Monitor
Dec 15 04:16:06 gbvpi-bedroom mpd_monitor.sh[30610]: MPD Monitor Service: Starting MPD Monitor Service
Dec 15 04:16:06 gbvpi-bedroom volumio[30072]: info: Executing endpoint tc_getconfig
Dec 15 04:16:06 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig
Dec 15 04:16:06 gbvpi-bedroom vtcs[30608]: STARTING TidalConnect services, version: 1.5.2.56
Dec 15 04:16:06 gbvpi-bedroom vtcs[30608]: STARTED TidalConnect services.
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: Executing endpoint tc_connect
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: Connecting to TidalConnect
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::servicePushState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreStateMachine::pushState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioPushState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: MRS: Pushing multiroomSync output update for this device
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: MRS: Pushing multiroomSync output
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CorePlayQueue::getTrack 0
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: 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 04:16:07 gbvpi-bedroom volumio[30072]: verbose: CURRENT POSITION 0
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreStateMachine::syncState stateService stop
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreStateMachine::syncState currentStatus stop
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreStateMachine::pushState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioPushState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: MRS: Pushing multiroomSync output update for this device
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: MRS: Pushing multiroomSync output
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: No code
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreStateMachine::pushState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioPushState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: MRS: Pushing multiroomSync output update for this device
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: MRS: Pushing multiroomSync output
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::servicePushState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreStateMachine::pushState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioPushState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: MRS: Pushing multiroomSync output update for this device
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: MRS: Pushing multiroomSync output
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CorePlayQueue::getTrack 0
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: 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 04:16:07 gbvpi-bedroom volumio[30072]: verbose: CURRENT POSITION 0
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreStateMachine::syncState stateService stop
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreStateMachine::syncState currentStatus stop
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreStateMachine::pushState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioPushState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: MRS: Pushing multiroomSync output update for this device
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: MRS: Pushing multiroomSync output
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: No code
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreStateMachine::pushState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioPushState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: MRS: Pushing multiroomSync output update for this device
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: MRS: Pushing multiroomSync output
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status'
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status'
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status'
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status'
Dec 15 04:16:07 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11.
Dec 15 04:16:07 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:07 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:07 gbvpi-bedroom go-librespot[30628]: go-librespot daemon starting...
Dec 15 04:16:07 gbvpi-bedroom go-librespot[30629]: time="2025-12-15T04:16:07-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 04:16:07 gbvpi-bedroom go-librespot[30629]: time="2025-12-15T04:16:07-05:00" level=debug msg="app state loaded"
Dec 15 04:16:07 gbvpi-bedroom go-librespot[30629]: time="2025-12-15T04:16:07-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: Listing playlists
Dec 15 04:16:07 gbvpi-bedroom volumio[30072]: info: Listing playlists
Dec 15 04:16:07 gbvpi-bedroom go-librespot[30629]: time="2025-12-15T04:16:07-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 04:16:07 gbvpi-bedroom go-librespot[30629]: time="2025-12-15T04:16:07-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 04:16:07 gbvpi-bedroom go-librespot[30629]: time="2025-12-15T04:16:07-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 04:16:07 gbvpi-bedroom go-librespot[30629]: time="2025-12-15T04:16:07-05:00" level=info msg="zeroconf server listening on port 39305"
Dec 15 04:16:07 gbvpi-bedroom go-librespot[30629]: time="2025-12-15T04:16:07-05:00" level=debug msg="obtained new client token: AADj/RAiyqbbCBzyqkiCNRiEwsU89DbzA4z/f1dmU7l+ooDkvjkzUVEiD1+kL/3AGcgfXYqy5XtXiFltAZMEViRMawg/Yo00YgtaQxediWR6zzPJwYE++YBXrQNzF/Bxl9iGke89fnRJ1/yZg5ZhAwnwVhoW768OZhwMf7POXvr1LV05Fh2N3qAuGGT7HT7iwuzhUDGn5BrVdDB1AQYtZ8DQX3AtxcQSxu0gfzhTfQ4HC2VKflMp9+5/TA=="
Dec 15 04:16:07 gbvpi-bedroom go-librespot[30629]: time="2025-12-15T04:16:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 04:16:07 gbvpi-bedroom go-librespot[30629]: time="2025-12-15T04:16:07-05:00" level=debug msg="completed keyexchange"
Dec 15 04:16:07 gbvpi-bedroom go-librespot[30629]: time="2025-12-15T04:16:07-05:00" level=debug msg="completed challenge"
Dec 15 04:16:07 gbvpi-bedroom go-librespot[30629]: time="2025-12-15T04:16:07-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 15 04:16:07 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 04:16:07 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 04:16:08 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:09 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:09 gbvpi-bedroom volumio[30072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:16:09 gbvpi-bedroom volumio[30072]: info: TidalConnect service started!
Dec 15 04:16:09 gbvpi-bedroom volumio[30072]: [Metrics] CommandRouter: 29s 281.25ms
Dec 15 04:16:09 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumiosetStartupVolume
Dec 15 04:16:09 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 04:16:09 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 04:16:09 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::Close All Modals sent
Dec 15 04:16:09 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::Close All Modals sent
Dec 15 04:16:10 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Dec 15 04:16:10 gbvpi-bedroom volumio[30072]: 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 04:16:10 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:10 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Dec 15 04:16:10 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Dec 15 04:16:10 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Dec 15 04:16:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12.
Dec 15 04:16:10 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:11 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:11 gbvpi-bedroom go-librespot[30640]: go-librespot daemon starting...
Dec 15 04:16:11 gbvpi-bedroom go-librespot[30641]: time="2025-12-15T04:16:11-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 04:16:11 gbvpi-bedroom go-librespot[30641]: time="2025-12-15T04:16:11-05:00" level=debug msg="app state loaded"
Dec 15 04:16:11 gbvpi-bedroom go-librespot[30641]: time="2025-12-15T04:16:11-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 04:16:11 gbvpi-bedroom go-librespot[30641]: time="2025-12-15T04:16:11-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 04:16:11 gbvpi-bedroom go-librespot[30641]: time="2025-12-15T04:16:11-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 04:16:11 gbvpi-bedroom go-librespot[30641]: time="2025-12-15T04:16:11-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 04:16:11 gbvpi-bedroom go-librespot[30641]: time="2025-12-15T04:16:11-05:00" level=info msg="zeroconf server listening on port 45991"
Dec 15 04:16:11 gbvpi-bedroom go-librespot[30641]: time="2025-12-15T04:16:11-05:00" level=debug msg="obtained new client token: AABw13r4szvwX8U59zTrSAVHgohIIWFctijOYCraGjZInf/kC/xnjDQoHI+triaLuixaIFRpnUJMPNHyJZW1oxV017BD27WhRgDY5mfDUmPS2QJGwTERjbUJSZpBNAXQUe1/1YTEvUtIKmQeKj1FFYyjP+2dJ7NdCUbHPmrwx7QSQJyazfgihNn0eQGU14iv3PMgssG3l4XaHkzET1ZPPGtivOdXyqiTHDRkIuQCGDtQbJh3QetBrYcYBA=="
Dec 15 04:16:11 gbvpi-bedroom go-librespot[30641]: time="2025-12-15T04:16:11-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 04:16:11 gbvpi-bedroom go-librespot[30641]: time="2025-12-15T04:16:11-05:00" level=debug msg="completed keyexchange"
Dec 15 04:16:11 gbvpi-bedroom go-librespot[30641]: time="2025-12-15T04:16:11-05:00" level=debug msg="completed challenge"
Dec 15 04:16:11 gbvpi-bedroom go-librespot[30641]: time="2025-12-15T04:16:11-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 04:16:11 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 04:16:11 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 04:16:12 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:12 gbvpi-bedroom volumio[30072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:16:14 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13.
Dec 15 04:16:14 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:14 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:14 gbvpi-bedroom go-librespot[30662]: go-librespot daemon starting...
Dec 15 04:16:14 gbvpi-bedroom go-librespot[30663]: time="2025-12-15T04:16:14-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 04:16:14 gbvpi-bedroom go-librespot[30663]: time="2025-12-15T04:16:14-05:00" level=debug msg="app state loaded"
Dec 15 04:16:14 gbvpi-bedroom go-librespot[30663]: time="2025-12-15T04:16:14-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 04:16:14 gbvpi-bedroom go-librespot[30663]: time="2025-12-15T04:16:14-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 15 04:16:14 gbvpi-bedroom go-librespot[30663]: time="2025-12-15T04:16:14-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 15 04:16:14 gbvpi-bedroom go-librespot[30663]: time="2025-12-15T04:16:14-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 15 04:16:14 gbvpi-bedroom go-librespot[30663]: time="2025-12-15T04:16:14-05:00" level=info msg="zeroconf server listening on port 43079"
Dec 15 04:16:14 gbvpi-bedroom go-librespot[30663]: time="2025-12-15T04:16:14-05:00" level=debug msg="obtained new client token: AABIoweP7KGfeEm/YIBOnr8jtVI8oIqwgMHwnsaR4tB3wNsgV3Z4HTywAE7g6EIU4Rle1yhVOdEv8wx4hKLmQndi78kdZZNa2UTTrgneNJWxzAssoEnGWOzsCz9qAuO8lEcFrox+HMFml2BtSfcSERtEp3FbDdBQ2M8EzGwPRyl17AF0kauZZAWn43mCPlG8Sl0wKyJrTCbWRu3SKweQZ2aBAM+k7NQXbFqBwqbu9dbH+a4eU58hqGDGEA=="
Dec 15 04:16:14 gbvpi-bedroom go-librespot[30663]: time="2025-12-15T04:16:14-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 04:16:14 gbvpi-bedroom go-librespot[30663]: time="2025-12-15T04:16:14-05:00" level=debug msg="completed keyexchange"
Dec 15 04:16:14 gbvpi-bedroom go-librespot[30663]: time="2025-12-15T04:16:14-05:00" level=debug msg="completed challenge"
Dec 15 04:16:14 gbvpi-bedroom go-librespot[30663]: time="2025-12-15T04:16:14-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 15 04:16:14 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 04:16:14 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 04:16:15 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 15 04:16:15 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 04:16:15 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Dec 15 04:16:15 gbvpi-bedroom volumio-remote-updater[775]: Test mode enabled
Dec 15 04:16:15 gbvpi-bedroom volumio-remote-updater[775]: Alpha mode disabled
Dec 15 04:16:15 gbvpi-bedroom volumio-remote-updater[775]: Alpha legacy test mode disabled
Dec 15 04:16:15 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Dec 15 04:16:15 gbvpi-bedroom volumio[30072]: 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 04:16:15 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Dec 15 04:16:15 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 04:16:15 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 04:16:15 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Dec 15 04:16:15 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Dec 15 04:16:15 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Dec 15 04:16:15 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetBrowseSources
Dec 15 04:16:15 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 15 04:16:15 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:15 gbvpi-bedroom volumio[30072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:16:16 gbvpi-bedroom volumio[30072]: info: BOOT COMPLETED
Dec 15 04:16:17 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:18 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:18 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14.
Dec 15 04:16:18 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:18 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:18 gbvpi-bedroom go-librespot[30674]: go-librespot daemon starting...
Dec 15 04:16:18 gbvpi-bedroom go-librespot[30675]: time="2025-12-15T04:16:18-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 04:16:18 gbvpi-bedroom go-librespot[30675]: time="2025-12-15T04:16:18-05:00" level=debug msg="app state loaded"
Dec 15 04:16:18 gbvpi-bedroom go-librespot[30675]: time="2025-12-15T04:16:18-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 04:16:18 gbvpi-bedroom go-librespot[30675]: time="2025-12-15T04:16:18-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 04:16:18 gbvpi-bedroom go-librespot[30675]: time="2025-12-15T04:16:18-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 04:16:18 gbvpi-bedroom go-librespot[30675]: time="2025-12-15T04:16:18-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 04:16:18 gbvpi-bedroom go-librespot[30675]: time="2025-12-15T04:16:18-05:00" level=info msg="zeroconf server listening on port 40001"
Dec 15 04:16:18 gbvpi-bedroom go-librespot[30675]: time="2025-12-15T04:16:18-05:00" level=debug msg="obtained new client token: AABaSZ2VZ0J/6XPRsLjKcc3irgqEdRrxK12xozuLjYoHLeOCQjWfRD39PtMQEzGlE92Jnn1gbz50CJhIZuO0ipAbt+Ht+OrK7bBDXswXhoZgl72hVA3CmRe3EcB3jI/aXHkWffulZq9Mv+8bszl7SD+2oFn3VWmkaqgsGb8i5pNIn2qsfd5DXVrmwVxyFkWZWYyOICtnEwzuSAjZDufJm4YiUO2jwY2jR65rKybrjwIndpuv+L65yUaRog=="
Dec 15 04:16:18 gbvpi-bedroom go-librespot[30675]: time="2025-12-15T04:16:18-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 04:16:18 gbvpi-bedroom go-librespot[30675]: time="2025-12-15T04:16:18-05:00" level=debug msg="completed keyexchange"
Dec 15 04:16:18 gbvpi-bedroom go-librespot[30675]: time="2025-12-15T04:16:18-05:00" level=debug msg="completed challenge"
Dec 15 04:16:18 gbvpi-bedroom go-librespot[30675]: time="2025-12-15T04:16:18-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 15 04:16:18 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 04:16:18 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 04:16:18 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:18 gbvpi-bedroom volumio[30072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:16:21 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:21 gbvpi-bedroom volumio[30072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:16:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15.
Dec 15 04:16:21 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:22 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:22 gbvpi-bedroom go-librespot[30696]: go-librespot daemon starting...
Dec 15 04:16:22 gbvpi-bedroom go-librespot[30697]: time="2025-12-15T04:16:22-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 04:16:22 gbvpi-bedroom go-librespot[30697]: time="2025-12-15T04:16:22-05:00" level=debug msg="app state loaded"
Dec 15 04:16:22 gbvpi-bedroom go-librespot[30697]: time="2025-12-15T04:16:22-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 04:16:22 gbvpi-bedroom go-librespot[30697]: time="2025-12-15T04:16:22-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 04:16:22 gbvpi-bedroom go-librespot[30697]: time="2025-12-15T04:16:22-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 04:16:22 gbvpi-bedroom go-librespot[30697]: time="2025-12-15T04:16:22-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 04:16:22 gbvpi-bedroom go-librespot[30697]: time="2025-12-15T04:16:22-05:00" level=info msg="zeroconf server listening on port 38427"
Dec 15 04:16:22 gbvpi-bedroom go-librespot[30697]: time="2025-12-15T04:16:22-05:00" level=debug msg="obtained new client token: AADdYEr4520qmL3Txqml5c6GXnUMxwjy4CeuZSjD/UBCeGPoeKbfw9PA3OEAw/wrbPcW1OCd9f7vR5FFysEu3YvqaZ3nRW83AeBb6lz+rqKsPqA4XXWEU7NR02yESdXshbo1qkEWyymcyn9xpnN0/2KDHTmg0HYc/ahKlSirAW9Xe1SJdmGC0153PuWR7vmUI/1PYs1vbzYN0Rdjh27PS7hAWdVboCdvX4z7+Y0hgBf7PSRXwGSiHpdtGA=="
Dec 15 04:16:22 gbvpi-bedroom go-librespot[30697]: time="2025-12-15T04:16:22-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 04:16:22 gbvpi-bedroom go-librespot[30697]: time="2025-12-15T04:16:22-05:00" level=debug msg="completed keyexchange"
Dec 15 04:16:22 gbvpi-bedroom go-librespot[30697]: time="2025-12-15T04:16:22-05:00" level=debug msg="completed challenge"
Dec 15 04:16:22 gbvpi-bedroom go-librespot[30697]: time="2025-12-15T04:16:22-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 15 04:16:22 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 04:16:22 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 04:16:24 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:24 gbvpi-bedroom volumio[30072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:16:25 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16.
Dec 15 04:16:25 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:25 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:25 gbvpi-bedroom go-librespot[30705]: go-librespot daemon starting...
Dec 15 04:16:25 gbvpi-bedroom go-librespot[30706]: time="2025-12-15T04:16:25-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 04:16:25 gbvpi-bedroom go-librespot[30706]: time="2025-12-15T04:16:25-05:00" level=debug msg="app state loaded"
Dec 15 04:16:25 gbvpi-bedroom go-librespot[30706]: time="2025-12-15T04:16:25-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 04:16:25 gbvpi-bedroom go-librespot[30706]: time="2025-12-15T04:16:25-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]"
Dec 15 04:16:25 gbvpi-bedroom go-librespot[30706]: time="2025-12-15T04:16:25-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Dec 15 04:16:25 gbvpi-bedroom go-librespot[30706]: time="2025-12-15T04:16:25-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Dec 15 04:16:25 gbvpi-bedroom go-librespot[30706]: time="2025-12-15T04:16:25-05:00" level=info msg="zeroconf server listening on port 41349"
Dec 15 04:16:25 gbvpi-bedroom go-librespot[30706]: time="2025-12-15T04:16:25-05:00" level=debug msg="obtained new client token: AAAa0cTo4wP8vjN4J0/C+6kQv+UwN49EWalw3wDN6oMR0esLHDm2sOt5Tv+et1cgMBK/dbPGKeT0I35goTGQ0ZCE5rUEb9yaqv8BiEVFCtDJ/NcH8ujPLnbKMkZfPafF9orWOn42BK61Zun3eaVZtGDFZ2vCyIUIMD8Ccf6U94H8/j5LzaUkb8qZt2rHOV2hci9ogh5eai2ppwp6NpQCDMqE/fe+DBdQI4N9K0J0HJsb39rXThPEEsfxaw=="
Dec 15 04:16:25 gbvpi-bedroom go-librespot[30706]: time="2025-12-15T04:16:25-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 04:16:25 gbvpi-bedroom go-librespot[30706]: time="2025-12-15T04:16:25-05:00" level=debug msg="completed keyexchange"
Dec 15 04:16:25 gbvpi-bedroom go-librespot[30706]: time="2025-12-15T04:16:25-05:00" level=debug msg="completed challenge"
Dec 15 04:16:25 gbvpi-bedroom go-librespot[30706]: time="2025-12-15T04:16:25-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 15 04:16:25 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 04:16:25 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 04:16:27 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:27 gbvpi-bedroom volumio[30072]: info: Listing playlists
Dec 15 04:16:27 gbvpi-bedroom volumio[30072]: info: Listing playlists
Dec 15 04:16:27 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:27 gbvpi-bedroom volumio[30072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:16:28 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:28 gbvpi-bedroom volumio[30072]: info: Listing playlists
Dec 15 04:16:28 gbvpi-bedroom volumio[30072]: info: Listing playlists
Dec 15 04:16:28 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17.
Dec 15 04:16:28 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:29 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:29 gbvpi-bedroom go-librespot[30717]: go-librespot daemon starting...
Dec 15 04:16:29 gbvpi-bedroom go-librespot[30718]: time="2025-12-15T04:16:29-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 04:16:29 gbvpi-bedroom go-librespot[30718]: time="2025-12-15T04:16:29-05:00" level=debug msg="app state loaded"
Dec 15 04:16:29 gbvpi-bedroom go-librespot[30718]: time="2025-12-15T04:16:29-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 04:16:29 gbvpi-bedroom go-librespot[30718]: time="2025-12-15T04:16:29-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 15 04:16:29 gbvpi-bedroom go-librespot[30718]: time="2025-12-15T04:16:29-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 04:16:29 gbvpi-bedroom go-librespot[30718]: time="2025-12-15T04:16:29-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 04:16:29 gbvpi-bedroom go-librespot[30718]: time="2025-12-15T04:16:29-05:00" level=info msg="zeroconf server listening on port 41405"
Dec 15 04:16:29 gbvpi-bedroom go-librespot[30718]: time="2025-12-15T04:16:29-05:00" level=debug msg="obtained new client token: AACKaLgitDzDfwLZugnO7J7NM/5o6AHrTM9GWjmVZcAJESHTA5DSL3yF8b2WlUcXLItMNYvavGRgAP+IfvDXtGqU+6yI77i6Egc6yf9iFtmmf14YPWoSo0I12F3NSOTQFaoiQEKji7Hm+o0u3IwemZjF23uU2/MWnejNPkAvklqAdCDf9OQ1q8A6CrIiYPIk6wsos3lecCQaSvntv4w0CxlLrxwn2Zpdvi08NyJLD6t3npJMgzaoj0z/AA=="
Dec 15 04:16:29 gbvpi-bedroom go-librespot[30718]: time="2025-12-15T04:16:29-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 04:16:29 gbvpi-bedroom go-librespot[30718]: time="2025-12-15T04:16:29-05:00" level=debug msg="completed keyexchange"
Dec 15 04:16:29 gbvpi-bedroom go-librespot[30718]: time="2025-12-15T04:16:29-05:00" level=debug msg="completed challenge"
Dec 15 04:16:29 gbvpi-bedroom go-librespot[30718]: time="2025-12-15T04:16:29-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 15 04:16:29 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 04:16:29 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 04:16:30 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:30 gbvpi-bedroom volumio[30072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:16:32 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18.
Dec 15 04:16:32 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:32 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:32 gbvpi-bedroom go-librespot[30739]: go-librespot daemon starting...
Dec 15 04:16:32 gbvpi-bedroom go-librespot[30740]: time="2025-12-15T04:16:32-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 04:16:32 gbvpi-bedroom go-librespot[30740]: time="2025-12-15T04:16:32-05:00" level=debug msg="app state loaded"
Dec 15 04:16:32 gbvpi-bedroom go-librespot[30740]: time="2025-12-15T04:16:32-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 04:16:32 gbvpi-bedroom go-librespot[30740]: time="2025-12-15T04:16:32-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 15 04:16:32 gbvpi-bedroom go-librespot[30740]: time="2025-12-15T04:16:32-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 04:16:32 gbvpi-bedroom go-librespot[30740]: time="2025-12-15T04:16:32-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 04:16:32 gbvpi-bedroom go-librespot[30740]: time="2025-12-15T04:16:32-05:00" level=info msg="zeroconf server listening on port 39547"
Dec 15 04:16:33 gbvpi-bedroom go-librespot[30740]: time="2025-12-15T04:16:33-05:00" level=debug msg="obtained new client token: AACgY5+p0uf8gvxU4/uynDXFPSVgYQtlTiAfKN9Z3s8LyAR/KFcnHNxHEGdILV+83rNuQYBrWQ5w+wsMupBstTqtyj1RajhrB+UqlByjTi0DH1fbB++F3hnQwkbIHEAob3nhGijNSBefPbrvQ/BzeBSYhMBziMztwYOc2SxlRulLU9TxRkOiERN506umrUDDnz6EZG76YZ+qBoGj1HxAtyfbHAcVpIBExURC0itYScyhPwYzgjtX1ko="
Dec 15 04:16:33 gbvpi-bedroom go-librespot[30740]: time="2025-12-15T04:16:33-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 04:16:33 gbvpi-bedroom go-librespot[30740]: time="2025-12-15T04:16:33-05:00" level=debug msg="completed keyexchange"
Dec 15 04:16:33 gbvpi-bedroom go-librespot[30740]: time="2025-12-15T04:16:33-05:00" level=debug msg="completed challenge"
Dec 15 04:16:33 gbvpi-bedroom go-librespot[30740]: time="2025-12-15T04:16:33-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 15 04:16:33 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 04:16:33 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 04:16:33 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:33 gbvpi-bedroom volumio[30072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:16:36 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19.
Dec 15 04:16:36 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:36 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:36 gbvpi-bedroom go-librespot[30747]: go-librespot daemon starting...
Dec 15 04:16:36 gbvpi-bedroom go-librespot[30748]: time="2025-12-15T04:16:36-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 04:16:36 gbvpi-bedroom go-librespot[30748]: time="2025-12-15T04:16:36-05:00" level=debug msg="app state loaded"
Dec 15 04:16:36 gbvpi-bedroom go-librespot[30748]: time="2025-12-15T04:16:36-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 04:16:36 gbvpi-bedroom go-librespot[30748]: time="2025-12-15T04:16:36-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 15 04:16:36 gbvpi-bedroom go-librespot[30748]: time="2025-12-15T04:16:36-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 04:16:36 gbvpi-bedroom go-librespot[30748]: time="2025-12-15T04:16:36-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 04:16:36 gbvpi-bedroom go-librespot[30748]: time="2025-12-15T04:16:36-05:00" level=info msg="zeroconf server listening on port 36879"
Dec 15 04:16:36 gbvpi-bedroom go-librespot[30748]: time="2025-12-15T04:16:36-05:00" level=debug msg="obtained new client token: AADRsXUlEYpWLhk/2189bLP4nUphKSuWkxep5WfL2fJPhcL3z2yZ1xC3DkbEzFDfqORnjPglEF0tXoo1IuzSBekJpuOHST+Zz6BYNdwaCko3/L06kxCnEXeWwJot8S8NMWUPzX5cSB8t9GBWYYOwA0i4zLXQhcaOofLAhg5MFKXb/g3nd8qFjHfI5ANS9xK266qed9xWqy8LkXJ7aOUgnh7hWa/apPdAEb94WG/ykqOwdt7e2wMYcljPcg=="
Dec 15 04:16:36 gbvpi-bedroom go-librespot[30748]: time="2025-12-15T04:16:36-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 04:16:36 gbvpi-bedroom go-librespot[30748]: time="2025-12-15T04:16:36-05:00" level=debug msg="connected to ap-gue1.spotify.com:443"
Dec 15 04:16:36 gbvpi-bedroom go-librespot[30748]: time="2025-12-15T04:16:36-05:00" level=debug msg="completed keyexchange"
Dec 15 04:16:36 gbvpi-bedroom go-librespot[30748]: time="2025-12-15T04:16:36-05:00" level=debug msg="completed challenge"
Dec 15 04:16:36 gbvpi-bedroom go-librespot[30748]: time="2025-12-15T04:16:36-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 15 04:16:36 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 04:16:36 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 04:16:36 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:36 gbvpi-bedroom volumio[30072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:16:37 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:38 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:39 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:39 gbvpi-bedroom volumio[30072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:16:39 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20.
Dec 15 04:16:39 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:40 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:40 gbvpi-bedroom go-librespot[30757]: go-librespot daemon starting...
Dec 15 04:16:40 gbvpi-bedroom go-librespot[30758]: time="2025-12-15T04:16:40-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 04:16:40 gbvpi-bedroom go-librespot[30758]: time="2025-12-15T04:16:40-05:00" level=debug msg="app state loaded"
Dec 15 04:16:40 gbvpi-bedroom go-librespot[30758]: time="2025-12-15T04:16:40-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 04:16:40 gbvpi-bedroom go-librespot[30758]: time="2025-12-15T04:16:40-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 15 04:16:40 gbvpi-bedroom go-librespot[30758]: time="2025-12-15T04:16:40-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 04:16:40 gbvpi-bedroom go-librespot[30758]: time="2025-12-15T04:16:40-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 04:16:40 gbvpi-bedroom go-librespot[30758]: time="2025-12-15T04:16:40-05:00" level=info msg="zeroconf server listening on port 43937"
Dec 15 04:16:40 gbvpi-bedroom go-librespot[30758]: time="2025-12-15T04:16:40-05:00" level=debug msg="obtained new client token: AAAHwN3mugiqdrFfmiWTMnTRWO6B6GGAgpAt67TP0OKiJOvOZWZzD3CK2yVWtWBbeP72qfk4NnziarY25nbX5alv07fXfE5RAS4qRvTQhlHnP0TdI/IHFaeQG+lyieP+gLBesYcx1FqQrqk03eFXuuyqQdxSB0uNeAfzj1I515/GNmjLtHenV98Et2jlVeOXQ/hqj93mO0fTQXnMEVkIAr98nglufcHljWSi/+thdGXPyWLygfqrA8U="
Dec 15 04:16:40 gbvpi-bedroom go-librespot[30758]: time="2025-12-15T04:16:40-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 04:16:40 gbvpi-bedroom go-librespot[30758]: time="2025-12-15T04:16:40-05:00" level=debug msg="completed keyexchange"
Dec 15 04:16:40 gbvpi-bedroom go-librespot[30758]: time="2025-12-15T04:16:40-05:00" level=debug msg="completed challenge"
Dec 15 04:16:40 gbvpi-bedroom go-librespot[30758]: time="2025-12-15T04:16:40-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 15 04:16:40 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 04:16:40 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 04:16:42 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:42 gbvpi-bedroom volumio[30072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:16:43 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21.
Dec 15 04:16:43 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:43 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:43 gbvpi-bedroom go-librespot[30779]: go-librespot daemon starting...
Dec 15 04:16:43 gbvpi-bedroom go-librespot[30782]: time="2025-12-15T04:16:43-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 04:16:43 gbvpi-bedroom go-librespot[30782]: time="2025-12-15T04:16:43-05:00" level=debug msg="app state loaded"
Dec 15 04:16:43 gbvpi-bedroom go-librespot[30782]: time="2025-12-15T04:16:43-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 04:16:43 gbvpi-bedroom go-librespot[30782]: time="2025-12-15T04:16:43-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 04:16:43 gbvpi-bedroom go-librespot[30782]: time="2025-12-15T04:16:43-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 04:16:43 gbvpi-bedroom go-librespot[30782]: time="2025-12-15T04:16:43-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 04:16:43 gbvpi-bedroom go-librespot[30782]: time="2025-12-15T04:16:43-05:00" level=info msg="zeroconf server listening on port 34397"
Dec 15 04:16:43 gbvpi-bedroom go-librespot[30782]: time="2025-12-15T04:16:43-05:00" level=debug msg="obtained new client token: AADZXJKKUIX+om1fypcSR8UhZ+hDFkDqUlXTDWVlsvTaTMCQwLWMyBxrM6KMw6vuhQoRzHI3B07+dmg6Bp18mHsPfgCqlWtGXQqOYlJW59yhgSNvGqN05Catjhnmli0IHd1Yyb+l0n8oXCJ/OwuXBHoEo9vOdtF95VuRbImOIQhM/SZ1zFPIKfSuirL3NYewU5ingh4lf/6eI8keylZEUe6GDXkQZPerl2LKiNTTA6PrPYcd1e4AQSKFnA=="
Dec 15 04:16:43 gbvpi-bedroom go-librespot[30782]: time="2025-12-15T04:16:43-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 04:16:43 gbvpi-bedroom go-librespot[30782]: time="2025-12-15T04:16:43-05:00" level=debug msg="completed keyexchange"
Dec 15 04:16:43 gbvpi-bedroom go-librespot[30782]: time="2025-12-15T04:16:43-05:00" level=debug msg="completed challenge"
Dec 15 04:16:43 gbvpi-bedroom go-librespot[30782]: time="2025-12-15T04:16:43-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 04:16:43 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 04:16:43 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 04:16:45 gbvpi-bedroom volumio[30072]: info: UPDATER: Scheduling automatic update
Dec 15 04:16:45 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStartTime
Dec 15 04:16:45 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStopTime
Dec 15 04:16:45 gbvpi-bedroom volumio[30072]: info: UPDATER: Auto update will take place at: Tue Dec 16 2025 03:14:55 GMT-0500 (Eastern Standard Time)
Dec 15 04:16:45 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:45 gbvpi-bedroom volumio[30072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:16:46 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22.
Dec 15 04:16:46 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:47 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:47 gbvpi-bedroom go-librespot[30792]: go-librespot daemon starting...
Dec 15 04:16:47 gbvpi-bedroom go-librespot[30793]: time="2025-12-15T04:16:47-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 04:16:47 gbvpi-bedroom go-librespot[30793]: time="2025-12-15T04:16:47-05:00" level=debug msg="app state loaded"
Dec 15 04:16:47 gbvpi-bedroom go-librespot[30793]: time="2025-12-15T04:16:47-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 04:16:47 gbvpi-bedroom go-librespot[30793]: time="2025-12-15T04:16:47-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]"
Dec 15 04:16:47 gbvpi-bedroom go-librespot[30793]: time="2025-12-15T04:16:47-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 04:16:47 gbvpi-bedroom go-librespot[30793]: time="2025-12-15T04:16:47-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 04:16:47 gbvpi-bedroom go-librespot[30793]: time="2025-12-15T04:16:47-05:00" level=info msg="zeroconf server listening on port 46545"
Dec 15 04:16:47 gbvpi-bedroom go-librespot[30793]: time="2025-12-15T04:16:47-05:00" level=debug msg="obtained new client token: AAC6RjBBz9qkt+VGNmblV4TADY4chdaYVZYphXYkXDIJSuU+LfJBZOcvk7GgsKCfG6a6URlagiJeD/J/t8JEZkQEdjhjUbC6nhrgh1+FW5+uRp3PNumhxCZuHKFxgGdTxOjnimv2fxmTaKeRPtjtTTT6S5QZpgukkpYDk60Tx6Lc9yc7FSjUV8sM6GA3Ijl+EO341n7GTSIPGTX/ZU13WtFVmeC2Q0TTVbPGutlFNtk1ly7/PjjBwo0yLA=="
Dec 15 04:16:47 gbvpi-bedroom go-librespot[30793]: time="2025-12-15T04:16:47-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 04:16:47 gbvpi-bedroom go-librespot[30793]: time="2025-12-15T04:16:47-05:00" level=debug msg="completed keyexchange"
Dec 15 04:16:47 gbvpi-bedroom go-librespot[30793]: time="2025-12-15T04:16:47-05:00" level=debug msg="completed challenge"
Dec 15 04:16:47 gbvpi-bedroom go-librespot[30793]: time="2025-12-15T04:16:47-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 04:16:47 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 04:16:47 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 04:16:47 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:47 gbvpi-bedroom volumio[30072]: info: Listing playlists
Dec 15 04:16:47 gbvpi-bedroom volumio[30072]: info: Listing playlists
Dec 15 04:16:48 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:48 gbvpi-bedroom volumio[30072]: info: Listing playlists
Dec 15 04:16:48 gbvpi-bedroom volumio[30072]: info: Listing playlists
Dec 15 04:16:48 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:48 gbvpi-bedroom volumio[30072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:16:50 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23.
Dec 15 04:16:50 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:50 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:50 gbvpi-bedroom go-librespot[30800]: go-librespot daemon starting...
Dec 15 04:16:50 gbvpi-bedroom go-librespot[30801]: time="2025-12-15T04:16:50-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 04:16:50 gbvpi-bedroom go-librespot[30801]: time="2025-12-15T04:16:50-05:00" level=debug msg="app state loaded"
Dec 15 04:16:50 gbvpi-bedroom go-librespot[30801]: time="2025-12-15T04:16:50-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 04:16:50 gbvpi-bedroom go-librespot[30801]: time="2025-12-15T04: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-gew1.spotify.com:80]"
Dec 15 04:16:50 gbvpi-bedroom go-librespot[30801]: time="2025-12-15T04: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 gew1-dealer.spotify.com:443]"
Dec 15 04:16:50 gbvpi-bedroom go-librespot[30801]: time="2025-12-15T04: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 gew1-spclient.spotify.com:443]"
Dec 15 04:16:50 gbvpi-bedroom go-librespot[30801]: time="2025-12-15T04:16:50-05:00" level=info msg="zeroconf server listening on port 40691"
Dec 15 04:16:51 gbvpi-bedroom go-librespot[30801]: time="2025-12-15T04:16:51-05:00" level=debug msg="obtained new client token: AABU6z8fbDcTZX/xZjGL9fUzLP9LcIb9knFHrGLECjjKNAHNurla//WimauHsHZcIoeOD84rWEgLTmw54G4IUay3aBrUM4UNs3uvSH8QIVzr4okJZ2cvxvZ1DP20xTGg34NU5J6m6eMcfgwepRrF0chkcKzAF/rhWdglXUNhl9QQRm49tUBodkJQMAImwM7zPrfcVgoSf2h0ojWdFT37X2tPI+2u9GlP2s8ke897cJAX9kMQEn8qxxE="
Dec 15 04:16:51 gbvpi-bedroom go-librespot[30801]: time="2025-12-15T04:16:51-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 04:16:51 gbvpi-bedroom go-librespot[30801]: time="2025-12-15T04:16:51-05:00" level=debug msg="completed keyexchange"
Dec 15 04:16:51 gbvpi-bedroom go-librespot[30801]: time="2025-12-15T04:16:51-05:00" level=debug msg="completed challenge"
Dec 15 04:16:51 gbvpi-bedroom go-librespot[30801]: time="2025-12-15T04:16:51-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 04:16:51 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 04:16:51 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 04:16:51 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:51 gbvpi-bedroom volumio[30072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:16:54 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24.
Dec 15 04:16:54 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:54 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:54 gbvpi-bedroom go-librespot[30824]: go-librespot daemon starting...
Dec 15 04:16:54 gbvpi-bedroom go-librespot[30825]: time="2025-12-15T04:16:54-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 04:16:54 gbvpi-bedroom go-librespot[30825]: time="2025-12-15T04:16:54-05:00" level=debug msg="app state loaded"
Dec 15 04:16:54 gbvpi-bedroom go-librespot[30825]: time="2025-12-15T04:16:54-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 04:16:54 gbvpi-bedroom go-librespot[30825]: time="2025-12-15T04:16:54-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 04:16:54 gbvpi-bedroom go-librespot[30825]: time="2025-12-15T04:16:54-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 04:16:54 gbvpi-bedroom go-librespot[30825]: time="2025-12-15T04:16:54-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 04:16:54 gbvpi-bedroom go-librespot[30825]: time="2025-12-15T04:16:54-05:00" level=info msg="zeroconf server listening on port 35337"
Dec 15 04:16:54 gbvpi-bedroom go-librespot[30825]: time="2025-12-15T04:16:54-05:00" level=debug msg="obtained new client token: AADMVSimerUSuazSEsBQRgkKdz+X6trrmgq8CWeWkS/50yPS7SDty0OpCgx3HxXPk1r0xLQY8UkSei20aMxlqoY9ZxUxm/Mc/5tfB53f4n9Me6wlEKrFJZxIMD3fIhAIl2Xd0HkWz7T3PpiVTHWqX5kUSN6zA0u4+4OQG3L74VRrIaS6xkqhmanpGldQMa1gKMogNqfncBqxbBA82e7iNOOjR2ODsqW/JpO6wQDDNCCuS57eL+UwinS12w=="
Dec 15 04:16:54 gbvpi-bedroom go-librespot[30825]: time="2025-12-15T04:16:54-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 04:16:54 gbvpi-bedroom go-librespot[30825]: time="2025-12-15T04:16:54-05:00" level=debug msg="completed keyexchange"
Dec 15 04:16:54 gbvpi-bedroom go-librespot[30825]: time="2025-12-15T04:16:54-05:00" level=debug msg="completed challenge"
Dec 15 04:16:54 gbvpi-bedroom go-librespot[30825]: time="2025-12-15T04: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 04:16:54 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 04:16:54 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 04:16:54 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:54 gbvpi-bedroom volumio[30072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:16:57 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:57 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25.
Dec 15 04:16:57 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:57 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:16:57 gbvpi-bedroom go-librespot[30833]: go-librespot daemon starting...
Dec 15 04:16:57 gbvpi-bedroom go-librespot[30834]: time="2025-12-15T04:16:57-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 04:16:57 gbvpi-bedroom go-librespot[30834]: time="2025-12-15T04:16:57-05:00" level=debug msg="app state loaded"
Dec 15 04:16:57 gbvpi-bedroom go-librespot[30834]: time="2025-12-15T04:16:57-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 04:16:57 gbvpi-bedroom volumio[30072]: info: Initializing connection to go-librespot Websocket
Dec 15 04:16:57 gbvpi-bedroom go-librespot[30834]: time="2025-12-15T04:16:57-05:00" level=debug msg="new websocket client"
Dec 15 04:16:57 gbvpi-bedroom volumio[30072]: info: Connection to go-librespot Websocket established
Dec 15 04:16:57 gbvpi-bedroom go-librespot[30834]: time="2025-12-15T04: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 15 04:16:57 gbvpi-bedroom go-librespot[30834]: time="2025-12-15T04:16:57-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 04:16:57 gbvpi-bedroom go-librespot[30834]: time="2025-12-15T04:16:57-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 04:16:57 gbvpi-bedroom go-librespot[30834]: time="2025-12-15T04:16:57-05:00" level=info msg="zeroconf server listening on port 45893"
Dec 15 04:16:58 gbvpi-bedroom go-librespot[30834]: time="2025-12-15T04:16:58-05:00" level=debug msg="obtained new client token: AAD/pKGhdGaJ0ikwaZMm8IxjOc6jZ7jdU6ARwa/9FTQ6AL4FCw2V9ItzqXJ9cxjDeKPHyedUS5XxkRnN8WTVbehPrveABGD9NEWeqiAibmMj3hZmquAVcie8JtKS3feFhU8d5twniJvvcSp+B9Q4Fm7zUW2xBN1fDPezON7ymeIBGYcjBGcJlIU1HDwb1QAvXGzbkaRdgIS5EhkUcVS6AwuTGQvmSPCZPYge/3tVliXT6N4Yi4yUMkU="
Dec 15 04:16:58 gbvpi-bedroom volumio[30072]: info: CoreCommandRouter::volumioGetState
Dec 15 04:16:58 gbvpi-bedroom go-librespot[30834]: time="2025-12-15T04:16:58-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 15 04:16:58 gbvpi-bedroom go-librespot[30834]: time="2025-12-15T04:16:58-05:00" level=debug msg="completed keyexchange"
Dec 15 04:16:58 gbvpi-bedroom go-librespot[30834]: time="2025-12-15T04:16:58-05:00" level=debug msg="completed challenge"
Dec 15 04:16:58 gbvpi-bedroom go-librespot[30834]: time="2025-12-15T04: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 04:16:58 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 04:16:58 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 04:16:58 gbvpi-bedroom volumio[30072]: info: Connection to go-librespot Websocket closed
Dec 15 04:17:00 gbvpi-bedroom volumio[30072]: info: Getting Spotify volume
Dec 15 04:17:00 gbvpi-bedroom volumio[30072]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 15 04:17:00 gbvpi-bedroom volumio[30072]: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 04:17:00 gbvpi-bedroom volumio[30072]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Dec 15 04:17:00 gbvpi-bedroom volumio[30072]: errno: -111,
Dec 15 04:17:00 gbvpi-bedroom volumio[30072]: code: 'ECONNREFUSED',
Dec 15 04:17:00 gbvpi-bedroom volumio[30072]: syscall: 'connect',
Dec 15 04:17:00 gbvpi-bedroom volumio[30072]: address: '127.0.0.1',
Dec 15 04:17:00 gbvpi-bedroom volumio[30072]: port: 9879,
Dec 15 04:17:00 gbvpi-bedroom volumio[30072]: response: undefined
Dec 15 04:17:00 gbvpi-bedroom volumio[30072]: }
Dec 15 04:17:00 gbvpi-bedroom volumio[30072]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 15 04:17:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26.
Dec 15 04:17:01 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:17:01 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 04:17:01 gbvpi-bedroom go-librespot[30853]: go-librespot daemon starting...
Dec 15 04:17:01 gbvpi-bedroom go-librespot[30854]: time="2025-12-15T04:17:01-05:00" level=info msg="running go-librespot 0.4.0"
Dec 15 04:17:01 gbvpi-bedroom go-librespot[30854]: time="2025-12-15T04:17:01-05:00" level=debug msg="app state loaded"
Dec 15 04:17:01 gbvpi-bedroom go-librespot[30854]: time="2025-12-15T04:17:01-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 04:17:01 gbvpi-bedroom sudo[30862]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 04:16'
Dec 15 04:17:01 gbvpi-bedroom sudo[30862]: 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"