Dec 12 17:46:01 gbvpi-bedroom volumio[11096]: info: go-librespot daemon successfully initialized
Dec 12 17:46:01 gbvpi-bedroom volumio[11096]: info: Discovery: Browse raised the following error Error: dns service error: unknown
Dec 12 17:46:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Dec 12 17:46:01 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:01 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:01 gbvpi-bedroom go-librespot[11356]: go-librespot daemon starting...
Dec 12 17:46:01 gbvpi-bedroom go-librespot[11357]: time="2025-12-12T17:46:01-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:46:01 gbvpi-bedroom go-librespot[11357]: time="2025-12-12T17:46:01-05:00" level=debug msg="app state loaded"
Dec 12 17:46:01 gbvpi-bedroom go-librespot[11357]: time="2025-12-12T17:46:01-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:46:01 gbvpi-bedroom sudo[11365]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 12 17:46:01 gbvpi-bedroom sudo[11365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:01 gbvpi-bedroom sudo[11367]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 12 17:46:01 gbvpi-bedroom sudo[11367]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:01 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Dec 12 17:46:01 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully.
Dec 12 17:46:01 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Dec 12 17:46:01 gbvpi-bedroom go-librespot[11357]: time="2025-12-12T17:46: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 12 17:46:01 gbvpi-bedroom go-librespot[11357]: time="2025-12-12T17:46:01-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 12 17:46:01 gbvpi-bedroom go-librespot[11357]: time="2025-12-12T17:46:01-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 12 17:46:01 gbvpi-bedroom go-librespot[11357]: time="2025-12-12T17:46:01-05:00" level=info msg="zeroconf server listening on port 36663"
Dec 12 17:46:02 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Dec 12 17:46:02 gbvpi-bedroom sudo[11367]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:02 gbvpi-bedroom sudo[11365]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:02 gbvpi-bedroom mpd_monitor.sh[11370]: MPD Monitor Service: Starting MPD Monitor Service
Dec 12 17:46:02 gbvpi-bedroom volumio[11096]: info: Successfully started MPD Monitor
Dec 12 17:46:02 gbvpi-bedroom volumio[11096]: info: Successfully started MPD Monitor
Dec 12 17:46:02 gbvpi-bedroom go-librespot[11357]: time="2025-12-12T17:46:02-05:00" level=debug msg="obtained new client token: AAD314uBwi7tZnCvM5ImmYj7u3k8fwtQYkRresaQX+sKM32vXZeKov5T//ZAK3FEx/qUANwT4NxpbpV8xtrfl2UcbYBuzuxgbdGujuO6+XEMCqIUdgQMLMnhi+7zfa+QIzAib58KOqzkaR4ttLVIW0GL0bfEghyV0G6yupq9vUBvMWZQwgyIByMmVr7BzwVMY6W7Kblb7ZWBBps5yY3P0HjcoeJYnNki7E8ouIJuDXWPBd/ECc7aC9U="
Dec 12 17:46:02 gbvpi-bedroom go-librespot[11357]: time="2025-12-12T17:46:02-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 12 17:46:02 gbvpi-bedroom go-librespot[11357]: time="2025-12-12T17:46:02-05:00" level=debug msg="completed keyexchange"
Dec 12 17:46:02 gbvpi-bedroom go-librespot[11357]: time="2025-12-12T17:46:02-05:00" level=debug msg="completed challenge"
Dec 12 17:46:02 gbvpi-bedroom go-librespot[11357]: time="2025-12-12T17:46:02-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 12 17:46:02 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:46:02 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:46:03 gbvpi-bedroom sudo[11393]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Dec 12 17:46:03 gbvpi-bedroom sudo[11393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:03 gbvpi-bedroom sudo[11393]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:03 gbvpi-bedroom sudo[11395]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 12 17:46:03 gbvpi-bedroom sudo[11395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:03 gbvpi-bedroom sudo[11395]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:03 gbvpi-bedroom sudo[11398]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Dec 12 17:46:03 gbvpi-bedroom sudo[11398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:03 gbvpi-bedroom sudo[11398]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:03 gbvpi-bedroom volumio[11096]: info: Upmpdcli Daemon Started
Dec 12 17:46:03 gbvpi-bedroom volumio[11096]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Dec 12 17:46:04 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:46:04 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:46:04 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:46:04 gbvpi-bedroom volumio[11096]: info: CorePlayQueue::getTrack 0
Dec 12 17:46:04 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:46:04 gbvpi-bedroom volumio[11096]: info: CorePlayQueue::getTrack 0
Dec 12 17:46:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Dec 12 17:46:05 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:05 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:05 gbvpi-bedroom go-librespot[11401]: go-librespot daemon starting...
Dec 12 17:46:05 gbvpi-bedroom go-librespot[11402]: time="2025-12-12T17:46:05-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:46:05 gbvpi-bedroom go-librespot[11402]: time="2025-12-12T17:46:05-05:00" level=debug msg="app state loaded"
Dec 12 17:46:05 gbvpi-bedroom go-librespot[11402]: time="2025-12-12T17:46:05-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:46:05 gbvpi-bedroom go-librespot[11402]: time="2025-12-12T17:46: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 12 17:46:05 gbvpi-bedroom go-librespot[11402]: time="2025-12-12T17:46: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 12 17:46:05 gbvpi-bedroom go-librespot[11402]: time="2025-12-12T17:46: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 12 17:46:05 gbvpi-bedroom go-librespot[11402]: time="2025-12-12T17:46:05-05:00" level=info msg="zeroconf server listening on port 40349"
Dec 12 17:46:05 gbvpi-bedroom go-librespot[11402]: time="2025-12-12T17:46:05-05:00" level=debug msg="obtained new client token: AAC79NX8wHVNhjh3siRwLL6IXUOOJ9ES/D2zqkpsVMXbl7MGKZFtQFIZCaUo2+GI8UvvAm/FYEgKW6RZIVcYGSETxAPiyczCcAhVZBXeIlHSLTmxG3LkqD6ftaFa8t6ulda7CH7Yg0Uuz9qGryoDf6AiOaWVQtNY4Ico20TjkzlJzI0GRR9f/OOR3AhEJ2uOwnLlUdZg2MpUh34JN4K8Zn91hWLSjWnLMM/TygpEEEVOnOURCGsOvznoAQ=="
Dec 12 17:46:05 gbvpi-bedroom go-librespot[11402]: time="2025-12-12T17:46:05-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 12 17:46:05 gbvpi-bedroom go-librespot[11402]: time="2025-12-12T17:46:05-05:00" level=debug msg="completed keyexchange"
Dec 12 17:46:05 gbvpi-bedroom go-librespot[11402]: time="2025-12-12T17:46:05-05:00" level=debug msg="completed challenge"
Dec 12 17:46:05 gbvpi-bedroom go-librespot[11402]: time="2025-12-12T17:46: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 12 17:46:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:46:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: Adding plugin bluetooth to MyMusic Plugins
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: Adding plugin multiroom to MyMusic Plugins
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: Adding plugin metavolumio to MyMusic Plugins
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: Adding plugin cd_controller to MyMusic Plugins
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: Adding plugin qobuzconnect to MyMusic Plugins
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: Adding plugin smart_inputs to MyMusic Plugins
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: Adding plugin tidalconnect to MyMusic Plugins
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: Starting MyVolumio Remote Streaming Endpoints
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: MyVolumio login type: Token
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Dec 12 17:46:07 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Dec 12 17:46:08 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Dec 12 17:46:08 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Dec 12 17:46:08 gbvpi-bedroom volumio[11096]: info: Streaming services startup
Dec 12 17:46:08 gbvpi-bedroom volumio[11096]: info: Starting Streaming Daemon
Dec 12 17:46:08 gbvpi-bedroom sudo[11410]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Dec 12 17:46:08 gbvpi-bedroom sudo[11410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:08 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Dec 12 17:46:08 gbvpi-bedroom sudo[11410]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:08 gbvpi-bedroom volumio[11096]: error: Cannot start Volumio Streaming Daemon
Dec 12 17:46:08 gbvpi-bedroom volumio[11096]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Dec 12 17:46:08 gbvpi-bedroom volumio[11096]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Dec 12 17:46:08 gbvpi-bedroom volumio[11096]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Dec 12 17:46:08 gbvpi-bedroom volumio[11096]: info: MyVolumio token set successfully
Dec 12 17:46:08 gbvpi-bedroom volumio[11096]: info: MYVOLUMIO: Adding device
Dec 12 17:46:08 gbvpi-bedroom volumio[11096]: info: MYVOLUMIO: Evaluating Server
Dec 12 17:46:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Dec 12 17:46:08 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:09 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:09 gbvpi-bedroom go-librespot[11418]: go-librespot daemon starting...
Dec 12 17:46:09 gbvpi-bedroom go-librespot[11421]: time="2025-12-12T17:46:09-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:46:09 gbvpi-bedroom go-librespot[11421]: time="2025-12-12T17:46:09-05:00" level=debug msg="app state loaded"
Dec 12 17:46:09 gbvpi-bedroom go-librespot[11421]: time="2025-12-12T17:46:09-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: info: MyVolumio Plan changed: premium
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Subscribed plan changed to premium
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: info: Removing browser output: myVolumio user plan is not superstar
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: info: Removing audio output:
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: info: MYVOLUMIO: Adding device
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: info: MYVOLUMIO: Evaluating Server
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: info: Remote config written successfully
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: info: Starting Tunnel 1
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: info: Starting Tunnel Connection Checker
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: info: Completed starting MyVolumio Plugin
Dec 12 17:46:09 gbvpi-bedroom go-librespot[11421]: time="2025-12-12T17:46: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 12 17:46:09 gbvpi-bedroom go-librespot[11421]: time="2025-12-12T17:46: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 12 17:46:09 gbvpi-bedroom go-librespot[11421]: time="2025-12-12T17:46: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 12 17:46:09 gbvpi-bedroom go-librespot[11421]: time="2025-12-12T17:46:09-05:00" level=info msg="zeroconf server listening on port 41905"
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: info: MYVolumio Device enabled
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins...
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: info: MyVolumio status changed
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: info: Streaming services startup
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: info: Starting Streaming Daemon
Dec 12 17:46:09 gbvpi-bedroom sudo[11463]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Dec 12 17:46:09 gbvpi-bedroom sudo[11463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:09 gbvpi-bedroom go-librespot[11421]: time="2025-12-12T17:46:09-05:00" level=debug msg="obtained new client token: AAB4tO/ReVAVLe1eouQ/WRdnzgdx8r/ncab7Gkx3B+CkPH5QTnvTLG8+PYHpWkDAksmjtxyqJAVmksNg9v6o7L6kGl8hWl6TcjNEeSep66P4p3CWT+FwcpJ7u+ARDtGoQ5k8S1YsHMRZEVYQXSlAFD3VEZNqZlxJebJ81mDgFyIljUR4sMaezefP9iigCCZB78gGAYDL8A//7K1qx9XEIqHRWnaO+etODw9+zIs4vWCzkS9AW23D39cWVg=="
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"...
Dec 12 17:46:09 gbvpi-bedroom sudo[11463]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:09 gbvpi-bedroom go-librespot[11421]: time="2025-12-12T17:46:09-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 12 17:46:09 gbvpi-bedroom go-librespot[11421]: time="2025-12-12T17:46:09-05:00" level=debug msg="completed keyexchange"
Dec 12 17:46:09 gbvpi-bedroom go-librespot[11421]: time="2025-12-12T17:46:09-05:00" level=debug msg="completed challenge"
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart
Dec 12 17:46:09 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Loading plugin "multiroom"...
Dec 12 17:46:09 gbvpi-bedroom go-librespot[11421]: time="2025-12-12T17:46: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 12 17:46:09 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:46:09 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom
Dec 12 17:46:10 gbvpi-bedroom sudo[11467]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom
Dec 12 17:46:10 gbvpi-bedroom sudo[11467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:10 gbvpi-bedroom sudo[11467]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: MRS: MultiRoom plugin initialized
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: MRS: STOPPING SNAPCLIENT
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: MRS: Snap server stop
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: MRS: STOPPING volumioStreaming
Dec 12 17:46:10 gbvpi-bedroom sudo[11484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient
Dec 12 17:46:10 gbvpi-bedroom sudo[11484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:10 gbvpi-bedroom sudo[11486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver
Dec 12 17:46:10 gbvpi-bedroom sudo[11486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"...
Dec 12 17:46:10 gbvpi-bedroom sudo[11488]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming
Dec 12 17:46:10 gbvpi-bedroom sudo[11488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Loading plugin "manifestui"...
Dec 12 17:46:10 gbvpi-bedroom sudo[11491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/*
Dec 12 17:46:10 gbvpi-bedroom sudo[11491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"...
Dec 12 17:46:10 gbvpi-bedroom sudo[11491]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"...
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"...
Dec 12 17:46:10 gbvpi-bedroom sudo[11484]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio
Dec 12 17:46:10 gbvpi-bedroom sudo[11486]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Loading plugin "tidal"...
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Loading plugin "qobuz"...
Dec 12 17:46:10 gbvpi-bedroom sudo[11488]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"...
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"...
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Preparing to generate the ALSA configuration file
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Setting Geolocation for MyVolumio to us4
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Reading ALSA contributions from plugins.
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Setting Geolocation for MyVolumio to us1
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: MRS: Removed streaming files
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: MRS: volumioStreaming STOPPED
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: MRS: SNAPSERVER STOPPED
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: MRS: SNAPCLIENT STOPPED
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: error: Cannot start Volumio Streaming Daemon
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Asound.conf file written
Dec 12 17:46:10 gbvpi-bedroom sudo[11498]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf
Dec 12 17:46:10 gbvpi-bedroom sudo[11498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:10 gbvpi-bedroom sudo[11498]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Output device has changed, restarting MPD
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Output device has changed, restarting Shairport Sync
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 12 17:46:10 gbvpi-bedroom sudo[11504]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 12 17:46:10 gbvpi-bedroom sudo[11504]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:10 gbvpi-bedroom sudo[11504]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 12 17:46:10 gbvpi-bedroom sudo[11506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 12 17:46:10 gbvpi-bedroom sudo[11506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: ------------------------------------ BT MESSAGE: [FUNC] onStart
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready.
Dec 12 17:46:10 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon...
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: MRS: Pushing multiroomSync output for this device
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: MRS: Pushing multiroomSync output
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Adding audio output:
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Adding audio output:
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Dec 12 17:46:10 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully.
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 12 17:46:10 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon.
Dec 12 17:46:10 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.906s CPU time.
Dec 12 17:46:10 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully.
Dec 12 17:46:10 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Dec 12 17:46:10 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio
Dec 12 17:46:10 gbvpi-bedroom bluetoothd[763]: Path / reserved for Adv Monitor app :1.49917
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Adding METAVOLUMIO REST API Endpoints
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Preparing CD Folders
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Adding CD REST API Endpoints
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Starting UDEV Watcher for CD
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: Detecting CD presence with UDEV
Dec 12 17:46:10 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices
Dec 12 17:46:10 gbvpi-bedroom bluetoothd[763]: Adv Monitor app :1.49917 disconnected from D-Bus
Dec 12 17:46:10 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Dec 12 17:46:10 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon...
Dec 12 17:46:10 gbvpi-bedroom sudo[11524]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Dec 12 17:46:10 gbvpi-bedroom sudo[11524]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Dec 12 17:46:10 gbvpi-bedroom sudo[11524]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:12 gbvpi-bedroom mpd[11526]: 2025-12-12T17:46:11 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Dec 12 17:46:12 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon.
Dec 12 17:46:12 gbvpi-bedroom sudo[11506]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Dec 12 17:46:12 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:12 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:12 gbvpi-bedroom go-librespot[11529]: go-librespot daemon starting...
Dec 12 17:46:12 gbvpi-bedroom go-librespot[11530]: time="2025-12-12T17:46:12-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:46:12 gbvpi-bedroom go-librespot[11530]: time="2025-12-12T17:46:12-05:00" level=debug msg="app state loaded"
Dec 12 17:46:12 gbvpi-bedroom go-librespot[11530]: time="2025-12-12T17:46:12-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:46:12 gbvpi-bedroom go-librespot[11530]: time="2025-12-12T17:46: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 12 17:46:12 gbvpi-bedroom go-librespot[11530]: time="2025-12-12T17:46:12-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 12 17:46:12 gbvpi-bedroom go-librespot[11530]: time="2025-12-12T17:46:12-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 12 17:46:12 gbvpi-bedroom go-librespot[11530]: time="2025-12-12T17:46:12-05:00" level=info msg="zeroconf server listening on port 42007"
Dec 12 17:46:13 gbvpi-bedroom go-librespot[11530]: time="2025-12-12T17:46:13-05:00" level=debug msg="obtained new client token: AAAkpWo7W/OrX+qCtzzRn08opKVOKhbvnth24/juM6U5jUIgPJGmIjD6I79kbTDXFNH8B22ZvtDXJoLu+TiKTM47jCVaxFnZP6eN9lQSd0ykZ8yga9awQBXc8Qmf7mkKbiS1xPN666Ju6pasxsVPztg4/YS3Fk3ZxnEKFYFiGIx6VD/sq2Of9vMefC1foXvu9fMRMx2MppnisnJoB8ShmSoaZ4AKXnWH6hTJZj8YBP8gEC4Lzak34c0="
Dec 12 17:46:13 gbvpi-bedroom go-librespot[11530]: time="2025-12-12T17:46:13-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 12 17:46:13 gbvpi-bedroom go-librespot[11530]: time="2025-12-12T17:46:13-05:00" level=debug msg="completed keyexchange"
Dec 12 17:46:13 gbvpi-bedroom go-librespot[11530]: time="2025-12-12T17:46:13-05:00" level=debug msg="completed challenge"
Dec 12 17:46:13 gbvpi-bedroom go-librespot[11530]: time="2025-12-12T17:46: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 12 17:46:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:46:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: warn: [cd-plugin] cdspeedctl: device or media not ready
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: Adding inputs REST Endpoints
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: Scanning Audio Inputs
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: Checking against Known Cards name
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: Adding Server instance for streaming
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: error: Hi Res Audio Failed Login: Missing Login Data
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: Adding HIGHRESAUDIO REST API Endpoints
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect
Dec 12 17:46:15 gbvpi-bedroom sudo[11556]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: QobuzConnect: Starting Qobuz Connect socket and service
Dec 12 17:46:15 gbvpi-bedroom sudo[11556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: Adding TIDAL REST API Endpoints
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: Stopping AccessToken refresher cron for QOBUZ
Dec 12 17:46:15 gbvpi-bedroom systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service...
Dec 12 17:46:15 gbvpi-bedroom sudo[11563]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service
Dec 12 17:46:15 gbvpi-bedroom sudo[11563]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:15 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully.
Dec 12 17:46:15 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service.
Dec 12 17:46:15 gbvpi-bedroom sudo[11556]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: AccessToken refresher cron started for QOBUZ
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: Adding QOBUZ REST API Endpoints
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: Updating MyVolumio device info
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: Updating MyVolumio device info
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 12 17:46:15 gbvpi-bedroom sudo[11563]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: MRS: Getting audio outputs on start
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: MRS: Requesting all other devices output
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:46:15 gbvpi-bedroom sudo[11566]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service
Dec 12 17:46:15 gbvpi-bedroom sudo[11566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:15 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service...
Dec 12 17:46:15 gbvpi-bedroom qobuz-connect[10947]: 20251212 17:46:15.913 [10947.10947] INFO SampleApp: Stopping Local configuration server
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: Successfully Added MyVolumio device
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: Successfully Added MyVolumio device
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: MPD Permissions set
Dec 12 17:46:15 gbvpi-bedroom sudo[11569]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service
Dec 12 17:46:15 gbvpi-bedroom sudo[11569]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:15 gbvpi-bedroom sudo[11569]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:46:15 gbvpi-bedroom volumio[11096]: info: CorePlayQueue::getTrack 0
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioStop
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: CoreStateMachine::stop
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: error: updateQueue error: null
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: Listing playlists
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: Listing playlists
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: Listing playlists
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: Listing playlists
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: MRS: Found cast device: SmartTV-4K-fe72c264393a59c76d38e27b8168114d
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: Adding audio output:
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: Starting Shairport Sync
Dec 12 17:46:16 gbvpi-bedroom sudo[11584]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service
Dec 12 17:46:16 gbvpi-bedroom sudo[11584]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: MRS: Found cast device: Google-Home-Mini-f209fa314cb426d40a59bcf66354ddc9
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: Adding audio output:
Dec 12 17:46:16 gbvpi-bedroom sudo[11587]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 12 17:46:16 gbvpi-bedroom sudo[11587]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:16 gbvpi-bedroom autossh[10955]: received signal to exit (15)
Dec 12 17:46:16 gbvpi-bedroom systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel...
Dec 12 17:46:16 gbvpi-bedroom systemd[1]: sshtunnel.service: Deactivated successfully.
Dec 12 17:46:16 gbvpi-bedroom systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel.
Dec 12 17:46:16 gbvpi-bedroom systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel.
Dec 12 17:46:16 gbvpi-bedroom sudo[11584]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: Remote SSH Started
Dec 12 17:46:16 gbvpi-bedroom autossh[11590]: port set to 0, monitoring disabled
Dec 12 17:46:16 gbvpi-bedroom autossh[11590]: starting ssh (count 1)
Dec 12 17:46:16 gbvpi-bedroom autossh[11590]: ssh child pid is 11593
Dec 12 17:46:16 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 12 17:46:16 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 12 17:46:16 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 12 17:46:16 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.634s CPU time.
Dec 12 17:46:16 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 12 17:46:16 gbvpi-bedroom sudo[11587]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: Shairport-Sync Started
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: 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 12 17:46:16 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:46:16 gbvpi-bedroom volumiossh-tunnel[11593]: Warning: Permanently added '[us1.myvolumio.org]:2222' (RSA) to the list of known hosts.
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status'
Dec 12 17:46:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Dec 12 17:46:16 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: Successfully Updated MyVolumio device
Dec 12 17:46:16 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: Successfully Updated MyVolumio device
Dec 12 17:46:16 gbvpi-bedroom go-librespot[11609]: go-librespot daemon starting...
Dec 12 17:46:16 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully.
Dec 12 17:46:16 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service.
Dec 12 17:46:16 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service.
Dec 12 17:46:16 gbvpi-bedroom sudo[11566]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:16 gbvpi-bedroom go-librespot[11610]: time="2025-12-12T17:46:16-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:46:16 gbvpi-bedroom go-librespot[11610]: time="2025-12-12T17:46:16-05:00" level=debug msg="app state loaded"
Dec 12 17:46:16 gbvpi-bedroom go-librespot[11610]: time="2025-12-12T17:46:16-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: Executing endpoint qc_getconfig
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig
Dec 12 17:46:16 gbvpi-bedroom qobuz-connect[11611]: 20251212 17:46:16.600 [11611.11611] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket
Dec 12 17:46:16 gbvpi-bedroom qobuz-connect[11611]: 20251212 17:46:16.604 [11611.11611] INFO VolumeManager: [0xbab588]: Setting new playback volume: 75
Dec 12 17:46:16 gbvpi-bedroom qobuz-connect[11611]: 20251212 17:46:16.604 [11611.11611] INFO VolumeManager: [0xbab588]: Setting new mute state: 0
Dec 12 17:46:16 gbvpi-bedroom qobuz-connect[11611]: 20251212 17:46:16.604 [11611.11611] INFO QobuzConnect: [0xbabf58]: Client initialized!
Dec 12 17:46:16 gbvpi-bedroom qobuz-connect[11611]: 20251212 17:46:16.604 [11611.11611] INFO SampleApp: Starting Avahi advertising, name: GBVPi-Bedroom, service name: _qobuz-connect._tcp
Dec 12 17:46:16 gbvpi-bedroom qobuz-connect[11611]: 20251212 17:46:16.615 [11611.11611] INFO LocalConfigManager: [0xbaae68]: Starting Local Configuration server
Dec 12 17:46:16 gbvpi-bedroom qobuz-connect[11611]: 20251212 17:46:16.615 [11611.11611] INFO SampleApp: Starting Local configuration server
Dec 12 17:46:16 gbvpi-bedroom qobuz-connect[11611]: 20251212 17:46:16.616 [11611.11611] INFO SampleApp: Connected to UNIX socket client 0xb95818
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object]
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: QobuzConnect: QOBUZ Connect daemon connected
Dec 12 17:46:16 gbvpi-bedroom go-librespot[11610]: time="2025-12-12T17:46: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 12 17:46:16 gbvpi-bedroom go-librespot[11610]: time="2025-12-12T17:46:16-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 12 17:46:16 gbvpi-bedroom go-librespot[11610]: time="2025-12-12T17:46:16-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 12 17:46:16 gbvpi-bedroom go-librespot[11610]: time="2025-12-12T17:46:16-05:00" level=info msg="zeroconf server listening on port 45899"
Dec 12 17:46:16 gbvpi-bedroom qobuz-connect[11611]: 20251212 17:46:16.750 [11611.11611] INFO SampleApp: Playback volume changed: 75
Dec 12 17:46:16 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:46:16 gbvpi-bedroom go-librespot[11610]: time="2025-12-12T17:46:16-05:00" level=debug msg="obtained new client token: AAAcSyUvwF2Bh3lZ4/xCQ5/00uxas9o2deCmoAQb9eTXf6i/sX+oPqVZnfIPrpK2DenNWmWN2dgTvHXcemmNVKqAyMaA04/+vyV6TlLFIzcM0IchauZ/OoPzPeQRey0mwLP5pcGjpbxYaRPJxa6SndDKMEQ+shvKcxaFjDp5By9tkBLNEJRe4X6qIN8kDhrtNaC/qn3MRf6T4w17B6HpLv557MKXWl6sTPfNuXf/+J4ItfCvAvQtUqzHlg=="
Dec 12 17:46:16 gbvpi-bedroom go-librespot[11610]: time="2025-12-12T17:46:16-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 12 17:46:16 gbvpi-bedroom go-librespot[11610]: time="2025-12-12T17:46:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:443"
Dec 12 17:46:16 gbvpi-bedroom go-librespot[11610]: time="2025-12-12T17:46:16-05:00" level=debug msg="completed keyexchange"
Dec 12 17:46:16 gbvpi-bedroom go-librespot[11610]: time="2025-12-12T17:46:16-05:00" level=debug msg="completed challenge"
Dec 12 17:46:17 gbvpi-bedroom go-librespot[11610]: time="2025-12-12T17:46:17-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 12 17:46:17 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:46:17 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:46:18 gbvpi-bedroom volumio[11096]: info: TidalConnect service stoped!
Dec 12 17:46:18 gbvpi-bedroom volumio[11096]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect
Dec 12 17:46:18 gbvpi-bedroom volumio[11096]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect
Dec 12 17:46:18 gbvpi-bedroom sudo[11633]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service
Dec 12 17:46:18 gbvpi-bedroom sudo[11633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:18 gbvpi-bedroom sudo[11637]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 12 17:46:18 gbvpi-bedroom sudo[11637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 12 17:46:18 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:46:18 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:46:19 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service.
Dec 12 17:46:19 gbvpi-bedroom sudo[11633]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:19 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Dec 12 17:46:19 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully.
Dec 12 17:46:19 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Dec 12 17:46:19 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Dec 12 17:46:19 gbvpi-bedroom mpd_monitor.sh[11641]: MPD Monitor Service: Starting MPD Monitor Service
Dec 12 17:46:19 gbvpi-bedroom sudo[11637]: pam_unix(sudo:session): session closed for user root
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: Successfully started MPD Monitor
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: Executing endpoint tc_getconfig
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig
Dec 12 17:46:19 gbvpi-bedroom vtcs[11639]: STARTING TidalConnect services, version: 1.5.2.56
Dec 12 17:46:19 gbvpi-bedroom vtcs[11639]: STARTED TidalConnect services.
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: Executing endpoint tc_connect
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: Connecting to TidalConnect
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::servicePushState
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: CoreStateMachine::pushState
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioPushState
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: MRS: Pushing multiroomSync output update for this device
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: MRS: Pushing multiroomSync output
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: CorePlayQueue::getTrack 0
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::servicePushState
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: CoreStateMachine::pushState
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioPushState
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: MRS: Pushing multiroomSync output update for this device
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: MRS: Pushing multiroomSync output
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: CorePlayQueue::getTrack 0
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect
Dec 12 17:46:19 gbvpi-bedroom volumio[11096]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status'
Dec 12 17:46:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Dec 12 17:46:20 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:20 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:20 gbvpi-bedroom go-librespot[11659]: go-librespot daemon starting...
Dec 12 17:46:20 gbvpi-bedroom go-librespot[11660]: time="2025-12-12T17:46:20-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:46:20 gbvpi-bedroom go-librespot[11660]: time="2025-12-12T17:46:20-05:00" level=debug msg="app state loaded"
Dec 12 17:46:20 gbvpi-bedroom go-librespot[11660]: time="2025-12-12T17:46:20-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:46:20 gbvpi-bedroom go-librespot[11660]: time="2025-12-12T17:46: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 12 17:46:20 gbvpi-bedroom go-librespot[11660]: time="2025-12-12T17:46: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 12 17:46:20 gbvpi-bedroom go-librespot[11660]: time="2025-12-12T17:46: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 12 17:46:20 gbvpi-bedroom go-librespot[11660]: time="2025-12-12T17:46:20-05:00" level=info msg="zeroconf server listening on port 42497"
Dec 12 17:46:20 gbvpi-bedroom go-librespot[11660]: time="2025-12-12T17:46:20-05:00" level=debug msg="obtained new client token: AABoHj9o2JnR7p2IUyIg78HrT6e5nXliCggzUmd5TNIPR2wmwc78v2M/g8BisPx9jCjBdRgaXZLxSemiliwQCLcoCGlxtmcNi6K6AurvOJpABWSSvoY+7R+paG3QvwfIskHkgPMiSeQ8xZJTcUgams9P0B/6vQLGngzNgr2A54eM35gCDi3pC+NsRp7oJYe14x9PFwPxiYds57SBQ8o7k5iPWKBOORm3BmD0ex6rzjS3khdVZOIeKI06Qg=="
Dec 12 17:46:20 gbvpi-bedroom go-librespot[11660]: time="2025-12-12T17:46:20-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 12 17:46:20 gbvpi-bedroom go-librespot[11660]: time="2025-12-12T17:46:20-05:00" level=debug msg="completed keyexchange"
Dec 12 17:46:20 gbvpi-bedroom go-librespot[11660]: time="2025-12-12T17:46:20-05:00" level=debug msg="completed challenge"
Dec 12 17:46:20 gbvpi-bedroom go-librespot[11660]: time="2025-12-12T17:46: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 12 17:46:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:46:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:46:21 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:46:21 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:46:22 gbvpi-bedroom volumio[11096]: info: TidalConnect service started!
Dec 12 17:46:22 gbvpi-bedroom volumio[11096]: [Metrics] CommandRouter: 29s 479.03ms
Dec 12 17:46:22 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumiosetStartupVolume
Dec 12 17:46:22 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 12 17:46:22 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 12 17:46:22 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::Close All Modals sent
Dec 12 17:46:22 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::Close All Modals sent
Dec 12 17:46:22 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Dec 12 17:46:22 gbvpi-bedroom volumio[11096]: 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 12 17:46:22 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:46:23 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Dec 12 17:46:23 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Dec 12 17:46:23 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Dec 12 17:46:23 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Dec 12 17:46:23 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:23 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:23 gbvpi-bedroom go-librespot[11671]: go-librespot daemon starting...
Dec 12 17:46:23 gbvpi-bedroom go-librespot[11686]: time="2025-12-12T17:46:23-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:46:23 gbvpi-bedroom go-librespot[11686]: time="2025-12-12T17:46:23-05:00" level=debug msg="app state loaded"
Dec 12 17:46:23 gbvpi-bedroom go-librespot[11686]: time="2025-12-12T17:46:23-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:46:23 gbvpi-bedroom go-librespot[11686]: time="2025-12-12T17:46: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-gae2.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 12 17:46:23 gbvpi-bedroom go-librespot[11686]: time="2025-12-12T17:46:23-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 12 17:46:23 gbvpi-bedroom go-librespot[11686]: time="2025-12-12T17:46:23-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 12 17:46:23 gbvpi-bedroom go-librespot[11686]: time="2025-12-12T17:46:23-05:00" level=info msg="zeroconf server listening on port 34291"
Dec 12 17:46:24 gbvpi-bedroom go-librespot[11686]: time="2025-12-12T17:46:24-05:00" level=debug msg="obtained new client token: AAA5ln70yLUOw5qbFCb+aIh3cVfhBMfmzULtmil329FN82B1hAQEJW06i2fFzQWJB6xoYm1FH9CbNgBDWu6WVcEwWVjpYb6qIlgJsIoJ8b9B1XQCj2UEIgv4dd44jgoM/E0yxNfKYUVSXO036BzVvgOXMBFrVRuzHoH77ajdY5UOeyDco8VBYF/GUSxaHqXDJMcZ+KKvIU+rjkJeVCTzQTipATapqnfbl3quwJO8ZT7YHe1u86Uwt2I="
Dec 12 17:46:24 gbvpi-bedroom go-librespot[11686]: time="2025-12-12T17:46:24-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 12 17:46:24 gbvpi-bedroom go-librespot[11686]: time="2025-12-12T17:46:24-05:00" level=debug msg="completed keyexchange"
Dec 12 17:46:24 gbvpi-bedroom go-librespot[11686]: time="2025-12-12T17:46:24-05:00" level=debug msg="completed challenge"
Dec 12 17:46:24 gbvpi-bedroom go-librespot[11686]: time="2025-12-12T17:46: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 12 17:46:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:46:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:46:24 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:46:24 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:46:24 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:46:24 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:46:27 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 12 17:46:27 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 12 17:46:27 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Dec 12 17:46:27 gbvpi-bedroom volumio-remote-updater[775]: Test mode enabled
Dec 12 17:46:27 gbvpi-bedroom volumio-remote-updater[775]: Alpha mode disabled
Dec 12 17:46:27 gbvpi-bedroom volumio-remote-updater[775]: Alpha legacy test mode disabled
Dec 12 17:46:27 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Dec 12 17:46:27 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Dec 12 17:46:27 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:27 gbvpi-bedroom volumio[11096]: 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 12 17:46:27 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Dec 12 17:46:27 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:27 gbvpi-bedroom go-librespot[11697]: go-librespot daemon starting...
Dec 12 17:46:27 gbvpi-bedroom go-librespot[11698]: time="2025-12-12T17:46:27-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:46:27 gbvpi-bedroom go-librespot[11698]: time="2025-12-12T17:46:27-05:00" level=debug msg="app state loaded"
Dec 12 17:46:27 gbvpi-bedroom go-librespot[11698]: time="2025-12-12T17:46:27-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:46:27 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 12 17:46:27 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 12 17:46:27 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Dec 12 17:46:27 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Dec 12 17:46:27 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Dec 12 17:46:27 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetBrowseSources
Dec 12 17:46:27 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 12 17:46:27 gbvpi-bedroom go-librespot[11698]: time="2025-12-12T17:46: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 12 17:46:27 gbvpi-bedroom go-librespot[11698]: time="2025-12-12T17:46:27-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 12 17:46:27 gbvpi-bedroom go-librespot[11698]: time="2025-12-12T17:46:27-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 12 17:46:27 gbvpi-bedroom go-librespot[11698]: time="2025-12-12T17:46:27-05:00" level=info msg="zeroconf server listening on port 42337"
Dec 12 17:46:27 gbvpi-bedroom go-librespot[11698]: time="2025-12-12T17:46:27-05:00" level=debug msg="obtained new client token: AABUtG2NMiAgCHLvqk/kDETjePFXitAcQRJk5DwUq9ELieXbFu4uTnpclSM3d4ki1rFl2h50VM3QpJyqki/bMR9pT/2u27jV9dJ3lKuvK9ZrqzWG8FU/jJFPtehqU6g1x6lKnbmCHvJHd0MY4rZvS0C8Vyc0YpWyAowGf4ugAAetKO7ZYdzIOOQJpK449j0MkdZZlmpoX+qiBovKkr+natuTocTrJh0tbLmmTBXF0b24ivWBqbEWSC/19A=="
Dec 12 17:46:27 gbvpi-bedroom go-librespot[11698]: time="2025-12-12T17:46:27-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 12 17:46:27 gbvpi-bedroom go-librespot[11698]: time="2025-12-12T17:46:27-05:00" level=debug msg="completed keyexchange"
Dec 12 17:46:27 gbvpi-bedroom go-librespot[11698]: time="2025-12-12T17:46:27-05:00" level=debug msg="completed challenge"
Dec 12 17:46:27 gbvpi-bedroom go-librespot[11698]: time="2025-12-12T17:46:27-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 12 17:46:27 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:46:27 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:46:27 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:46:27 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:46:29 gbvpi-bedroom volumio[11096]: info: BOOT COMPLETED
Dec 12 17:46:30 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:46:30 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:46:31 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Dec 12 17:46:31 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:31 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:31 gbvpi-bedroom go-librespot[11705]: go-librespot daemon starting...
Dec 12 17:46:31 gbvpi-bedroom go-librespot[11706]: time="2025-12-12T17:46:31-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:46:31 gbvpi-bedroom go-librespot[11706]: time="2025-12-12T17:46:31-05:00" level=debug msg="app state loaded"
Dec 12 17:46:31 gbvpi-bedroom go-librespot[11706]: time="2025-12-12T17:46:31-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:46:31 gbvpi-bedroom go-librespot[11706]: time="2025-12-12T17:46: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-gae2.spotify.com:443 ap-gew1.spotify.com:80]"
Dec 12 17:46:31 gbvpi-bedroom go-librespot[11706]: time="2025-12-12T17:46:31-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 12 17:46:31 gbvpi-bedroom go-librespot[11706]: time="2025-12-12T17:46:31-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 12 17:46:31 gbvpi-bedroom go-librespot[11706]: time="2025-12-12T17:46:31-05:00" level=info msg="zeroconf server listening on port 43029"
Dec 12 17:46:31 gbvpi-bedroom go-librespot[11706]: time="2025-12-12T17:46:31-05:00" level=debug msg="obtained new client token: AAC1q3oM5lIcZ74ATNd88UosF/L7JJsNYEbWfPZp5MJX1haK8h+E3xnJvSLohINTo0TuqP7G7hzmhzx06Lq0MdYwd5ACGZbZA2Hm6OzTV7l5QI8h3VO50b9PaBIclr6XQflc0TJp9wynNOAF6P0caqjl0Hpz1spUNkg+9+a4JBILRHtYpkWIPr+hwiTAwOui0ucSS2JHQmUVbnNB6qD6xlwQyYGI/JmcJDFbZ0CrX5LzuisEU4IYU0GGSw=="
Dec 12 17:46:31 gbvpi-bedroom go-librespot[11706]: time="2025-12-12T17:46:31-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 12 17:46:31 gbvpi-bedroom go-librespot[11706]: time="2025-12-12T17:46:31-05:00" level=debug msg="completed keyexchange"
Dec 12 17:46:31 gbvpi-bedroom go-librespot[11706]: time="2025-12-12T17:46:31-05:00" level=debug msg="completed challenge"
Dec 12 17:46:31 gbvpi-bedroom go-librespot[11706]: time="2025-12-12T17:46: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 12 17:46:31 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:46:31 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:46:33 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:46:34 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:46:34 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:46:34 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:46:34 gbvpi-bedroom volumio[11096]: info: Listing playlists
Dec 12 17:46:34 gbvpi-bedroom volumio[11096]: info: Listing playlists
Dec 12 17:46:34 gbvpi-bedroom volumio[11096]: info: Listing playlists
Dec 12 17:46:34 gbvpi-bedroom volumio[11096]: info: Listing playlists
Dec 12 17:46:34 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Dec 12 17:46:34 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:35 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:35 gbvpi-bedroom go-librespot[11727]: go-librespot daemon starting...
Dec 12 17:46:35 gbvpi-bedroom go-librespot[11728]: time="2025-12-12T17:46:35-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:46:35 gbvpi-bedroom go-librespot[11728]: time="2025-12-12T17:46:35-05:00" level=debug msg="app state loaded"
Dec 12 17:46:35 gbvpi-bedroom go-librespot[11728]: time="2025-12-12T17:46:35-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:46:35 gbvpi-bedroom go-librespot[11728]: time="2025-12-12T17:46: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 12 17:46:35 gbvpi-bedroom go-librespot[11728]: time="2025-12-12T17:46:35-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 12 17:46:35 gbvpi-bedroom go-librespot[11728]: time="2025-12-12T17:46:35-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 12 17:46:35 gbvpi-bedroom go-librespot[11728]: time="2025-12-12T17:46:35-05:00" level=info msg="zeroconf server listening on port 33825"
Dec 12 17:46:35 gbvpi-bedroom go-librespot[11728]: time="2025-12-12T17:46:35-05:00" level=debug msg="obtained new client token: AACgDDfXID4vxyBgzamqyzjKIK5BMRGj771RTGgRu1zLJ92H7oXIXfeRGEKvBGjcvhjPRvITQLzrqACySY8CstIusPbch9TdFURPukYw6eSLtT7tBu3Ii/zL0jEYLF10rfVm88UUzSFTnmSva9ZrxllRdB7+f2v/aObqTShOYJhljyN9p5xxiYZUTUagvF3XQkcBIPnxKriewXdjL4ptt1YYnVb8NNzaa7IAOYWzr5yf2u8EJj+uDccEmg=="
Dec 12 17:46:35 gbvpi-bedroom go-librespot[11728]: time="2025-12-12T17:46: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 12 17:46:35 gbvpi-bedroom go-librespot[11728]: time="2025-12-12T17:46:35-05:00" level=debug msg="connected to ap-gue1.spotify.com:443"
Dec 12 17:46:35 gbvpi-bedroom go-librespot[11728]: time="2025-12-12T17:46:35-05:00" level=debug msg="completed keyexchange"
Dec 12 17:46:35 gbvpi-bedroom go-librespot[11728]: time="2025-12-12T17:46:35-05:00" level=debug msg="completed challenge"
Dec 12 17:46:35 gbvpi-bedroom go-librespot[11728]: time="2025-12-12T17:46: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 12 17:46:35 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:46:35 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:46:37 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:46:37 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:46:38 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11.
Dec 12 17:46:38 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:38 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:38 gbvpi-bedroom go-librespot[11735]: go-librespot daemon starting...
Dec 12 17:46:38 gbvpi-bedroom go-librespot[11736]: time="2025-12-12T17:46:38-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:46:38 gbvpi-bedroom go-librespot[11736]: time="2025-12-12T17:46:38-05:00" level=debug msg="app state loaded"
Dec 12 17:46:38 gbvpi-bedroom go-librespot[11736]: time="2025-12-12T17:46:38-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:46:38 gbvpi-bedroom go-librespot[11736]: time="2025-12-12T17:46: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 12 17:46:38 gbvpi-bedroom go-librespot[11736]: time="2025-12-12T17:46: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 12 17:46:38 gbvpi-bedroom go-librespot[11736]: time="2025-12-12T17:46: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 12 17:46:38 gbvpi-bedroom go-librespot[11736]: time="2025-12-12T17:46:38-05:00" level=info msg="zeroconf server listening on port 39197"
Dec 12 17:46:39 gbvpi-bedroom go-librespot[11736]: time="2025-12-12T17:46:39-05:00" level=debug msg="obtained new client token: AACU+eHS7f0uWKDhkQzp5UbLm4tubndaHqHnIj20qSuUfvOPjZtdWIFmUfUfx957MDvBQ5T51B8h8PeYp4yzyBSPRL89aQWtnHXIwword7DVtZwLIyLVGQtwcz1PLBou6Sb8krOePoQUyU6sHc8hBQMaoxWffOoSw/k9fb3/6V4oSYJHML18CrAPF6e36jKT0cvSNSpZ9AwWMntpUHKSIvgjvZF63f4zLs7yOzY/zkm6yC5dbUg96nM="
Dec 12 17:46:39 gbvpi-bedroom go-librespot[11736]: time="2025-12-12T17:46:39-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 12 17:46:39 gbvpi-bedroom go-librespot[11736]: time="2025-12-12T17:46:39-05:00" level=debug msg="completed keyexchange"
Dec 12 17:46:39 gbvpi-bedroom go-librespot[11736]: time="2025-12-12T17:46:39-05:00" level=debug msg="completed challenge"
Dec 12 17:46:39 gbvpi-bedroom go-librespot[11736]: time="2025-12-12T17:46: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 12 17:46:39 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:46:39 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:46:40 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:46:40 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:46:42 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12.
Dec 12 17:46:42 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:42 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:42 gbvpi-bedroom go-librespot[11747]: go-librespot daemon starting...
Dec 12 17:46:42 gbvpi-bedroom go-librespot[11748]: time="2025-12-12T17:46:42-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:46:42 gbvpi-bedroom go-librespot[11748]: time="2025-12-12T17:46:42-05:00" level=debug msg="app state loaded"
Dec 12 17:46:42 gbvpi-bedroom go-librespot[11748]: time="2025-12-12T17:46:42-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:46:42 gbvpi-bedroom go-librespot[11748]: time="2025-12-12T17:46: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-gew4.spotify.com:80]"
Dec 12 17:46:42 gbvpi-bedroom go-librespot[11748]: time="2025-12-12T17:46:42-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 12 17:46:42 gbvpi-bedroom go-librespot[11748]: time="2025-12-12T17:46:42-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 12 17:46:42 gbvpi-bedroom go-librespot[11748]: time="2025-12-12T17:46:42-05:00" level=info msg="zeroconf server listening on port 42237"
Dec 12 17:46:42 gbvpi-bedroom go-librespot[11748]: time="2025-12-12T17:46:42-05:00" level=debug msg="obtained new client token: AAD4FnmNZER2KArk8ChNFS0l3+uPGL9hfsyaRuwGiaAatuCQW0Av1UpHWCZ/19AERH9ZZYBT9ySeldkP5V/RN97fYfyDVdScUpyn25Qz86ROvVwgv4v53MLv6s03D+fbj1DsFjRc/Un51H8upxrLbvJyySkot6EglLSZ/HBmwPxyYgmYrqodCjffmz+TEkqgenkOm/U9/C9FQBq9FX0rlXyeaV86RaFKBwJINqs8AMhuujqFzYbZQ0Plwg=="
Dec 12 17:46:42 gbvpi-bedroom go-librespot[11748]: time="2025-12-12T17:46:42-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 12 17:46:42 gbvpi-bedroom go-librespot[11748]: time="2025-12-12T17:46:42-05:00" level=debug msg="completed keyexchange"
Dec 12 17:46:42 gbvpi-bedroom go-librespot[11748]: time="2025-12-12T17:46:42-05:00" level=debug msg="completed challenge"
Dec 12 17:46:42 gbvpi-bedroom go-librespot[11748]: time="2025-12-12T17:46: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 12 17:46:42 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:46:42 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:46:43 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:46:43 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:46:44 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:46:44 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:46:45 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13.
Dec 12 17:46:45 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:46 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:46 gbvpi-bedroom go-librespot[11770]: go-librespot daemon starting...
Dec 12 17:46:46 gbvpi-bedroom systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service...
Dec 12 17:46:46 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:46:46 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:46:46 gbvpi-bedroom go-librespot[11771]: time="2025-12-12T17:46:46-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:46:46 gbvpi-bedroom go-librespot[11771]: time="2025-12-12T17:46:46-05:00" level=debug msg="app state loaded"
Dec 12 17:46:46 gbvpi-bedroom go-librespot[11771]: time="2025-12-12T17:46:46-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:46:46 gbvpi-bedroom go-librespot[11771]: time="2025-12-12T17:46: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 12 17:46:46 gbvpi-bedroom go-librespot[11771]: time="2025-12-12T17:46: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 12 17:46:46 gbvpi-bedroom go-librespot[11771]: time="2025-12-12T17:46: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 12 17:46:46 gbvpi-bedroom go-librespot[11771]: time="2025-12-12T17:46:46-05:00" level=info msg="zeroconf server listening on port 46869"
Dec 12 17:46:46 gbvpi-bedroom go-librespot[11771]: time="2025-12-12T17:46:46-05:00" level=debug msg="obtained new client token: AAAyfb+ebPr6VzorGMAywZ5IEoEenc++SypbYJ5kBJUvOBE0f/Kwg1mn9bc04W4dAo4Sq6O43MNd3u63NppNSfj7tZwdR6vAIvrqkUXzPbhfuQz3yWs74tKdVT/+lUPL4XJ9wwoeVWP/svAoYTfv/rw1Yg1hj0nl6EjTF3jW8LzeFJG/a0+f6xxfSSo53c+OtDxX3dMvlGoyca5MuYkNY0murPymCkJtMoOZzTMLAKs3+WgdQsvRPlUKSw=="
Dec 12 17:46:46 gbvpi-bedroom go-librespot[11771]: time="2025-12-12T17:46:46-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 12 17:46:46 gbvpi-bedroom go-librespot[11771]: time="2025-12-12T17:46:46-05:00" level=debug msg="connected to ap-gue1.spotify.com:443"
Dec 12 17:46:46 gbvpi-bedroom go-librespot[11771]: time="2025-12-12T17:46:46-05:00" level=debug msg="completed keyexchange"
Dec 12 17:46:46 gbvpi-bedroom go-librespot[11771]: time="2025-12-12T17:46:46-05:00" level=debug msg="completed challenge"
Dec 12 17:46:46 gbvpi-bedroom go-librespot[11771]: time="2025-12-12T17:46: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 12 17:46:46 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:46:46 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:46:46 gbvpi-bedroom systemd[1]: setdatetime-helper.service: Deactivated successfully.
Dec 12 17:46:46 gbvpi-bedroom systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service.
Dec 12 17:46:49 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:46:49 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:46:49 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14.
Dec 12 17:46:49 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:49 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:49 gbvpi-bedroom go-librespot[11804]: go-librespot daemon starting...
Dec 12 17:46:49 gbvpi-bedroom go-librespot[11805]: time="2025-12-12T17:46:49-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:46:49 gbvpi-bedroom go-librespot[11805]: time="2025-12-12T17:46:49-05:00" level=debug msg="app state loaded"
Dec 12 17:46:49 gbvpi-bedroom go-librespot[11805]: time="2025-12-12T17:46:49-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:46:49 gbvpi-bedroom go-librespot[11805]: time="2025-12-12T17:46:49-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 12 17:46:49 gbvpi-bedroom go-librespot[11805]: time="2025-12-12T17:46:49-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 12 17:46:49 gbvpi-bedroom go-librespot[11805]: time="2025-12-12T17:46:49-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 12 17:46:49 gbvpi-bedroom go-librespot[11805]: time="2025-12-12T17:46:49-05:00" level=info msg="zeroconf server listening on port 45635"
Dec 12 17:46:50 gbvpi-bedroom go-librespot[11805]: time="2025-12-12T17:46:50-05:00" level=debug msg="obtained new client token: AAC7vNYKO9OxGbYsuv7myQKH2ancErwI11+8G5kUF8sfegWBv495kn4jq2Ml12buel6/laTZaDqlbySj8Y/2aVann5TVpUJbY3/fcRdCaNfXeVOXu0w3PUpLzIfAiw//qjEGRzNtby61BcSUj/ShhqXX35+VzPDdQX6cvklMypQIJGnVdQFC597ylZwHARVc3B42Qh88DjdiTdBpFzgYCGrTjA/9S/jKYaZ5glqopS9hd+0u3gZ9Kwc="
Dec 12 17:46:50 gbvpi-bedroom go-librespot[11805]: time="2025-12-12T17:46:50-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 12 17:46:50 gbvpi-bedroom go-librespot[11805]: time="2025-12-12T17:46:50-05:00" level=debug msg="completed keyexchange"
Dec 12 17:46:50 gbvpi-bedroom go-librespot[11805]: time="2025-12-12T17:46:50-05:00" level=debug msg="completed challenge"
Dec 12 17:46:50 gbvpi-bedroom go-librespot[11805]: time="2025-12-12T17:46: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 12 17:46:50 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:46:50 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:46:52 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:46:52 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:46:53 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15.
Dec 12 17:46:53 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:53 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:53 gbvpi-bedroom go-librespot[11812]: go-librespot daemon starting...
Dec 12 17:46:53 gbvpi-bedroom go-librespot[11813]: time="2025-12-12T17:46:53-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:46:53 gbvpi-bedroom go-librespot[11813]: time="2025-12-12T17:46:53-05:00" level=debug msg="app state loaded"
Dec 12 17:46:53 gbvpi-bedroom go-librespot[11813]: time="2025-12-12T17:46:53-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:46:53 gbvpi-bedroom go-librespot[11813]: time="2025-12-12T17:46: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 12 17:46:53 gbvpi-bedroom go-librespot[11813]: time="2025-12-12T17:46:53-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 12 17:46:53 gbvpi-bedroom go-librespot[11813]: time="2025-12-12T17:46:53-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 12 17:46:53 gbvpi-bedroom go-librespot[11813]: time="2025-12-12T17:46:53-05:00" level=info msg="zeroconf server listening on port 33557"
Dec 12 17:46:53 gbvpi-bedroom go-librespot[11813]: time="2025-12-12T17:46:53-05:00" level=debug msg="obtained new client token: AAC9SAhaFP+ankDTYpjdw+s80OoVU49lBTJ/i6vI75FPH6cJeHM00WzgrCy1euG6N9qrAGk77drSpfZZa+Qew+qima79oSHkLTzXhh7wysw+lI8bnetPyQCoOllKYgIALP2pXsQ0RiEYRIaoWwSWSexY8E7m4HR5jkMV8ntIEmlkOzzOehAmr+gfkXn/QIry43WmFGgK0hay+tjTN+sCRfWFReEQY5wRB3+nbZ6XPLwfOn6B+rO9Orm84g=="
Dec 12 17:46:53 gbvpi-bedroom go-librespot[11813]: time="2025-12-12T17:46:53-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 12 17:46:53 gbvpi-bedroom go-librespot[11813]: time="2025-12-12T17:46:53-05:00" level=debug msg="completed keyexchange"
Dec 12 17:46:53 gbvpi-bedroom go-librespot[11813]: time="2025-12-12T17:46:53-05:00" level=debug msg="completed challenge"
Dec 12 17:46:54 gbvpi-bedroom go-librespot[11813]: time="2025-12-12T17:46: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 12 17:46:54 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:46:54 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:46:54 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:46:54 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:46:54 gbvpi-bedroom volumio[11096]: info: Listing playlists
Dec 12 17:46:54 gbvpi-bedroom volumio[11096]: info: Listing playlists
Dec 12 17:46:54 gbvpi-bedroom volumio[11096]: info: Listing playlists
Dec 12 17:46:54 gbvpi-bedroom volumio[11096]: info: Listing playlists
Dec 12 17:46:55 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:46:55 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:46:57 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16.
Dec 12 17:46:57 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:57 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:46:57 gbvpi-bedroom go-librespot[11834]: go-librespot daemon starting...
Dec 12 17:46:57 gbvpi-bedroom go-librespot[11835]: time="2025-12-12T17:46:57-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:46:57 gbvpi-bedroom go-librespot[11835]: time="2025-12-12T17:46:57-05:00" level=debug msg="app state loaded"
Dec 12 17:46:57 gbvpi-bedroom go-librespot[11835]: time="2025-12-12T17:46:57-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:46:57 gbvpi-bedroom volumio[11096]: info: UPDATER: Scheduling automatic update
Dec 12 17:46:57 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStartTime
Dec 12 17:46:57 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStopTime
Dec 12 17:46:57 gbvpi-bedroom volumio[11096]: info: UPDATER: Auto update will take place at: Sat Dec 13 2025 05:03:15 GMT-0500 (Eastern Standard Time)
Dec 12 17:46:57 gbvpi-bedroom go-librespot[11835]: time="2025-12-12T17:46: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-gae2.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 12 17:46:57 gbvpi-bedroom go-librespot[11835]: time="2025-12-12T17:46:57-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 12 17:46:57 gbvpi-bedroom go-librespot[11835]: time="2025-12-12T17:46:57-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 12 17:46:57 gbvpi-bedroom go-librespot[11835]: time="2025-12-12T17:46:57-05:00" level=info msg="zeroconf server listening on port 45467"
Dec 12 17:46:57 gbvpi-bedroom go-librespot[11835]: time="2025-12-12T17:46:57-05:00" level=debug msg="obtained new client token: AADyKrqAXAzrcZinG6/0aFKCYxPL7mrUQJrj8du45s3rTmjMfyQ0J1z+lSneDCn+Hy4sIgW8bvyiRNEGeJbO5u5wu5tyF00pSDgXClk1MNWJZ5IpyO8phNNm9Xe1Iu1M2ahpYYWNHNu0eOlAj6pBkgq2mwl5n+FgYi0aaONq5m4GNsbRVezQWJyhD3tRA+bvg45JnNYsK+0FRVnj9Rp48NW2ALz8bBvumIy4p9N8G8edtkkinD0EmrByWQ=="
Dec 12 17:46:57 gbvpi-bedroom go-librespot[11835]: time="2025-12-12T17:46:57-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 12 17:46:57 gbvpi-bedroom go-librespot[11835]: time="2025-12-12T17:46:57-05:00" level=debug msg="connected to ap-gue1.spotify.com:443"
Dec 12 17:46:57 gbvpi-bedroom go-librespot[11835]: time="2025-12-12T17:46:57-05:00" level=debug msg="completed keyexchange"
Dec 12 17:46:57 gbvpi-bedroom go-librespot[11835]: time="2025-12-12T17:46:57-05:00" level=debug msg="completed challenge"
Dec 12 17:46:57 gbvpi-bedroom go-librespot[11835]: time="2025-12-12T17:46:57-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 12 17:46:57 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:46:57 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:46:58 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:46:58 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:47:00 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17.
Dec 12 17:47:00 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:47:01 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:47:01 gbvpi-bedroom go-librespot[11845]: go-librespot daemon starting...
Dec 12 17:47:01 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:47:01 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:47:01 gbvpi-bedroom go-librespot[11846]: time="2025-12-12T17:47:01-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:47:01 gbvpi-bedroom go-librespot[11846]: time="2025-12-12T17:47:01-05:00" level=debug msg="app state loaded"
Dec 12 17:47:01 gbvpi-bedroom go-librespot[11846]: time="2025-12-12T17:47:01-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:47:01 gbvpi-bedroom go-librespot[11846]: time="2025-12-12T17:47: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 12 17:47:01 gbvpi-bedroom go-librespot[11846]: time="2025-12-12T17:47:01-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 12 17:47:01 gbvpi-bedroom go-librespot[11846]: time="2025-12-12T17:47:01-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 12 17:47:01 gbvpi-bedroom go-librespot[11846]: time="2025-12-12T17:47:01-05:00" level=info msg="zeroconf server listening on port 43233"
Dec 12 17:47:01 gbvpi-bedroom go-librespot[11846]: time="2025-12-12T17:47:01-05:00" level=debug msg="obtained new client token: AABowJlzeVp7uQEWlM1lyXPqefbud639853CNDvL0XCf/RndHZufy2i1+oFiU3VGuPimiHKZIbE6zfSy28oOdFPCojoBS9CKCdIacvxE6/Xc30B7CIrISjgwo91XkfiII2kDyYOjoucJceo2LoxL0w87UkXoDETeHD0GXuVfVzMiVraTYxKABuXIB3D5bd35k9T0pW8jthfmYrqZjOrkts1UBwk6XF0kkP+OWRSDqZilkwDMxcNV3AGP/A=="
Dec 12 17:47:01 gbvpi-bedroom go-librespot[11846]: time="2025-12-12T17:47:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 12 17:47:01 gbvpi-bedroom go-librespot[11846]: time="2025-12-12T17:47:01-05:00" level=debug msg="completed keyexchange"
Dec 12 17:47:01 gbvpi-bedroom go-librespot[11846]: time="2025-12-12T17:47:01-05:00" level=debug msg="completed challenge"
Dec 12 17:47:01 gbvpi-bedroom go-librespot[11846]: time="2025-12-12T17:47: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 12 17:47:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:47:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:47:04 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:47:04 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:47:04 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:47:04 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:47:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18.
Dec 12 17:47:04 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:47:04 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:47:04 gbvpi-bedroom go-librespot[11868]: go-librespot daemon starting...
Dec 12 17:47:04 gbvpi-bedroom go-librespot[11869]: time="2025-12-12T17:47:04-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:47:04 gbvpi-bedroom go-librespot[11869]: time="2025-12-12T17:47:04-05:00" level=debug msg="app state loaded"
Dec 12 17:47:04 gbvpi-bedroom go-librespot[11869]: time="2025-12-12T17:47:04-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:47:04 gbvpi-bedroom go-librespot[11869]: time="2025-12-12T17:47: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-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]"
Dec 12 17:47:04 gbvpi-bedroom go-librespot[11869]: time="2025-12-12T17:47:04-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 12 17:47:04 gbvpi-bedroom go-librespot[11869]: time="2025-12-12T17:47:04-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 12 17:47:04 gbvpi-bedroom go-librespot[11869]: time="2025-12-12T17:47:04-05:00" level=info msg="zeroconf server listening on port 43405"
Dec 12 17:47:05 gbvpi-bedroom go-librespot[11869]: time="2025-12-12T17:47:05-05:00" level=debug msg="obtained new client token: AAA0qA2lAq0OXfiau6fna4xPDKXWg+dKZS9sXjlExtIKVFrf+aCp94lv+qnzr5M7aUFVzsaKZQ15MtUn7yILfmC7pWfvS8tCWJHkCU07GQJfbMbScXm405+W5acd0xXvEgHYtN/7qt2/7F9sxVRD1AdrouAu1B6LL/45xAnnrF++LPlVUPsK99tBT4JnmZ907o1Dygr5lBaKDyKPJiDzc0sdLpXBRDpqGmKra6QT0xSxCoLoZmQUYo4="
Dec 12 17:47:05 gbvpi-bedroom go-librespot[11869]: time="2025-12-12T17:47:05-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 12 17:47:05 gbvpi-bedroom go-librespot[11869]: time="2025-12-12T17:47:05-05:00" level=debug msg="completed keyexchange"
Dec 12 17:47:05 gbvpi-bedroom go-librespot[11869]: time="2025-12-12T17:47:05-05:00" level=debug msg="completed challenge"
Dec 12 17:47:05 gbvpi-bedroom go-librespot[11869]: time="2025-12-12T17:47: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 12 17:47:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:47:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:47:07 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:47:07 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:47:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19.
Dec 12 17:47:08 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:47:08 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:47:08 gbvpi-bedroom go-librespot[11876]: go-librespot daemon starting...
Dec 12 17:47:08 gbvpi-bedroom go-librespot[11877]: time="2025-12-12T17:47:08-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:47:08 gbvpi-bedroom go-librespot[11877]: time="2025-12-12T17:47:08-05:00" level=debug msg="app state loaded"
Dec 12 17:47:08 gbvpi-bedroom go-librespot[11877]: time="2025-12-12T17:47:08-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:47:08 gbvpi-bedroom go-librespot[11877]: time="2025-12-12T17:47: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 12 17:47:08 gbvpi-bedroom go-librespot[11877]: time="2025-12-12T17:47:08-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 12 17:47:08 gbvpi-bedroom go-librespot[11877]: time="2025-12-12T17:47:08-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 12 17:47:08 gbvpi-bedroom go-librespot[11877]: time="2025-12-12T17:47:08-05:00" level=info msg="zeroconf server listening on port 38347"
Dec 12 17:47:08 gbvpi-bedroom go-librespot[11877]: time="2025-12-12T17:47:08-05:00" level=debug msg="obtained new client token: AACBwisAoRPaycjuWyx4wPxagz+O1PStbXEi4zEAzeKMTd59V4OWxXN8WzIqtpZ1b2acgBhv4r9PIW7/L6BnM30o45UV+fHOb77VoqXnb4Wn3UlZY6wKzseb+cvzWBIDixa7qeAeHDFlkElCt9JazdhnJAxFh7m1LIgFv9aX3OFC+TI51Fm+9xXHvvyqbTOFmQwWAVUfo8JCe+DJq15wCgkOVQgedyJTlCmvTVwaWL0y66Oyx6Hmsuwwfg=="
Dec 12 17:47:08 gbvpi-bedroom go-librespot[11877]: time="2025-12-12T17:47:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 12 17:47:08 gbvpi-bedroom go-librespot[11877]: time="2025-12-12T17:47:08-05:00" level=debug msg="completed keyexchange"
Dec 12 17:47:08 gbvpi-bedroom go-librespot[11877]: time="2025-12-12T17:47:08-05:00" level=debug msg="completed challenge"
Dec 12 17:47:08 gbvpi-bedroom go-librespot[11877]: time="2025-12-12T17:47:08-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 12 17:47:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:47:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:47:10 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:47:10 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:47:11 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20.
Dec 12 17:47:11 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:47:12 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:47:12 gbvpi-bedroom go-librespot[11884]: go-librespot daemon starting...
Dec 12 17:47:12 gbvpi-bedroom go-librespot[11885]: time="2025-12-12T17:47:12-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:47:12 gbvpi-bedroom go-librespot[11885]: time="2025-12-12T17:47:12-05:00" level=debug msg="app state loaded"
Dec 12 17:47:12 gbvpi-bedroom go-librespot[11885]: time="2025-12-12T17:47:12-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:47:12 gbvpi-bedroom go-librespot[11885]: time="2025-12-12T17:47: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 12 17:47:12 gbvpi-bedroom go-librespot[11885]: time="2025-12-12T17:47:12-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 12 17:47:12 gbvpi-bedroom go-librespot[11885]: time="2025-12-12T17:47:12-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 12 17:47:12 gbvpi-bedroom go-librespot[11885]: time="2025-12-12T17:47:12-05:00" level=info msg="zeroconf server listening on port 42451"
Dec 12 17:47:12 gbvpi-bedroom go-librespot[11885]: time="2025-12-12T17:47:12-05:00" level=debug msg="obtained new client token: AADkEAET/6gu/tyDMrGCL1mhnF+Spy8Nh9pJqJbhcvyJoU+JL4Bv2M31mmz0qErQKgdK55qy4Js5SSVJvmTTg7YFIMrJH6yzKFHNyJ3vF5hHAmm77h5WE+uNbOi7EhfyAzrdRvrsWOKzMyxGUyFtSE81ReWYOsHH+cT7m4kiWyMtXloL1KVTjPR0z3n68p91bW8FgkyjdJ5V1eP5fxkuB+LSIa0bnsg3s62WJahf7bzwjbFuD3fohfKStA=="
Dec 12 17:47:12 gbvpi-bedroom go-librespot[11885]: time="2025-12-12T17:47:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 12 17:47:12 gbvpi-bedroom go-librespot[11885]: time="2025-12-12T17:47:12-05:00" level=debug msg="completed keyexchange"
Dec 12 17:47:12 gbvpi-bedroom go-librespot[11885]: time="2025-12-12T17:47:12-05:00" level=debug msg="completed challenge"
Dec 12 17:47:12 gbvpi-bedroom go-librespot[11885]: time="2025-12-12T17:47:12-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 12 17:47:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:47:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:47:13 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:47:13 gbvpi-bedroom volumio[11096]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:47:14 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:47:14 gbvpi-bedroom volumio[11096]: info: CoreCommandRouter::volumioGetState
Dec 12 17:47:14 gbvpi-bedroom volumio[11096]: info: Listing playlists
Dec 12 17:47:14 gbvpi-bedroom volumio[11096]: info: Listing playlists
Dec 12 17:47:14 gbvpi-bedroom volumio[11096]: info: Listing playlists
Dec 12 17:47:14 gbvpi-bedroom volumio[11096]: info: Listing playlists
Dec 12 17:47:15 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21.
Dec 12 17:47:15 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:47:15 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:47:15 gbvpi-bedroom go-librespot[11906]: go-librespot daemon starting...
Dec 12 17:47:15 gbvpi-bedroom go-librespot[11907]: time="2025-12-12T17:47:15-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:47:15 gbvpi-bedroom go-librespot[11907]: time="2025-12-12T17:47:15-05:00" level=debug msg="app state loaded"
Dec 12 17:47:15 gbvpi-bedroom go-librespot[11907]: time="2025-12-12T17:47:15-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:47:15 gbvpi-bedroom go-librespot[11907]: time="2025-12-12T17:47:15-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 12 17:47:15 gbvpi-bedroom go-librespot[11907]: time="2025-12-12T17:47:15-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 12 17:47:15 gbvpi-bedroom go-librespot[11907]: time="2025-12-12T17:47:15-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 12 17:47:15 gbvpi-bedroom go-librespot[11907]: time="2025-12-12T17:47:15-05:00" level=info msg="zeroconf server listening on port 38821"
Dec 12 17:47:16 gbvpi-bedroom volumio[11096]: info: Initializing connection to go-librespot Websocket
Dec 12 17:47:16 gbvpi-bedroom go-librespot[11907]: time="2025-12-12T17:47:16-05:00" level=debug msg="new websocket client"
Dec 12 17:47:16 gbvpi-bedroom volumio[11096]: info: Connection to go-librespot Websocket established
Dec 12 17:47:16 gbvpi-bedroom go-librespot[11907]: time="2025-12-12T17:47:16-05:00" level=debug msg="obtained new client token: AAAQRHQ4mwalUmf+CqYMmVvMsphS+FoSBXGr96NHD0gLmfi5s6GxwZuyShEKnaxQ5uWZiSRdwi3ijl4qdA5tPzFXuNzrhlb8mefmPI7/K/xS3ycyDQFdpYTRZIfqLJWycSh+r69vhlEcpJq0h6brb3jLrZ7i4vv9wgjYAhHKeLWnHjfsngBmNrVD3+WjNcFy9GRcU5CYXwUs85LCOK4Oe41DA3oKoOzzY3d1PMufvFYTCnNsWeJgqQM="
Dec 12 17:47:16 gbvpi-bedroom go-librespot[11907]: time="2025-12-12T17:47:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 12 17:47:16 gbvpi-bedroom go-librespot[11907]: time="2025-12-12T17:47:16-05:00" level=debug msg="completed keyexchange"
Dec 12 17:47:16 gbvpi-bedroom go-librespot[11907]: time="2025-12-12T17:47:16-05:00" level=debug msg="completed challenge"
Dec 12 17:47:16 gbvpi-bedroom go-librespot[11907]: time="2025-12-12T17:47: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 12 17:47:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 12 17:47:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 12 17:47:16 gbvpi-bedroom volumio[11096]: info: Connection to go-librespot Websocket closed
Dec 12 17:47:19 gbvpi-bedroom volumio[11096]: info: Getting Spotify volume
Dec 12 17:47:19 gbvpi-bedroom volumio[11096]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 12 17:47:19 gbvpi-bedroom volumio[11096]: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 12 17:47:19 gbvpi-bedroom volumio[11096]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Dec 12 17:47:19 gbvpi-bedroom volumio[11096]: errno: -111,
Dec 12 17:47:19 gbvpi-bedroom volumio[11096]: code: 'ECONNREFUSED',
Dec 12 17:47:19 gbvpi-bedroom volumio[11096]: syscall: 'connect',
Dec 12 17:47:19 gbvpi-bedroom volumio[11096]: address: '127.0.0.1',
Dec 12 17:47:19 gbvpi-bedroom volumio[11096]: port: 9879,
Dec 12 17:47:19 gbvpi-bedroom volumio[11096]: response: undefined
Dec 12 17:47:19 gbvpi-bedroom volumio[11096]: }
Dec 12 17:47:19 gbvpi-bedroom volumio[11096]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 12 17:47:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22.
Dec 12 17:47:19 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:47:19 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 12 17:47:19 gbvpi-bedroom go-librespot[11929]: go-librespot daemon starting...
Dec 12 17:47:19 gbvpi-bedroom go-librespot[11930]: time="2025-12-12T17:47:19-05:00" level=info msg="running go-librespot 0.4.0"
Dec 12 17:47:19 gbvpi-bedroom go-librespot[11930]: time="2025-12-12T17:47:19-05:00" level=debug msg="app state loaded"
Dec 12 17:47:19 gbvpi-bedroom go-librespot[11930]: time="2025-12-12T17:47:19-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 12 17:47:19 gbvpi-bedroom go-librespot[11930]: time="2025-12-12T17:47:19-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 12 17:47:19 gbvpi-bedroom go-librespot[11930]: time="2025-12-12T17:47:19-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 12 17:47:19 gbvpi-bedroom go-librespot[11930]: time="2025-12-12T17:47:19-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 12 17:47:19 gbvpi-bedroom go-librespot[11930]: time="2025-12-12T17:47:19-05:00" level=info msg="zeroconf server listening on port 45031"
Dec 12 17:47:19 gbvpi-bedroom sudo[11940]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-12 17:46'
Dec 12 17:47:19 gbvpi-bedroom sudo[11940]: 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"