Dec 15 15:14:00 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 15 15:14:00 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:00 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:00 gbvpi-bedroom go-librespot[13684]: go-librespot daemon starting... Dec 15 15:14:00 gbvpi-bedroom go-librespot[13685]: time="2025-12-15T15:14:00-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:14:00 gbvpi-bedroom go-librespot[13685]: time="2025-12-15T15:14:00-05:00" level=debug msg="app state loaded" Dec 15 15:14:00 gbvpi-bedroom go-librespot[13685]: time="2025-12-15T15:14:00-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:14:00 gbvpi-bedroom go-librespot[13685]: time="2025-12-15T15:14:00-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 15:14:00 gbvpi-bedroom go-librespot[13685]: time="2025-12-15T15:14:00-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 15:14:00 gbvpi-bedroom go-librespot[13685]: time="2025-12-15T15:14:00-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 15:14:00 gbvpi-bedroom go-librespot[13685]: time="2025-12-15T15:14:00-05:00" level=info msg="zeroconf server listening on port 41455" Dec 15 15:14:01 gbvpi-bedroom go-librespot[13685]: time="2025-12-15T15:14:01-05:00" level=debug msg="obtained new client token: AAAr+GSqY7i00Iiqup1tZjRf2y7D8YYwWHNAPuIqKK+jnqubvfaOXirWnyZZ4kzlhK3B8dNwrAQdE+XPCtM6V+yVERCeK9x6fgwN/HK4OWalWREi+3qS5uR6r2ZNczPhE0gPkoM9MC8KCZjSudBrPBPGuDppQNgc5rv5Wy4ACTsp10F7Atr0/V7OsOSI0YPYOzEbXJ8RwspZoRYCdSVnIKh4Iaqivh0UhbwCq3FoKJwu3Qo/nFVT5n8=" Dec 15 15:14:01 gbvpi-bedroom go-librespot[13685]: time="2025-12-15T15:14:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:14:01 gbvpi-bedroom go-librespot[13685]: time="2025-12-15T15:14:01-05:00" level=debug msg="completed keyexchange" Dec 15 15:14:01 gbvpi-bedroom go-librespot[13685]: time="2025-12-15T15:14:01-05:00" level=debug msg="completed challenge" Dec 15 15:14:01 gbvpi-bedroom go-librespot[13685]: time="2025-12-15T15:14:01-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 15:14:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:14:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 15:14:02 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 15:14:03 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 15:14:03 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 15:14:03 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:14:03 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:14:03 gbvpi-bedroom volumio[13382]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 15:14:03 gbvpi-bedroom volumio[13382]: info: MyVolumio login type: Token Dec 15 15:14:03 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 15:14:03 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 15:14:03 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 15:14:03 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 15:14:03 gbvpi-bedroom volumio[13382]: info: Streaming services startup Dec 15 15:14:03 gbvpi-bedroom volumio[13382]: info: Starting Streaming Daemon Dec 15 15:14:03 gbvpi-bedroom sudo[13693]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 15:14:03 gbvpi-bedroom sudo[13693]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:14:03 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 15:14:03 gbvpi-bedroom sudo[13693]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:03 gbvpi-bedroom volumio[13382]: error: Cannot start Volumio Streaming Daemon Dec 15 15:14:03 gbvpi-bedroom volumio[13382]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 15:14:03 gbvpi-bedroom volumio[13382]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: MyVolumio token set successfully Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: MYVOLUMIO: Adding device Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: MYVOLUMIO: Evaluating Server Dec 15 15:14:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 15 15:14:04 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: MyVolumio Plan changed: premium Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: Removing browser output: myVolumio user plan is not superstar Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: Removing audio output: Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: MYVOLUMIO: Adding device Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: MYVOLUMIO: Evaluating Server Dec 15 15:14:04 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:04 gbvpi-bedroom go-librespot[13713]: go-librespot daemon starting... Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: Remote config written successfully Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: Starting Tunnel 1 Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: Starting Tunnel Connection Checker Dec 15 15:14:04 gbvpi-bedroom go-librespot[13721]: time="2025-12-15T15:14:04-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: Completed starting MyVolumio Plugin Dec 15 15:14:04 gbvpi-bedroom go-librespot[13721]: time="2025-12-15T15:14:04-05:00" level=debug msg="app state loaded" Dec 15 15:14:04 gbvpi-bedroom go-librespot[13721]: time="2025-12-15T15:14:04-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:14:04 gbvpi-bedroom go-librespot[13721]: time="2025-12-15T15:14: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 15 15:14:04 gbvpi-bedroom go-librespot[13721]: time="2025-12-15T15:14: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 15 15:14:04 gbvpi-bedroom go-librespot[13721]: time="2025-12-15T15:14: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 15 15:14:04 gbvpi-bedroom go-librespot[13721]: time="2025-12-15T15:14:04-05:00" level=info msg="zeroconf server listening on port 44841" Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: MYVolumio Device enabled Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: MyVolumio status changed Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: Streaming services startup Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: Starting Streaming Daemon Dec 15 15:14:04 gbvpi-bedroom sudo[13747]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 15:14:04 gbvpi-bedroom sudo[13747]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:14:04 gbvpi-bedroom go-librespot[13721]: time="2025-12-15T15:14:04-05:00" level=debug msg="obtained new client token: AACnDpm7zE1WyPgE3BjfF9eC5Ifw3vSJRxiuDQj10juy4UpyrvAjgUUzsvcFFNXGRCl/qdZhkYBXviT/ZDxbGdM0VzjRcZb8vXy/RCO4ytrCrvJCXMY6jnxJaV6+/ossvjpoeuaJPyw/ot+SMfSRavEx5AapNWZvv6t1KwWuU0/NeaZKDSMQN61IaEaheZJwf0GJzEbNtE8dvUFoa6VN/VQkYlflkfHuzdveBq0QqJnur5hH2xi9ySttLw==" Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: Setting Geolocation for MyVolumio to us4 Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 15 15:14:04 gbvpi-bedroom sudo[13747]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:04 gbvpi-bedroom go-librespot[13721]: time="2025-12-15T15:14:04-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:14:04 gbvpi-bedroom go-librespot[13721]: time="2025-12-15T15:14:04-05:00" level=debug msg="completed keyexchange" Dec 15 15:14:04 gbvpi-bedroom go-librespot[13721]: time="2025-12-15T15:14:04-05:00" level=debug msg="completed challenge" Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 15 15:14:04 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 15 15:14:04 gbvpi-bedroom go-librespot[13721]: time="2025-12-15T15:14:04-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 15:14:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:14:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 15 15:14:05 gbvpi-bedroom sudo[13751]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 15 15:14:05 gbvpi-bedroom sudo[13751]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:14:05 gbvpi-bedroom sudo[13751]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: MRS: MultiRoom plugin initialized Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: MRS: STOPPING SNAPCLIENT Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: MRS: Snap server stop Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: MRS: STOPPING volumioStreaming Dec 15 15:14:05 gbvpi-bedroom sudo[13768]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 15 15:14:05 gbvpi-bedroom sudo[13768]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:14:05 gbvpi-bedroom sudo[13770]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 15 15:14:05 gbvpi-bedroom sudo[13770]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 15 15:14:05 gbvpi-bedroom sudo[13772]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 15 15:14:05 gbvpi-bedroom sudo[13772]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 15 15:14:05 gbvpi-bedroom sudo[13776]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 15 15:14:05 gbvpi-bedroom sudo[13776]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:14:05 gbvpi-bedroom sudo[13776]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 15 15:14:05 gbvpi-bedroom sudo[13768]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:05 gbvpi-bedroom sudo[13770]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 15 15:14:05 gbvpi-bedroom sudo[13772]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: Preparing to generate the ALSA configuration file Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: Updating MyVolumio device info Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: Setting Geolocation for MyVolumio to us1 Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: Successfully Added MyVolumio device Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: Reading ALSA contributions from plugins. Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: MRS: Removed streaming files Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: MRS: volumioStreaming STOPPED Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: MRS: SNAPSERVER STOPPED Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: MRS: SNAPCLIENT STOPPED Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: error: Cannot start Volumio Streaming Daemon Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: Asound.conf file written Dec 15 15:14:05 gbvpi-bedroom sudo[13781]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 15 15:14:05 gbvpi-bedroom sudo[13781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:14:05 gbvpi-bedroom sudo[13781]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 15 15:14:05 gbvpi-bedroom volumio[13382]: info: Output device has changed, restarting MPD Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: Output device has changed, restarting Shairport Sync Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:14:06 gbvpi-bedroom sudo[13787]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 15:14:06 gbvpi-bedroom sudo[13787]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:14:06 gbvpi-bedroom sudo[13787]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:06 gbvpi-bedroom sudo[13790]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 15 15:14:06 gbvpi-bedroom sudo[13790]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 15 15:14:06 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: MRS: Pushing multiroomSync output for this device Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: MRS: Pushing multiroomSync output Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: Adding audio output: Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: Adding audio output: Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:14:06 gbvpi-bedroom bluetoothd[763]: Path / reserved for Adv Monitor app :1.108618 Dec 15 15:14:06 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 15 15:14:06 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 15:14:06 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.915s CPU time. Dec 15 15:14:06 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 15 15:14:06 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 15:14:06 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: Adding METAVOLUMIO REST API Endpoints Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 15 15:14:06 gbvpi-bedroom bluetoothd[763]: Adv Monitor app :1.108618 disconnected from D-Bus Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: Preparing CD Folders Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: Adding CD REST API Endpoints Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: Starting UDEV Watcher for CD Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: Detecting CD presence with UDEV Dec 15 15:14:06 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 15 15:14:06 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 15:14:06 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 15:14:06 gbvpi-bedroom sudo[13808]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 15:14:06 gbvpi-bedroom sudo[13808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 15:14:06 gbvpi-bedroom sudo[13808]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:07 gbvpi-bedroom mpd[13810]: 2025-12-15T15:14:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 15:14:07 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 15:14:07 gbvpi-bedroom sudo[13790]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:07 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 15 15:14:07 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:08 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:08 gbvpi-bedroom go-librespot[13813]: go-librespot daemon starting... Dec 15 15:14:08 gbvpi-bedroom go-librespot[13814]: time="2025-12-15T15:14:08-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:14:08 gbvpi-bedroom go-librespot[13814]: time="2025-12-15T15:14:08-05:00" level=debug msg="app state loaded" Dec 15 15:14:08 gbvpi-bedroom go-librespot[13814]: time="2025-12-15T15:14:08-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:14:08 gbvpi-bedroom go-librespot[13814]: time="2025-12-15T15:14: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-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 15 15:14:08 gbvpi-bedroom go-librespot[13814]: time="2025-12-15T15:14:08-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 15 15:14:08 gbvpi-bedroom go-librespot[13814]: time="2025-12-15T15:14:08-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 15 15:14:08 gbvpi-bedroom go-librespot[13814]: time="2025-12-15T15:14:08-05:00" level=info msg="zeroconf server listening on port 46829" Dec 15 15:14:08 gbvpi-bedroom go-librespot[13814]: time="2025-12-15T15:14:08-05:00" level=debug msg="obtained new client token: AACZMGO6KjovLuDIT4mQQuELYVNIKLmnzQmdfySJWw15TS3RV93M2xfz23DUmJMOSQ2nrvWDa+wtqJvFElT4W648DPKbC6hP5N0pD57p+Fi2fGqjxviBO00IVgSAb4I3fZQTJzDYSbFN1b/5WYgOUdP9tWGAEHNxUP5b2gqMNyfPoKE6HJmycPLNftOR/L6yT9QFsKEibn4UROZem8qYLBWOgdkjWGBVZ4tZgquJuiqXmv2tWGj+fnD3iw==" Dec 15 15:14:08 gbvpi-bedroom go-librespot[13814]: time="2025-12-15T15:14:08-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Dec 15 15:14:08 gbvpi-bedroom go-librespot[13814]: time="2025-12-15T15:14:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Dec 15 15:14:08 gbvpi-bedroom go-librespot[13814]: time="2025-12-15T15:14:08-05:00" level=debug msg="completed keyexchange" Dec 15 15:14:08 gbvpi-bedroom go-librespot[13814]: time="2025-12-15T15:14:08-05:00" level=debug msg="completed challenge" Dec 15 15:14:08 gbvpi-bedroom go-librespot[13814]: time="2025-12-15T15:14: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 15 15:14:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:14:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Adding inputs REST Endpoints Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Scanning Audio Inputs Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Checking against Known Cards name Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Adding Server instance for streaming Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: error: Hi Res Audio Failed Login: Missing Login Data Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 15 15:14:11 gbvpi-bedroom sudo[13839]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 15 15:14:11 gbvpi-bedroom sudo[13839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:14:11 gbvpi-bedroom sudo[13846]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 15 15:14:11 gbvpi-bedroom systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Dec 15 15:14:11 gbvpi-bedroom sudo[13846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:14:11 gbvpi-bedroom systemd[1]: vtcs.service: Killing process 13279 (vtcs) with signal SIGKILL. Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Adding TIDAL REST API Endpoints Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Stopping AccessToken refresher cron for QOBUZ Dec 15 15:14:11 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully. Dec 15 15:14:11 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 15 15:14:11 gbvpi-bedroom sudo[13839]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:11 gbvpi-bedroom sudo[13846]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:11 gbvpi-bedroom sudo[13849]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 15 15:14:11 gbvpi-bedroom sudo[13849]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: AccessToken refresher cron started for QOBUZ Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Adding QOBUZ REST API Endpoints Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Updating MyVolumio device info Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: MRS: Getting audio outputs on start Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: MRS: Requesting all other devices output Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:11 gbvpi-bedroom qobuz-connect[13216]: 20251215 15:14:11.287 [13216.13216] INFO SampleApp: Stopping Local configuration server Dec 15 15:14:11 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Successfully Updated MyVolumio device Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: MPD Permissions set Dec 15 15:14:11 gbvpi-bedroom sudo[13852]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 15 15:14:11 gbvpi-bedroom sudo[13852]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CorePlayQueue::getTrack 0 Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:14:11 gbvpi-bedroom sudo[13852]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CorePlayQueue::getTrack 0 Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: error: updateQueue error: null Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Listing playlists Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Listing playlists Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioStop Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreStateMachine::stop Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Listing playlists Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Listing playlists Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Starting Shairport Sync Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: MRS: Found cast device: Google-Home-Mini-f209fa314cb426d40a59bcf66354ddc9 Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Adding audio output: Dec 15 15:14:11 gbvpi-bedroom sudo[13869]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 15 15:14:11 gbvpi-bedroom sudo[13869]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: MRS: Found cast device: SmartTV-4K-fe72c264393a59c76d38e27b8168114d Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Adding audio output: Dec 15 15:14:11 gbvpi-bedroom sudo[13871]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 15:14:11 gbvpi-bedroom sudo[13871]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:14:11 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Successfully Added MyVolumio device Dec 15 15:14:11 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Successfully Updated MyVolumio device Dec 15 15:14:11 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:11 gbvpi-bedroom go-librespot[13874]: go-librespot daemon starting... Dec 15 15:14:11 gbvpi-bedroom autossh[13212]: received signal to exit (15) Dec 15 15:14:11 gbvpi-bedroom systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Dec 15 15:14:11 gbvpi-bedroom systemd[1]: sshtunnel.service: Deactivated successfully. Dec 15 15:14:11 gbvpi-bedroom systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 15 15:14:11 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 15 15:14:11 gbvpi-bedroom go-librespot[13875]: time="2025-12-15T15:14:11-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:14:11 gbvpi-bedroom go-librespot[13875]: time="2025-12-15T15:14:11-05:00" level=debug msg="app state loaded" Dec 15 15:14:11 gbvpi-bedroom go-librespot[13875]: time="2025-12-15T15:14:11-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:14:11 gbvpi-bedroom systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 15 15:14:11 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 15 15:14:11 gbvpi-bedroom sudo[13869]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:11 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 15:14:11 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.618s CPU time. Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Remote SSH Started Dec 15 15:14:11 gbvpi-bedroom autossh[13883]: port set to 0, monitoring disabled Dec 15 15:14:11 gbvpi-bedroom autossh[13883]: starting ssh (count 1) Dec 15 15:14:11 gbvpi-bedroom autossh[13883]: ssh child pid is 13887 Dec 15 15:14:11 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 15:14:11 gbvpi-bedroom sudo[13871]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: Shairport-Sync Started Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:11 gbvpi-bedroom volumiossh-tunnel[13887]: Warning: Permanently added '[us1.myvolumio.org]:2222' (RSA) to the list of known hosts. Dec 15 15:14:11 gbvpi-bedroom volumio[13382]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 15 15:14:11 gbvpi-bedroom go-librespot[13875]: time="2025-12-15T15:14:11-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 15:14:11 gbvpi-bedroom go-librespot[13875]: time="2025-12-15T15:14:11-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 15:14:11 gbvpi-bedroom go-librespot[13875]: time="2025-12-15T15:14:11-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 15:14:11 gbvpi-bedroom go-librespot[13875]: time="2025-12-15T15:14:11-05:00" level=info msg="zeroconf server listening on port 43619" Dec 15 15:14:11 gbvpi-bedroom go-librespot[13875]: time="2025-12-15T15:14:11-05:00" level=debug msg="obtained new client token: AAD4esLcBKCoAv7ZVxAq8+TfKBnHUXlWtO64STBhIzMOBcvwi29xLzVOBeu1pYbXjSvRvlkGa+Ddz+Iu2J5RiiEx+v5LbXAFHPb9odXJ5LEc8hNdkTck2AD4Q7RL6Oh87db/jaC3Uv2vosh+DaGhi9dG7Nju3brSgYXJlOdxLJySQqOISZHrMKBhbGaIhJYQvX6/PrHUHJWPTawE+Rayqaq0jEQECkyWQs45T6WlSyA2WYjbRL5HMWShcg==" Dec 15 15:14:12 gbvpi-bedroom go-librespot[13875]: time="2025-12-15T15:14:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:14:12 gbvpi-bedroom go-librespot[13875]: time="2025-12-15T15:14:12-05:00" level=debug msg="completed keyexchange" Dec 15 15:14:12 gbvpi-bedroom go-librespot[13875]: time="2025-12-15T15:14:12-05:00" level=debug msg="completed challenge" Dec 15 15:14:12 gbvpi-bedroom go-librespot[13875]: time="2025-12-15T15:14: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 15 15:14:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:14:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:14:12 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 15 15:14:12 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 15 15:14:12 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 15 15:14:12 gbvpi-bedroom sudo[13849]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:12 gbvpi-bedroom volumio[13382]: info: Executing endpoint qc_getconfig Dec 15 15:14:12 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 15 15:14:12 gbvpi-bedroom qobuz-connect[13903]: 20251215 15:14:12.795 [13903.13903] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 15 15:14:12 gbvpi-bedroom volumio[13382]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 15 15:14:12 gbvpi-bedroom volumio[13382]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 15 15:14:12 gbvpi-bedroom qobuz-connect[13903]: 20251215 15:14:12.798 [13903.13903] INFO VolumeManager: [0x613588]: Setting new playback volume: 75 Dec 15 15:14:12 gbvpi-bedroom qobuz-connect[13903]: 20251215 15:14:12.799 [13903.13903] INFO VolumeManager: [0x613588]: Setting new mute state: 0 Dec 15 15:14:12 gbvpi-bedroom qobuz-connect[13903]: 20251215 15:14:12.799 [13903.13903] INFO QobuzConnect: [0x613f58]: Client initialized! Dec 15 15:14:12 gbvpi-bedroom qobuz-connect[13903]: 20251215 15:14:12.799 [13903.13903] INFO SampleApp: Starting Avahi advertising, name: GBVPi-Bedroom, service name: _qobuz-connect._tcp Dec 15 15:14:12 gbvpi-bedroom qobuz-connect[13903]: 20251215 15:14:12.808 [13903.13903] INFO LocalConfigManager: [0x612e68]: Starting Local Configuration server Dec 15 15:14:12 gbvpi-bedroom qobuz-connect[13903]: 20251215 15:14:12.808 [13903.13903] INFO SampleApp: Starting Local configuration server Dec 15 15:14:12 gbvpi-bedroom qobuz-connect[13903]: 20251215 15:14:12.809 [13903.13903] INFO SampleApp: Connected to UNIX socket client 0x5fd818 Dec 15 15:14:12 gbvpi-bedroom qobuz-connect[13903]: 20251215 15:14:12.944 [13903.13903] INFO SampleApp: Playback volume changed: 75 Dec 15 15:14:12 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: TidalConnect service stoped! Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 15 15:14:14 gbvpi-bedroom sudo[13918]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 15 15:14:14 gbvpi-bedroom sudo[13918]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:14:14 gbvpi-bedroom sudo[13922]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 15:14:14 gbvpi-bedroom sudo[13922]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:14 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:14:14 gbvpi-bedroom sudo[13918]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:14 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 15:14:14 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 15:14:14 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 15:14:14 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 15:14:14 gbvpi-bedroom sudo[13922]: pam_unix(sudo:session): session closed for user root Dec 15 15:14:14 gbvpi-bedroom mpd_monitor.sh[13926]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: Successfully started MPD Monitor Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: Executing endpoint tc_getconfig Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 15 15:14:14 gbvpi-bedroom vtcs[13924]: STARTING TidalConnect services, version: 1.5.2.56 Dec 15 15:14:14 gbvpi-bedroom vtcs[13924]: STARTED TidalConnect services. Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: Executing endpoint tc_connect Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: Connecting to TidalConnect Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::servicePushState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreStateMachine::pushState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioPushState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: MRS: Pushing multiroomSync output update for this device Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: MRS: Pushing multiroomSync output Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CorePlayQueue::getTrack 0 Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: verbose: CURRENT POSITION 0 Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreStateMachine::syncState stateService stop Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreStateMachine::syncState currentStatus stop Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreStateMachine::pushState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioPushState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: MRS: Pushing multiroomSync output update for this device Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: MRS: Pushing multiroomSync output Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: No code Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreStateMachine::pushState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioPushState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: MRS: Pushing multiroomSync output update for this device Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: MRS: Pushing multiroomSync output Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::servicePushState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreStateMachine::pushState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioPushState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: MRS: Pushing multiroomSync output update for this device Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: MRS: Pushing multiroomSync output Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CorePlayQueue::getTrack 0 Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: verbose: CURRENT POSITION 0 Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreStateMachine::syncState stateService stop Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreStateMachine::syncState currentStatus stop Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreStateMachine::pushState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioPushState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: MRS: Pushing multiroomSync output update for this device Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: MRS: Pushing multiroomSync output Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: No code Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreStateMachine::pushState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioPushState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: MRS: Pushing multiroomSync output update for this device Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: MRS: Pushing multiroomSync output Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 15 15:14:14 gbvpi-bedroom volumio[13382]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 15 15:14:15 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 15 15:14:15 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:15 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:15 gbvpi-bedroom go-librespot[13944]: go-librespot daemon starting... Dec 15 15:14:15 gbvpi-bedroom go-librespot[13945]: time="2025-12-15T15:14:15-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:14:15 gbvpi-bedroom go-librespot[13945]: time="2025-12-15T15:14:15-05:00" level=debug msg="app state loaded" Dec 15 15:14:15 gbvpi-bedroom go-librespot[13945]: time="2025-12-15T15:14:15-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:14:15 gbvpi-bedroom go-librespot[13945]: time="2025-12-15T15:14: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-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 15 15:14:15 gbvpi-bedroom go-librespot[13945]: time="2025-12-15T15:14:15-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 15 15:14:15 gbvpi-bedroom go-librespot[13945]: time="2025-12-15T15:14:15-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 15 15:14:15 gbvpi-bedroom go-librespot[13945]: time="2025-12-15T15:14:15-05:00" level=info msg="zeroconf server listening on port 38007" Dec 15 15:14:15 gbvpi-bedroom go-librespot[13945]: time="2025-12-15T15:14:15-05:00" level=debug msg="obtained new client token: AABJwd24MIvRPDQ6jDitbv1up1/HBZtVouKqXhYvxUG1pzOxlTJufooDzvYg/MN8XlxvqIy06BFoqtNw824Nbt7nfwQX/BxsQabFEiWXT9bv8yP/TJtrPiucwaXJEIU5iWI6CcL5Nyw/MJOndhFZf4djxeVaBwVEgZas5SsNCkab0Q/JKHitB0fC8gyFjJRApVeYEkbkdTmnrm6e+TJ3i6WZ/EXKU57fPDX7ESPfVASYm+wz8nvutoHJzQ==" Dec 15 15:14:15 gbvpi-bedroom go-librespot[13945]: time="2025-12-15T15:14:15-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:14:15 gbvpi-bedroom go-librespot[13945]: time="2025-12-15T15:14:15-05:00" level=debug msg="completed keyexchange" Dec 15 15:14:15 gbvpi-bedroom go-librespot[13945]: time="2025-12-15T15:14:15-05:00" level=debug msg="completed challenge" Dec 15 15:14:15 gbvpi-bedroom go-librespot[13945]: time="2025-12-15T15:14:15-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 15:14:15 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:14:15 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:14:17 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:17 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:14:17 gbvpi-bedroom volumio[13382]: info: TidalConnect service started! Dec 15 15:14:17 gbvpi-bedroom volumio[13382]: [Metrics] CommandRouter: 29s 327.22ms Dec 15 15:14:17 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumiosetStartupVolume Dec 15 15:14:17 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:14:17 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:14:17 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::Close All Modals sent Dec 15 15:14:17 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::Close All Modals sent Dec 15 15:14:18 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 15 15:14:18 gbvpi-bedroom volumio[13382]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 15 15:14:18 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:18 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 15 15:14:18 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 15 15:14:18 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 15 15:14:18 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Dec 15 15:14:18 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:19 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:19 gbvpi-bedroom go-librespot[13955]: go-librespot daemon starting... Dec 15 15:14:19 gbvpi-bedroom go-librespot[13956]: time="2025-12-15T15:14:19-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:14:19 gbvpi-bedroom go-librespot[13956]: time="2025-12-15T15:14:19-05:00" level=debug msg="app state loaded" Dec 15 15:14:19 gbvpi-bedroom go-librespot[13956]: time="2025-12-15T15:14:19-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:14:19 gbvpi-bedroom go-librespot[13956]: time="2025-12-15T15:14: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-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 15 15:14:19 gbvpi-bedroom go-librespot[13956]: time="2025-12-15T15:14:19-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 15 15:14:19 gbvpi-bedroom go-librespot[13956]: time="2025-12-15T15:14:19-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 15 15:14:19 gbvpi-bedroom go-librespot[13956]: time="2025-12-15T15:14:19-05:00" level=info msg="zeroconf server listening on port 35887" Dec 15 15:14:19 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:19 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:19 gbvpi-bedroom go-librespot[13956]: time="2025-12-15T15:14:19-05:00" level=debug msg="obtained new client token: AABmtUwdLPwohds91cDuj82aqfa48ymxxem2OLOgEJFy+G6UjR5qavvTn33ad6KXy1Oj9kyuhUVc6l+pq/yyXbk4ZgvxIMX5qRtCle/kP39cWKVTkFf+7euw2hfZ4F1vTWTYUdfwSaulovBB3dE6cpKQX2V8ef2mf72ZxcX2OV1M1NDc8VnEQZdApXlif8vKT41TJZgSxJebL4O0ahtT8i2YivBuhBgoSkDdKdQ9Qz/cWTmcIlDN/bNQVQ==" Dec 15 15:14:19 gbvpi-bedroom go-librespot[13956]: time="2025-12-15T15:14:19-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:14:19 gbvpi-bedroom go-librespot[13956]: time="2025-12-15T15:14:19-05:00" level=debug msg="completed keyexchange" Dec 15 15:14:19 gbvpi-bedroom go-librespot[13956]: time="2025-12-15T15:14:19-05:00" level=debug msg="completed challenge" Dec 15 15:14:19 gbvpi-bedroom go-librespot[13956]: time="2025-12-15T15:14:19-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 15:14:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:14:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:14:20 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:20 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:14:22 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 15:14:22 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:14:22 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 15:14:22 gbvpi-bedroom volumio-remote-updater[775]: Test mode enabled Dec 15 15:14:22 gbvpi-bedroom volumio-remote-updater[775]: Alpha mode disabled Dec 15 15:14:22 gbvpi-bedroom volumio-remote-updater[775]: Alpha legacy test mode disabled Dec 15 15:14:22 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 15 15:14:22 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 15 15:14:22 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:22 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:22 gbvpi-bedroom go-librespot[13982]: go-librespot daemon starting... Dec 15 15:14:22 gbvpi-bedroom go-librespot[13983]: time="2025-12-15T15:14:22-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:14:22 gbvpi-bedroom go-librespot[13983]: time="2025-12-15T15:14:22-05:00" level=debug msg="app state loaded" Dec 15 15:14:22 gbvpi-bedroom go-librespot[13983]: time="2025-12-15T15:14:22-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:14:22 gbvpi-bedroom volumio[13382]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

CAUTION

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

FIX

\n
    \n
  • Wireless and network handling
    • \n
\n","title":"Update v4.080","updateavailable":true} Dec 15 15:14:22 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 15 15:14:22 gbvpi-bedroom go-librespot[13983]: time="2025-12-15T15:14:22-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 15 15:14:22 gbvpi-bedroom go-librespot[13983]: time="2025-12-15T15:14:22-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 15 15:14:22 gbvpi-bedroom go-librespot[13983]: time="2025-12-15T15:14:22-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 15 15:14:22 gbvpi-bedroom go-librespot[13983]: time="2025-12-15T15:14:22-05:00" level=info msg="zeroconf server listening on port 46495" Dec 15 15:14:23 gbvpi-bedroom go-librespot[13983]: time="2025-12-15T15:14:23-05:00" level=debug msg="obtained new client token: AAC1P1+2eexFhcrxCZZE9zwjM5Yx7s9WLvvGSi/n2sbivCx8KwvXQ7h6Gh9rLP+YacdjDzFbxRksQE3pO1le6FXLXzS5xiBibd5JN0Y6DJ5y2DqaWLoHldX7cwCLM31u+qKRdBaMxTdEvJNAGsyBk7D36TjjmFNZg9q7ipIly9zMWzUf6SAplCxtIp0AHCbaSUn/i+WhxTWSC3nCI7D5Udk8XhbErgKNGLPQoTUiruAoQZ9YBVoFZ5c=" Dec 15 15:14:23 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:14:23 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:14:23 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 15 15:14:23 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 15 15:14:23 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 15 15:14:23 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 15:14:23 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 15:14:23 gbvpi-bedroom go-librespot[13983]: time="2025-12-15T15:14:23-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:14:23 gbvpi-bedroom go-librespot[13983]: time="2025-12-15T15:14:23-05:00" level=debug msg="completed keyexchange" Dec 15 15:14:23 gbvpi-bedroom go-librespot[13983]: time="2025-12-15T15:14:23-05:00" level=debug msg="completed challenge" Dec 15 15:14:23 gbvpi-bedroom go-librespot[13983]: time="2025-12-15T15:14:23-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 15:14:23 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:14:23 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:14:23 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:23 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:14:24 gbvpi-bedroom volumio[13382]: info: BOOT COMPLETED Dec 15 15:14:26 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:26 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:14:26 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Dec 15 15:14:26 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:26 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:26 gbvpi-bedroom go-librespot[13991]: go-librespot daemon starting... Dec 15 15:14:26 gbvpi-bedroom go-librespot[13992]: time="2025-12-15T15:14:26-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:14:26 gbvpi-bedroom go-librespot[13992]: time="2025-12-15T15:14:26-05:00" level=debug msg="app state loaded" Dec 15 15:14:26 gbvpi-bedroom go-librespot[13992]: time="2025-12-15T15:14:26-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:14:26 gbvpi-bedroom go-librespot[13992]: time="2025-12-15T15:14:26-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 15 15:14:26 gbvpi-bedroom go-librespot[13992]: time="2025-12-15T15:14:26-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 15 15:14:26 gbvpi-bedroom go-librespot[13992]: time="2025-12-15T15:14:26-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 15 15:14:26 gbvpi-bedroom go-librespot[13992]: time="2025-12-15T15:14:26-05:00" level=info msg="zeroconf server listening on port 33457" Dec 15 15:14:26 gbvpi-bedroom go-librespot[13992]: time="2025-12-15T15:14:26-05:00" level=debug msg="obtained new client token: AAAI1f/h0yYq5iDtzsktW5vCctjJLd0M9HfJXYus0VeMM1kKpz/e6xFexRyawwqdfYfa7UWhbxmulpgTGd12IWy2d1Z2uq9WnEjQtoHL9/8nrUIw5vzwYi+1rftz/rUMNe1ZxAsCJewB5gFJVBuq6Qb8Kp5pktgI175YMfysJG5HDeQ+Syf+F7nntFSfT/nirSogXRJ9VNo2Qb90yDBNXyod5fVcvrPx3CmqL+vPXISZ5Vp+vcWnsXKHxw==" Dec 15 15:14:26 gbvpi-bedroom go-librespot[13992]: time="2025-12-15T15:14:26-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:14:26 gbvpi-bedroom go-librespot[13992]: time="2025-12-15T15:14:26-05:00" level=debug msg="completed keyexchange" Dec 15 15:14:26 gbvpi-bedroom go-librespot[13992]: time="2025-12-15T15:14:26-05:00" level=debug msg="completed challenge" Dec 15 15:14:26 gbvpi-bedroom go-librespot[13992]: time="2025-12-15T15:14:26-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 15:14:26 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:14:26 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:14:29 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:29 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:29 gbvpi-bedroom volumio[13382]: info: Listing playlists Dec 15 15:14:29 gbvpi-bedroom volumio[13382]: info: Listing playlists Dec 15 15:14:29 gbvpi-bedroom volumio[13382]: info: Listing playlists Dec 15 15:14:29 gbvpi-bedroom volumio[13382]: info: Listing playlists Dec 15 15:14:29 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:29 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:14:30 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Dec 15 15:14:30 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:30 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:30 gbvpi-bedroom go-librespot[14013]: go-librespot daemon starting... Dec 15 15:14:30 gbvpi-bedroom go-librespot[14014]: time="2025-12-15T15:14:30-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:14:30 gbvpi-bedroom go-librespot[14014]: time="2025-12-15T15:14:30-05:00" level=debug msg="app state loaded" Dec 15 15:14:30 gbvpi-bedroom go-librespot[14014]: time="2025-12-15T15:14:30-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:14:30 gbvpi-bedroom go-librespot[14014]: time="2025-12-15T15:14:30-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 15:14:30 gbvpi-bedroom go-librespot[14014]: time="2025-12-15T15:14:30-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 15:14:30 gbvpi-bedroom go-librespot[14014]: time="2025-12-15T15:14:30-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 15:14:30 gbvpi-bedroom go-librespot[14014]: time="2025-12-15T15:14:30-05:00" level=info msg="zeroconf server listening on port 36871" Dec 15 15:14:30 gbvpi-bedroom go-librespot[14014]: time="2025-12-15T15:14:30-05:00" level=debug msg="obtained new client token: AACQP+ny4GBjexlcMCCtwsyBlp/Ej7NPvlzVUo4OSA+0uIsd4ReFY2VGyFl39hN6OhldkaM69m4AIpjZnankM3s2HpsbwfXdxO/TuXm0+VuNM7baUY79SG1Ei5h4t5UzaJPN6OtlOMuNox7qhkhwjTtWRUoWIXQn7neNFGYJnNZWc4IwJUvZRweinqj4be7kUFAdz4jxYkB6cSZi4K11GFb+f8ULVwC/h1yjdNiLh61FA6oVq8W4G+3uCg==" Dec 15 15:14:30 gbvpi-bedroom go-librespot[14014]: time="2025-12-15T15:14:30-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:14:30 gbvpi-bedroom go-librespot[14014]: time="2025-12-15T15:14:30-05:00" level=debug msg="completed keyexchange" Dec 15 15:14:30 gbvpi-bedroom go-librespot[14014]: time="2025-12-15T15:14:30-05:00" level=debug msg="completed challenge" Dec 15 15:14:30 gbvpi-bedroom go-librespot[14014]: time="2025-12-15T15:14:30-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 15:14:30 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:14:30 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:14:32 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:32 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:14:33 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Dec 15 15:14:33 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:33 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:33 gbvpi-bedroom go-librespot[14021]: go-librespot daemon starting... Dec 15 15:14:33 gbvpi-bedroom go-librespot[14022]: time="2025-12-15T15:14:33-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:14:33 gbvpi-bedroom go-librespot[14022]: time="2025-12-15T15:14:33-05:00" level=debug msg="app state loaded" Dec 15 15:14:33 gbvpi-bedroom go-librespot[14022]: time="2025-12-15T15:14:33-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:14:34 gbvpi-bedroom go-librespot[14022]: time="2025-12-15T15:14:34-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 15:14:34 gbvpi-bedroom go-librespot[14022]: time="2025-12-15T15:14:34-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 15:14:34 gbvpi-bedroom go-librespot[14022]: time="2025-12-15T15:14:34-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 15:14:34 gbvpi-bedroom go-librespot[14022]: time="2025-12-15T15:14:34-05:00" level=info msg="zeroconf server listening on port 42167" Dec 15 15:14:34 gbvpi-bedroom go-librespot[14022]: time="2025-12-15T15:14:34-05:00" level=debug msg="obtained new client token: AABRiyVyUg2pqRf7zLtDANgauDDvmXpdOrG3iBBqexOxI+sZHYhKKMY15vcxGYypUbK/o+/AOwJ/jIy4tRTdqm/d1+JAeD6A6eLZYCpajLLefL+tz3Vnqj2iMGizDnZ9w9yGumb01GKqH+gflUlrwszY5pYmBHQiagIVoo6gHHtSUD7S6/F0QZ9yCzC5QsvQ8Xmk/1xcVO50xRCMLSMGlu7KbrWYSDENyWIdiWcxhhpd2lQIvoR/aRAXzQ==" Dec 15 15:14:34 gbvpi-bedroom go-librespot[14022]: time="2025-12-15T15:14:34-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:14:35 gbvpi-bedroom go-librespot[14022]: time="2025-12-15T15:14:35-05:00" level=debug msg="completed keyexchange" Dec 15 15:14:35 gbvpi-bedroom go-librespot[14022]: time="2025-12-15T15:14:35-05:00" level=debug msg="completed challenge" Dec 15 15:14:35 gbvpi-bedroom go-librespot[14022]: time="2025-12-15T15:14:35-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 15:14:35 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:14:35 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:14:35 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:35 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:14:38 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:38 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:14:38 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Dec 15 15:14:38 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:38 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:38 gbvpi-bedroom go-librespot[14032]: go-librespot daemon starting... Dec 15 15:14:38 gbvpi-bedroom go-librespot[14033]: time="2025-12-15T15:14:38-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:14:38 gbvpi-bedroom go-librespot[14033]: time="2025-12-15T15:14:38-05:00" level=debug msg="app state loaded" Dec 15 15:14:38 gbvpi-bedroom go-librespot[14033]: time="2025-12-15T15:14:38-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:14:38 gbvpi-bedroom go-librespot[14033]: time="2025-12-15T15:14: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 15:14:38 gbvpi-bedroom go-librespot[14033]: time="2025-12-15T15:14:38-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 15:14:38 gbvpi-bedroom go-librespot[14033]: time="2025-12-15T15:14:38-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 15:14:38 gbvpi-bedroom go-librespot[14033]: time="2025-12-15T15:14:38-05:00" level=info msg="zeroconf server listening on port 37099" Dec 15 15:14:38 gbvpi-bedroom go-librespot[14033]: time="2025-12-15T15:14:38-05:00" level=debug msg="obtained new client token: AADOUkms+Muvu+OssyNAU/wzZWniOYw38wrT/W4D8+D9bJydkdWr5mXlO9k0Wqi4+VtcJE8trMM4IrP6abPneowdlZC6YFwFpfN7JRnmXaEWqXtnxRhDu2ZQ1Ow6glHIWYuikI4Rai5HfDDs56tSIJ/niSWSuoY9fp5y0YAO2nKC5VwZGvMPFFyaZCq49q7MU2Hotx4OkyYOkoexWevTkuXsW15879cHBmAC4pOxBcHeDw0+DW3uk3P9nw==" Dec 15 15:14:38 gbvpi-bedroom go-librespot[14033]: time="2025-12-15T15:14:38-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:14:38 gbvpi-bedroom go-librespot[14033]: time="2025-12-15T15:14:38-05:00" level=debug msg="completed keyexchange" Dec 15 15:14:38 gbvpi-bedroom go-librespot[14033]: time="2025-12-15T15:14:38-05:00" level=debug msg="completed challenge" Dec 15 15:14:38 gbvpi-bedroom go-librespot[14033]: time="2025-12-15T15:14:38-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 15:14:38 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:14:38 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:14:39 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:39 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:41 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:41 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:14:42 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Dec 15 15:14:42 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:42 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:42 gbvpi-bedroom go-librespot[14056]: go-librespot daemon starting... Dec 15 15:14:42 gbvpi-bedroom go-librespot[14057]: time="2025-12-15T15:14:42-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:14:42 gbvpi-bedroom go-librespot[14057]: time="2025-12-15T15:14:42-05:00" level=debug msg="app state loaded" Dec 15 15:14:42 gbvpi-bedroom go-librespot[14057]: time="2025-12-15T15:14:42-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:14:42 gbvpi-bedroom go-librespot[14057]: time="2025-12-15T15:14: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 15 15:14:42 gbvpi-bedroom go-librespot[14057]: time="2025-12-15T15:14: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 15 15:14:42 gbvpi-bedroom go-librespot[14057]: time="2025-12-15T15:14: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 15 15:14:42 gbvpi-bedroom go-librespot[14057]: time="2025-12-15T15:14:42-05:00" level=info msg="zeroconf server listening on port 42181" Dec 15 15:14:42 gbvpi-bedroom go-librespot[14057]: time="2025-12-15T15:14:42-05:00" level=debug msg="obtained new client token: AACWjhmn53H3nxjphtX2LJBPiSiySY6OYIoy54ZHVhvL0GP+T11yf9faW8yuS9/2nbCKT5l9yv4b9v9S62rQycdi61mj6xw+sGETwRdDtNiImgVoe5tjgme6COHuCAOYixsoJ00vSJMQysd45IOD0E8SMopSIWFZyFEKmDrAHuHNm8L8H0D/TRV8v0j6qlXr97NH4A4VUfSsZPplJL0r9nNdupevgN5JzyzuchwJd1FjjnInTtlOK4lclg==" Dec 15 15:14:42 gbvpi-bedroom go-librespot[14057]: time="2025-12-15T15:14:42-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:14:42 gbvpi-bedroom go-librespot[14057]: time="2025-12-15T15:14:42-05:00" level=debug msg="completed keyexchange" Dec 15 15:14:42 gbvpi-bedroom go-librespot[14057]: time="2025-12-15T15:14:42-05:00" level=debug msg="completed challenge" Dec 15 15:14:42 gbvpi-bedroom go-librespot[14057]: time="2025-12-15T15:14:42-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 15:14:42 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:14:42 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:14:44 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:44 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:14:45 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Dec 15 15:14:45 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:46 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:46 gbvpi-bedroom go-librespot[14065]: go-librespot daemon starting... Dec 15 15:14:46 gbvpi-bedroom go-librespot[14066]: time="2025-12-15T15:14:46-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:14:46 gbvpi-bedroom go-librespot[14066]: time="2025-12-15T15:14:46-05:00" level=debug msg="app state loaded" Dec 15 15:14:46 gbvpi-bedroom go-librespot[14066]: time="2025-12-15T15:14:46-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:14:46 gbvpi-bedroom go-librespot[14066]: time="2025-12-15T15:14: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 15:14:46 gbvpi-bedroom go-librespot[14066]: time="2025-12-15T15:14:46-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 15:14:46 gbvpi-bedroom go-librespot[14066]: time="2025-12-15T15:14:46-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 15:14:46 gbvpi-bedroom go-librespot[14066]: time="2025-12-15T15:14:46-05:00" level=info msg="zeroconf server listening on port 35263" Dec 15 15:14:46 gbvpi-bedroom go-librespot[14066]: time="2025-12-15T15:14:46-05:00" level=debug msg="obtained new client token: AADGlR/o/HOstkdQw4VPq6PkAvyzqt+rI+i3v5NwSMZqt9/I+dvekCute7TGlMdN/eonTpIJBPnurgaF26AHgvsKYhJEbSdRW5/+OGo2U/JipuR64n087Z6+iJLORu0+H/grLC4aNMr0KD3QOL7wAATjqAILWQe+V1KLUUZtdt6HTVanXCnOAoww/fVOB3URBgCIffVU5Lsk/67jhgiL7WAcxMJNG8E/dREAGe97ZrIYTzUZTE/ECPbZUw==" Dec 15 15:14:46 gbvpi-bedroom go-librespot[14066]: time="2025-12-15T15:14:46-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:14:46 gbvpi-bedroom go-librespot[14066]: time="2025-12-15T15:14:46-05:00" level=debug msg="completed keyexchange" Dec 15 15:14:46 gbvpi-bedroom go-librespot[14066]: time="2025-12-15T15:14:46-05:00" level=debug msg="completed challenge" Dec 15 15:14:46 gbvpi-bedroom go-librespot[14066]: time="2025-12-15T15:14:46-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 15:14:46 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:14:46 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:14:47 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:47 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:14:49 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:49 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:49 gbvpi-bedroom volumio[13382]: info: Listing playlists Dec 15 15:14:49 gbvpi-bedroom volumio[13382]: info: Listing playlists Dec 15 15:14:49 gbvpi-bedroom volumio[13382]: info: Listing playlists Dec 15 15:14:49 gbvpi-bedroom volumio[13382]: info: Listing playlists Dec 15 15:14:49 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Dec 15 15:14:49 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:49 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:49 gbvpi-bedroom go-librespot[14087]: go-librespot daemon starting... Dec 15 15:14:49 gbvpi-bedroom go-librespot[14088]: time="2025-12-15T15:14:49-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:14:49 gbvpi-bedroom go-librespot[14088]: time="2025-12-15T15:14:49-05:00" level=debug msg="app state loaded" Dec 15 15:14:49 gbvpi-bedroom go-librespot[14088]: time="2025-12-15T15:14:49-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:14:49 gbvpi-bedroom go-librespot[14088]: time="2025-12-15T15:14: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 15:14:49 gbvpi-bedroom go-librespot[14088]: time="2025-12-15T15:14:49-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 15:14:49 gbvpi-bedroom go-librespot[14088]: time="2025-12-15T15:14:49-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 15:14:49 gbvpi-bedroom go-librespot[14088]: time="2025-12-15T15:14:49-05:00" level=info msg="zeroconf server listening on port 43029" Dec 15 15:14:50 gbvpi-bedroom go-librespot[14088]: time="2025-12-15T15:14:50-05:00" level=debug msg="obtained new client token: AAAG3f+N7wUdEJGjaUr8hX9sstor6KQYgXR2IN9aL6OV9ehIAW6Zkfr2r0ReKU+kGC34oRad98CUvJzM1U2774Ilwxhqx52qxk8mHHHmxswe6OUzzMHzsJGO9LhE8YAsT0qULvFdhwEyMR/xPpFbwjl4Gy4MQZ/Y5r4Cgt787Y2JdvMujGGPiEfhYb0tVxnZeVwCzTkDnoy9CB6pokY9/1W7AuJHigzRzDkLoOANwPEo1auAUM5tOfE=" Dec 15 15:14:50 gbvpi-bedroom go-librespot[14088]: time="2025-12-15T15:14:50-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:14:50 gbvpi-bedroom go-librespot[14088]: time="2025-12-15T15:14:50-05:00" level=debug msg="completed keyexchange" Dec 15 15:14:50 gbvpi-bedroom go-librespot[14088]: time="2025-12-15T15:14:50-05:00" level=debug msg="completed challenge" Dec 15 15:14:50 gbvpi-bedroom go-librespot[14088]: time="2025-12-15T15:14:50-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 15:14:50 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:14:50 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:14:50 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:50 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:14:52 gbvpi-bedroom volumio[13382]: info: UPDATER: Scheduling automatic update Dec 15 15:14:52 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStartTime Dec 15 15:14:52 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStopTime Dec 15 15:14:52 gbvpi-bedroom volumio[13382]: info: UPDATER: Auto update will take place at: Tue Dec 16 2025 04:58:41 GMT-0500 (Eastern Standard Time) Dec 15 15:14:53 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:53 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:14:53 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Dec 15 15:14:53 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:53 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:53 gbvpi-bedroom go-librespot[14095]: go-librespot daemon starting... Dec 15 15:14:53 gbvpi-bedroom go-librespot[14096]: time="2025-12-15T15:14:53-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:14:53 gbvpi-bedroom go-librespot[14096]: time="2025-12-15T15:14:53-05:00" level=debug msg="app state loaded" Dec 15 15:14:53 gbvpi-bedroom go-librespot[14096]: time="2025-12-15T15:14:53-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:14:53 gbvpi-bedroom go-librespot[14096]: time="2025-12-15T15:14:53-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 15 15:14:53 gbvpi-bedroom go-librespot[14096]: time="2025-12-15T15:14:53-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 15 15:14:53 gbvpi-bedroom go-librespot[14096]: time="2025-12-15T15:14:53-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 15 15:14:53 gbvpi-bedroom go-librespot[14096]: time="2025-12-15T15:14:53-05:00" level=info msg="zeroconf server listening on port 42861" Dec 15 15:14:53 gbvpi-bedroom go-librespot[14096]: time="2025-12-15T15:14:53-05:00" level=debug msg="obtained new client token: AAB1qB8qbnTdv4fVgGrydA7G4pP1TrDICSLt0kUzGzNU/5zLHd7aTRtcnWRATDgYkGQxdrHjPnrvMz28x6j16WgNjQMLGRa66lFdNZCXuz6NF7c2zGJZOp7c0b9oR+3aw0kgzsRuDNUXwrdKESBpYWzP1SOePYk1t6wEJe/Mh8CuZWE2vTwpZbTorfy/bMrNKJerwB7BMha4awxB1xj4MrsIIMRobX4NMprQsl2G2X8+gxB1XljKTrtwEg==" Dec 15 15:14:54 gbvpi-bedroom go-librespot[14096]: time="2025-12-15T15:14:54-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:14:54 gbvpi-bedroom go-librespot[14096]: time="2025-12-15T15:14:54-05:00" level=debug msg="completed keyexchange" Dec 15 15:14:54 gbvpi-bedroom go-librespot[14096]: time="2025-12-15T15:14:54-05:00" level=debug msg="completed challenge" Dec 15 15:14:54 gbvpi-bedroom go-librespot[14096]: time="2025-12-15T15:14:54-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 15:14:54 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:14:54 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:14:56 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:56 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:14:57 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Dec 15 15:14:57 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:57 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:14:57 gbvpi-bedroom go-librespot[14106]: go-librespot daemon starting... Dec 15 15:14:57 gbvpi-bedroom go-librespot[14107]: time="2025-12-15T15:14:57-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:14:57 gbvpi-bedroom go-librespot[14107]: time="2025-12-15T15:14:57-05:00" level=debug msg="app state loaded" Dec 15 15:14:57 gbvpi-bedroom go-librespot[14107]: time="2025-12-15T15:14:57-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:14:57 gbvpi-bedroom go-librespot[14107]: time="2025-12-15T15:14:57-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 15:14:57 gbvpi-bedroom go-librespot[14107]: time="2025-12-15T15:14:57-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 15:14:57 gbvpi-bedroom go-librespot[14107]: time="2025-12-15T15:14:57-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 15:14:57 gbvpi-bedroom go-librespot[14107]: time="2025-12-15T15:14:57-05:00" level=info msg="zeroconf server listening on port 42039" Dec 15 15:14:57 gbvpi-bedroom go-librespot[14107]: time="2025-12-15T15:14:57-05:00" level=debug msg="obtained new client token: AAAF1/GB0C8Pfqal9mIJFhy3d/FZ6OWZhEPw5nltCrbVc/HeLas05KBleAP1FkJgamHglKHTVeWOEMxs50JaiXwkLrZi/2Wqsf7ZwFMxG+Md1VB/ySEXF5B7AJ0j70M+I3NOXt7brHDuyLnVlpHPBBkwU70lWpdGuG8xKGzv9zOHSyOg2reJy4O/4JpbwzZJWinpD7gG8xoMPtVs8uQbOR0PddgHVxJ6IgAT7FvwuVkje2geyFBGSELH5w==" Dec 15 15:14:57 gbvpi-bedroom go-librespot[14107]: time="2025-12-15T15:14:57-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:14:57 gbvpi-bedroom go-librespot[14107]: time="2025-12-15T15:14:57-05:00" level=debug msg="completed keyexchange" Dec 15 15:14:57 gbvpi-bedroom go-librespot[14107]: time="2025-12-15T15:14:57-05:00" level=debug msg="completed challenge" Dec 15 15:14:57 gbvpi-bedroom go-librespot[14107]: time="2025-12-15T15:14: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 15 15:14:57 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:14:57 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:14:59 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:59 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:14:59 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:14:59 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:15:00 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Dec 15 15:15:00 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:15:01 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:15:01 gbvpi-bedroom go-librespot[14128]: go-librespot daemon starting... Dec 15 15:15:01 gbvpi-bedroom go-librespot[14129]: time="2025-12-15T15:15:01-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:15:01 gbvpi-bedroom go-librespot[14129]: time="2025-12-15T15:15:01-05:00" level=debug msg="app state loaded" Dec 15 15:15:01 gbvpi-bedroom go-librespot[14129]: time="2025-12-15T15:15:01-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:15:01 gbvpi-bedroom go-librespot[14129]: time="2025-12-15T15:15:01-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 15:15:01 gbvpi-bedroom go-librespot[14129]: time="2025-12-15T15:15:01-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 15:15:01 gbvpi-bedroom go-librespot[14129]: time="2025-12-15T15:15:01-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 15:15:01 gbvpi-bedroom go-librespot[14129]: time="2025-12-15T15:15:01-05:00" level=info msg="zeroconf server listening on port 42227" Dec 15 15:15:01 gbvpi-bedroom go-librespot[14129]: time="2025-12-15T15:15:01-05:00" level=debug msg="obtained new client token: AABUs0FuNqwPGX+TjIUqFT+zAzxAGXG4GbUG125iXcRsQAjDyjh2R2S9wQjhgnxR+KM8ty8G5YKPWEOTUG08gapB6P8wuzNT6t5CHWINxTFu47TPUXKk+bB5b7gC41Ce14Gs4zKOS7NBUO5fgszz1UFwqMBI6M6cxsCI7IEeVcqgxzwKTwf3X1w9ri/jGwYqVy0Ps/4+AYRTGj6ki648tOrmd/VhkgkIid9y/TrblyRhrDB5P0a6jqeZsQ==" Dec 15 15:15:01 gbvpi-bedroom go-librespot[14129]: time="2025-12-15T15:15:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:15:01 gbvpi-bedroom go-librespot[14129]: time="2025-12-15T15:15:01-05:00" level=debug msg="completed keyexchange" Dec 15 15:15:01 gbvpi-bedroom go-librespot[14129]: time="2025-12-15T15:15:01-05:00" level=debug msg="completed challenge" Dec 15 15:15:01 gbvpi-bedroom go-librespot[14129]: time="2025-12-15T15:15:01-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 15:15:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:15:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:15:02 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:15:02 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:15:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Dec 15 15:15:04 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:15:04 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:15:04 gbvpi-bedroom go-librespot[14138]: go-librespot daemon starting... Dec 15 15:15:04 gbvpi-bedroom go-librespot[14139]: time="2025-12-15T15:15:04-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:15:04 gbvpi-bedroom go-librespot[14139]: time="2025-12-15T15:15:04-05:00" level=debug msg="app state loaded" Dec 15 15:15:04 gbvpi-bedroom go-librespot[14139]: time="2025-12-15T15:15:04-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:15:04 gbvpi-bedroom go-librespot[14139]: time="2025-12-15T15:15: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-gew4.spotify.com:80]" Dec 15 15:15:04 gbvpi-bedroom go-librespot[14139]: time="2025-12-15T15:15:04-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 15:15:04 gbvpi-bedroom go-librespot[14139]: time="2025-12-15T15:15:04-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 15:15:04 gbvpi-bedroom go-librespot[14139]: time="2025-12-15T15:15:04-05:00" level=info msg="zeroconf server listening on port 39323" Dec 15 15:15:05 gbvpi-bedroom go-librespot[14139]: time="2025-12-15T15:15:05-05:00" level=debug msg="obtained new client token: AABpgpifEJYMxw2F0+3mSLV6UTM2NI6cm9/P1pWY1z1FG8sUIRrRTywnnFTQWyvUjMMoKc1Od3ylcFuSS/rOW6GxZvnYKrTUhrF1+yKF2cz8kEBDjE9ILUZckEhwJTUwPE4tTFtydl1j1XH6/pPHnI7GY/qAsU7Jva1SrNYJtN3jtH7unlmt8dFUAvh4I+EZ4zrv3/Qbw/4owlLTCgPXoZ7fLuhUbxsKkPfHWD2XqLc0aIqcIc8dAx8=" Dec 15 15:15:05 gbvpi-bedroom go-librespot[14139]: time="2025-12-15T15:15:05-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:15:05 gbvpi-bedroom go-librespot[14139]: time="2025-12-15T15:15:05-05:00" level=debug msg="completed keyexchange" Dec 15 15:15:05 gbvpi-bedroom go-librespot[14139]: time="2025-12-15T15:15:05-05:00" level=debug msg="completed challenge" Dec 15 15:15:05 gbvpi-bedroom go-librespot[14139]: time="2025-12-15T15:15:05-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 15:15:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:15:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:15:05 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:15:05 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:15:08 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:15:08 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:15:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Dec 15 15:15:08 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:15:08 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:15:08 gbvpi-bedroom go-librespot[14148]: go-librespot daemon starting... Dec 15 15:15:08 gbvpi-bedroom go-librespot[14149]: time="2025-12-15T15:15:08-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:15:08 gbvpi-bedroom go-librespot[14149]: time="2025-12-15T15:15:08-05:00" level=debug msg="app state loaded" Dec 15 15:15:08 gbvpi-bedroom go-librespot[14149]: time="2025-12-15T15:15:08-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:15:08 gbvpi-bedroom go-librespot[14149]: time="2025-12-15T15:15:08-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 15:15:08 gbvpi-bedroom go-librespot[14149]: time="2025-12-15T15:15:08-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 15:15:08 gbvpi-bedroom go-librespot[14149]: time="2025-12-15T15:15:08-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 15:15:08 gbvpi-bedroom go-librespot[14149]: time="2025-12-15T15:15:08-05:00" level=info msg="zeroconf server listening on port 36855" Dec 15 15:15:08 gbvpi-bedroom go-librespot[14149]: time="2025-12-15T15:15:08-05:00" level=debug msg="obtained new client token: AADbHISnRlz9XL8m/GIV7fHTUKWq7Pwi8LDeuP3SUF5Pdk1Mu3oGnlahprmgThLQpPVlgdTx5nMkDr5Vub/ZAZcWcA3tMc+hybKXDDN1rX2g1UHEEjoSVOs3U2uOQpBjhtJAvJ/Wv7rLOreG1FPtTTALLIJFo6i4Zu844dkO3pgYKF14a/ZzrugkKdJ0ehQaYRmLsoY4YEKK2VwCkv4xdtTQeRzrpH63UwG37Vo4FVVgf4VmsQU76X7u4g==" Dec 15 15:15:08 gbvpi-bedroom go-librespot[14149]: time="2025-12-15T15:15:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:15:08 gbvpi-bedroom go-librespot[14149]: time="2025-12-15T15:15:08-05:00" level=debug msg="completed keyexchange" Dec 15 15:15:08 gbvpi-bedroom go-librespot[14149]: time="2025-12-15T15:15:08-05:00" level=debug msg="completed challenge" Dec 15 15:15:08 gbvpi-bedroom go-librespot[14149]: time="2025-12-15T15:15: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 15 15:15:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:15:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:15:09 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:15:09 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:15:09 gbvpi-bedroom volumio[13382]: info: Listing playlists Dec 15 15:15:09 gbvpi-bedroom volumio[13382]: info: Listing playlists Dec 15 15:15:09 gbvpi-bedroom volumio[13382]: info: Listing playlists Dec 15 15:15:09 gbvpi-bedroom volumio[13382]: info: Listing playlists Dec 15 15:15:11 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:15:11 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:15:11 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Dec 15 15:15:11 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:15:12 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:15:12 gbvpi-bedroom go-librespot[14170]: go-librespot daemon starting... Dec 15 15:15:12 gbvpi-bedroom go-librespot[14171]: time="2025-12-15T15:15:12-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:15:12 gbvpi-bedroom go-librespot[14171]: time="2025-12-15T15:15:12-05:00" level=debug msg="app state loaded" Dec 15 15:15:12 gbvpi-bedroom go-librespot[14171]: time="2025-12-15T15:15:12-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:15:12 gbvpi-bedroom go-librespot[14171]: time="2025-12-15T15:15: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 15 15:15:12 gbvpi-bedroom go-librespot[14171]: time="2025-12-15T15:15: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 15 15:15:12 gbvpi-bedroom go-librespot[14171]: time="2025-12-15T15:15: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 15 15:15:12 gbvpi-bedroom go-librespot[14171]: time="2025-12-15T15:15:12-05:00" level=info msg="zeroconf server listening on port 43233" Dec 15 15:15:12 gbvpi-bedroom go-librespot[14171]: time="2025-12-15T15:15:12-05:00" level=debug msg="obtained new client token: AAC6SCz4KtAf9RK+PsxoqpYxjQZCRhQuk+K9g5lKjwqQkukMaKQg7BMWXf8AiGiabrKsOLeY2NVA/m0pS2J2WFcAZO34hP591WXKw2qqDbgdgacCvqJ9WOaMhO/+b2LD6tfSxqIYh/CsTbtwkDAIVZgGbo44ubih+Wcd6E3o86668xS2vczWzYN6/mKYMdUgY1saYUgvC86yGSpgkjb1Zno3HPUHQEMYh7G2kUU/lveFWAR/z60Lws7I0A==" Dec 15 15:15:12 gbvpi-bedroom go-librespot[14171]: time="2025-12-15T15:15:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:15:12 gbvpi-bedroom go-librespot[14171]: time="2025-12-15T15:15:12-05:00" level=debug msg="completed keyexchange" Dec 15 15:15:12 gbvpi-bedroom go-librespot[14171]: time="2025-12-15T15:15:12-05:00" level=debug msg="completed challenge" Dec 15 15:15:12 gbvpi-bedroom go-librespot[14171]: time="2025-12-15T15:15: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 15 15:15:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:15:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:15:14 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:15:14 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:15:15 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Dec 15 15:15:15 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:15:15 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:15:15 gbvpi-bedroom go-librespot[14181]: go-librespot daemon starting... Dec 15 15:15:15 gbvpi-bedroom go-librespot[14182]: time="2025-12-15T15:15:15-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:15:15 gbvpi-bedroom go-librespot[14182]: time="2025-12-15T15:15:15-05:00" level=debug msg="app state loaded" Dec 15 15:15:15 gbvpi-bedroom go-librespot[14182]: time="2025-12-15T15:15:15-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:15:15 gbvpi-bedroom go-librespot[14182]: time="2025-12-15T15:15: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 15:15:15 gbvpi-bedroom go-librespot[14182]: time="2025-12-15T15:15:15-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 15:15:15 gbvpi-bedroom go-librespot[14182]: time="2025-12-15T15:15:15-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 15:15:15 gbvpi-bedroom go-librespot[14182]: time="2025-12-15T15:15:15-05:00" level=info msg="zeroconf server listening on port 45113" Dec 15 15:15:16 gbvpi-bedroom go-librespot[14182]: time="2025-12-15T15:15:16-05:00" level=debug msg="obtained new client token: AAC43jkXnbl5DfyJiK9GtZdLMMtj3mBo3md9qSYMwAjmocGemowG+tPqR+UNUghkI7tHEKmod1EVPUnaKfaK/ZE5CP8O3orLXM3ioudFYY1v8jop6zQxd+Sl5DQ2L2ua86OfticC972B3ong9Bn7QSrgL4JtyVn3mRnix/LIWN9YzqwiWRVvMnLLch6MJNaKKcqasTh7U8Uz61RDMLEErc0s2IdVJcqF5Mbf6g5zaq9AS9NKzSRJbGs=" Dec 15 15:15:16 gbvpi-bedroom go-librespot[14182]: time="2025-12-15T15:15:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:15:16 gbvpi-bedroom go-librespot[14182]: time="2025-12-15T15:15:16-05:00" level=debug msg="completed keyexchange" Dec 15 15:15:16 gbvpi-bedroom go-librespot[14182]: time="2025-12-15T15:15:16-05:00" level=debug msg="completed challenge" Dec 15 15:15:16 gbvpi-bedroom go-librespot[14182]: time="2025-12-15T15:15:16-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 15:15:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:15:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:15:17 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:15:17 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:15:19 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:15:19 gbvpi-bedroom volumio[13382]: info: CoreCommandRouter::volumioGetState Dec 15 15:15:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Dec 15 15:15:19 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:15:19 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:15:19 gbvpi-bedroom go-librespot[14189]: go-librespot daemon starting... Dec 15 15:15:19 gbvpi-bedroom go-librespot[14204]: time="2025-12-15T15:15:19-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:15:19 gbvpi-bedroom go-librespot[14204]: time="2025-12-15T15:15:19-05:00" level=debug msg="app state loaded" Dec 15 15:15:19 gbvpi-bedroom go-librespot[14204]: time="2025-12-15T15:15:19-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:15:19 gbvpi-bedroom go-librespot[14204]: time="2025-12-15T15:15: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-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 15:15:19 gbvpi-bedroom go-librespot[14204]: time="2025-12-15T15:15:19-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 15:15:19 gbvpi-bedroom go-librespot[14204]: time="2025-12-15T15:15:19-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 15:15:19 gbvpi-bedroom go-librespot[14204]: time="2025-12-15T15:15:19-05:00" level=info msg="zeroconf server listening on port 33743" Dec 15 15:15:19 gbvpi-bedroom go-librespot[14204]: time="2025-12-15T15:15:19-05:00" level=debug msg="obtained new client token: AABiXaprMwjq2y0xQ/JN7sfpn6iD7LzOQelQv60VrpCIuCdd6SxMjlI9/U4QUBhprc/xQiAmCamJo00oR4YqhZl6gw4v/oWtSmAgFhGZ4DiF54Vrua3EhlxZGFCroZXzPY214yggRbh+0AOmiibBrkcc1SStnPIEJeeqFVi8MoiK0OkITBOBgjZWxnzDGYSR3nScC8m7Mfrtb4dCOgtCIJOKfEhJnaMTzkINrRlV2Bh4MsNLj9Kflep0jg==" Dec 15 15:15:19 gbvpi-bedroom go-librespot[14204]: time="2025-12-15T15:15:19-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:15:19 gbvpi-bedroom go-librespot[14204]: time="2025-12-15T15:15:19-05:00" level=debug msg="completed keyexchange" Dec 15 15:15:19 gbvpi-bedroom go-librespot[14204]: time="2025-12-15T15:15:19-05:00" level=debug msg="completed challenge" Dec 15 15:15:19 gbvpi-bedroom go-librespot[14204]: time="2025-12-15T15:15:19-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 15:15:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:15:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:15:20 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:15:20 gbvpi-bedroom volumio[13382]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:15:22 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Dec 15 15:15:22 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:15:23 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:15:23 gbvpi-bedroom go-librespot[14211]: go-librespot daemon starting... Dec 15 15:15:23 gbvpi-bedroom go-librespot[14212]: time="2025-12-15T15:15:23-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:15:23 gbvpi-bedroom go-librespot[14212]: time="2025-12-15T15:15:23-05:00" level=debug msg="app state loaded" Dec 15 15:15:23 gbvpi-bedroom go-librespot[14212]: time="2025-12-15T15:15:23-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:15:23 gbvpi-bedroom go-librespot[14212]: time="2025-12-15T15:15:23-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 15:15:23 gbvpi-bedroom go-librespot[14212]: time="2025-12-15T15:15:23-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 15:15:23 gbvpi-bedroom go-librespot[14212]: time="2025-12-15T15:15:23-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 15:15:23 gbvpi-bedroom go-librespot[14212]: time="2025-12-15T15:15:23-05:00" level=info msg="zeroconf server listening on port 41859" Dec 15 15:15:23 gbvpi-bedroom go-librespot[14212]: time="2025-12-15T15:15:23-05:00" level=debug msg="obtained new client token: AADSCEqK3YjRyn02DYTeLmwEwlFGkuCiFlFAnWBBpmJbYB3v0PUBoUlsyF9s1JDxk9haa0C2oeSsZYw1pCsbVa2ZGGRP3usj1+AGJnJIwjAnxL5aW5CQ3+jKLPlf+jL9RZy7N8lxDhDi5DPE+/KjE7auCQCRasbYWVZ489yWEARVnnXgMWk98lnqLc8HFpbRnrZMiRWSbkttskN7jp4NGZ8z4gafqI1E/G1n+T+io6mHLlb8UU9Pyhe/hQ==" Dec 15 15:15:23 gbvpi-bedroom go-librespot[14212]: time="2025-12-15T15:15:23-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 15 15:15:23 gbvpi-bedroom volumio[13382]: info: Initializing connection to go-librespot Websocket Dec 15 15:15:23 gbvpi-bedroom go-librespot[14212]: time="2025-12-15T15:15:23-05:00" level=debug msg="new websocket client" Dec 15 15:15:23 gbvpi-bedroom volumio[13382]: info: Connection to go-librespot Websocket established Dec 15 15:15:23 gbvpi-bedroom go-librespot[14212]: time="2025-12-15T15:15:23-05:00" level=debug msg="completed keyexchange" Dec 15 15:15:23 gbvpi-bedroom go-librespot[14212]: time="2025-12-15T15:15:23-05:00" level=debug msg="completed challenge" Dec 15 15:15:23 gbvpi-bedroom go-librespot[14212]: time="2025-12-15T15:15:23-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 15:15:23 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:15:23 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:15:23 gbvpi-bedroom volumio[13382]: info: Connection to go-librespot Websocket closed Dec 15 15:15:26 gbvpi-bedroom volumio[13382]: info: Getting Spotify volume Dec 15 15:15:26 gbvpi-bedroom volumio[13382]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 15:15:26 gbvpi-bedroom volumio[13382]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:15:26 gbvpi-bedroom volumio[13382]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 15 15:15:26 gbvpi-bedroom volumio[13382]: errno: -111, Dec 15 15:15:26 gbvpi-bedroom volumio[13382]: code: 'ECONNREFUSED', Dec 15 15:15:26 gbvpi-bedroom volumio[13382]: syscall: 'connect', Dec 15 15:15:26 gbvpi-bedroom volumio[13382]: address: '127.0.0.1', Dec 15 15:15:26 gbvpi-bedroom volumio[13382]: port: 9879, Dec 15 15:15:26 gbvpi-bedroom volumio[13382]: response: undefined Dec 15 15:15:26 gbvpi-bedroom volumio[13382]: } Dec 15 15:15:26 gbvpi-bedroom volumio[13382]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 15:15:26 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Dec 15 15:15:26 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:15:26 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:15:26 gbvpi-bedroom go-librespot[14234]: go-librespot daemon starting... Dec 15 15:15:26 gbvpi-bedroom go-librespot[14235]: time="2025-12-15T15:15:26-05:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:15:26 gbvpi-bedroom go-librespot[14235]: time="2025-12-15T15:15:26-05:00" level=debug msg="app state loaded" Dec 15 15:15:26 gbvpi-bedroom go-librespot[14235]: time="2025-12-15T15:15:26-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:15:26 gbvpi-bedroom sudo[14244]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 15:14' Dec 15 15:15:26 gbvpi-bedroom sudo[14244]: 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"