Dec 22 12:48:01 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 72. Dec 22 12:48:01 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:01 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:01 sala go-librespot[18590]: go-librespot daemon starting... Dec 22 12:48:01 sala go-librespot[18591]: time="2025-12-22T12:48:01+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:48:01 sala go-librespot[18591]: time="2025-12-22T12:48:01+01:00" level=debug msg="app state loaded" Dec 22 12:48:01 sala go-librespot[18591]: time="2025-12-22T12:48:01+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:48:01 sala go-librespot[18591]: time="2025-12-22T12:48:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 22 12:48:01 sala go-librespot[18591]: time="2025-12-22T12:48:01+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 22 12:48:01 sala go-librespot[18591]: time="2025-12-22T12:48:01+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 22 12:48:01 sala go-librespot[18591]: time="2025-12-22T12:48:01+01:00" level=info msg="zeroconf server listening on port 44971" Dec 22 12:48:01 sala go-librespot[18591]: time="2025-12-22T12:48:01+01:00" level=debug msg="obtained new client token: AABFq/ArdtFOwwoZB4qgMT0LGfS3AFtQ6xcFLlPXjGBAxR2s+EJntHg/dtcL6UbKMfxs96guHg/wDcZEfb2vkkUFOi2I6U+HGRI+ApdLwYuBeIJoWauhSSY39j1J+4+yte/srEAFMfT/tIpijcG+gV4O1colhcksQxaNBwdo/MIC32kYczFd9az6umft6EnPigtGAIXwdLOc8goijh143xYWP6HOjW59r4CRY842GAKe4kByy6FlOxU=" Dec 22 12:48:01 sala go-librespot[18591]: time="2025-12-22T12:48:01+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:48:01 sala go-librespot[18591]: time="2025-12-22T12:48:01+01:00" level=debug msg="completed keyexchange" Dec 22 12:48:01 sala go-librespot[18591]: time="2025-12-22T12:48:01+01:00" level=debug msg="completed challenge" Dec 22 12:48:01 sala go-librespot[18591]: time="2025-12-22T12:48:01+01: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 22 12:48:01 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:01 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 22 12:48:02 sala volumio[18263]: info: Adding plugin bluetooth to MyMusic Plugins Dec 22 12:48:02 sala volumio[18263]: info: Adding plugin multiroom to MyMusic Plugins Dec 22 12:48:02 sala volumio[18263]: info: Adding plugin metavolumio to MyMusic Plugins Dec 22 12:48:02 sala volumio[18263]: info: Adding plugin cd_controller to MyMusic Plugins Dec 22 12:48:02 sala volumio[18263]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 22 12:48:02 sala volumio[18263]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 22 12:48:02 sala volumio[18263]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 22 12:48:02 sala volumio[18263]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 22 12:48:03 sala volumio[18263]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 22 12:48:03 sala volumio[18263]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 22 12:48:03 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 12:48:03 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 12:48:03 sala volumio[18263]: info: Starting MyVolumio Remote Streaming Endpoints Dec 22 12:48:03 sala volumio[18263]: info: MyVolumio login type: Token Dec 22 12:48:03 sala volumio[18263]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 22 12:48:03 sala volumio[18263]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 22 12:48:03 sala volumio[18263]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 22 12:48:03 sala volumio[18263]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 22 12:48:03 sala volumio[18263]: info: Streaming services startup Dec 22 12:48:03 sala volumio[18263]: info: Starting Streaming Daemon Dec 22 12:48:03 sala sudo[18599]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 22 12:48:03 sala sudo[18599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 12:48:03 sala volumio[18263]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 22 12:48:03 sala sudo[18599]: pam_unix(sudo:session): session closed for user root Dec 22 12:48:03 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:03 sala volumio[18263]: error: Cannot start Volumio Streaming Daemon Dec 22 12:48:03 sala volumio[18263]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 22 12:48:03 sala volumio[18263]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 22 12:48:03 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:04 sala volumio[18263]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 22 12:48:04 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 73. Dec 22 12:48:04 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:04 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:04 sala go-librespot[18609]: go-librespot daemon starting... Dec 22 12:48:04 sala go-librespot[18610]: time="2025-12-22T12:48:04+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:48:04 sala go-librespot[18610]: time="2025-12-22T12:48:04+01:00" level=debug msg="app state loaded" Dec 22 12:48:04 sala go-librespot[18610]: time="2025-12-22T12:48:04+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:48:05 sala go-librespot[18610]: time="2025-12-22T12:48:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 22 12:48:05 sala go-librespot[18610]: time="2025-12-22T12:48:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 22 12:48:05 sala go-librespot[18610]: time="2025-12-22T12:48:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 22 12:48:05 sala go-librespot[18610]: time="2025-12-22T12:48:05+01:00" level=info msg="zeroconf server listening on port 40823" Dec 22 12:48:05 sala go-librespot[18610]: time="2025-12-22T12:48:05+01:00" level=debug msg="obtained new client token: AABsMJnzU9O92Pr54JO1LTaGbZASF2Y39nBd/uQf4K2Q9uJ0lvDrD8XtDnodzZgOzkxAyqKIPA9WNXet8w7MVpWpKneYCNsr8zqzrVohFPOACzLAeLRo2BBbj5nvY1cTQXG0vRQDlbquePaGU7h7rnoCa14O0FkK0cE/eK63Xy1r2TINflCl/nbeDtGEM4p8AjJgAT+fONL4vIMcSpb4GjycWe+GM/0eC2VHLh1jkXI6Ze0/0io+vBk=" Dec 22 12:48:05 sala volumio[18263]: info: MyVolumio token set successfully Dec 22 12:48:05 sala volumio[18263]: info: MYVOLUMIO: Adding device Dec 22 12:48:05 sala volumio[18263]: info: MYVOLUMIO: Evaluating Server Dec 22 12:48:05 sala go-librespot[18610]: time="2025-12-22T12:48:05+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:48:05 sala go-librespot[18610]: time="2025-12-22T12:48:05+01:00" level=debug msg="completed keyexchange" Dec 22 12:48:05 sala go-librespot[18610]: time="2025-12-22T12:48:05+01:00" level=debug msg="completed challenge" Dec 22 12:48:05 sala go-librespot[18610]: time="2025-12-22T12:48:05+01: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 22 12:48:05 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:05 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:48:05 sala volumio[18263]: info: MyVolumio Plan changed: premium Dec 22 12:48:05 sala volumio[18263]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 22 12:48:05 sala volumio[18263]: info: Removing browser output: myVolumio user plan is not superstar Dec 22 12:48:05 sala volumio[18263]: info: Removing audio output: Dec 22 12:48:05 sala volumio[18263]: info: MYVOLUMIO: Adding device Dec 22 12:48:05 sala volumio[18263]: info: MYVOLUMIO: Evaluating Server Dec 22 12:48:05 sala volumio[18263]: info: Remote config written successfully Dec 22 12:48:05 sala volumio[18263]: info: Starting Tunnel 1 Dec 22 12:48:05 sala volumio[18263]: info: Starting Tunnel Connection Checker Dec 22 12:48:05 sala volumio[18263]: info: Completed starting MyVolumio Plugin Dec 22 12:48:05 sala volumio[18263]: info: MYVolumio Device enabled Dec 22 12:48:05 sala volumio[18263]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 22 12:48:05 sala volumio[18263]: info: MyVolumio status changed Dec 22 12:48:05 sala volumio[18263]: info: Streaming services startup Dec 22 12:48:05 sala volumio[18263]: info: Starting Streaming Daemon Dec 22 12:48:06 sala volumio[18263]: info: Setting Geolocation for MyVolumio to eu10 Dec 22 12:48:06 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 12:48:06 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 12:48:06 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 12:48:06 sala sudo[18654]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 22 12:48:06 sala sudo[18654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 12:48:06 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 22 12:48:06 sala volumio[18263]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 22 12:48:06 sala sudo[18654]: pam_unix(sudo:session): session closed for user root Dec 22 12:48:06 sala volumio[18263]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 22 12:48:06 sala volumio[18263]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 22 12:48:06 sala volumio[18263]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 22 12:48:06 sala sudo[18672]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 22 12:48:06 sala sudo[18672]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 12:48:06 sala sudo[18672]: pam_unix(sudo:session): session closed for user root Dec 22 12:48:06 sala volumio[18263]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 22 12:48:06 sala volumio[18263]: info: MRS: MultiRoom plugin initialized Dec 22 12:48:06 sala volumio[18263]: info: MRS: STOPPING SNAPCLIENT Dec 22 12:48:06 sala volumio[18263]: info: MRS: Snap server stop Dec 22 12:48:06 sala volumio[18263]: info: MRS: STOPPING volumioStreaming Dec 22 12:48:06 sala sudo[18689]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 22 12:48:06 sala sudo[18689]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 12:48:06 sala sudo[18691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 22 12:48:06 sala sudo[18691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 12:48:06 sala volumio[18263]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 22 12:48:06 sala sudo[18694]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 22 12:48:06 sala sudo[18694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 12:48:06 sala volumio[18263]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 22 12:48:06 sala sudo[18697]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 22 12:48:06 sala sudo[18697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 12:48:06 sala volumio[18263]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 22 12:48:06 sala sudo[18697]: pam_unix(sudo:session): session closed for user root Dec 22 12:48:06 sala volumio[18263]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 22 12:48:06 sala volumio[18263]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 22 12:48:06 sala volumio[18263]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 22 12:48:07 sala sudo[18689]: pam_unix(sudo:session): session closed for user root Dec 22 12:48:07 sala sudo[18691]: pam_unix(sudo:session): session closed for user root Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 22 12:48:07 sala sudo[18694]: pam_unix(sudo:session): session closed for user root Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 22 12:48:07 sala volumio[18263]: info: Preparing to generate the ALSA configuration file Dec 22 12:48:07 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:07 sala volumio[18263]: info: Updating MyVolumio device info Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 12:48:07 sala volumio[18263]: info: Setting Geolocation for MyVolumio to eu10 Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 12:48:07 sala volumio[18263]: info: MRS: Removed streaming files Dec 22 12:48:07 sala volumio[18263]: info: MRS: volumioStreaming STOPPED Dec 22 12:48:07 sala volumio[18263]: info: MRS: SNAPSERVER STOPPED Dec 22 12:48:07 sala volumio[18263]: info: MRS: SNAPCLIENT STOPPED Dec 22 12:48:07 sala volumio[18263]: error: Cannot start Volumio Streaming Daemon Dec 22 12:48:07 sala volumio[18263]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 22 12:48:07 sala volumio[18263]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 22 12:48:07 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:07 sala volumio[18263]: info: Asound.conf file unchanged, so no further update is needed Dec 22 12:48:07 sala volumio[18263]: info: Output device has changed, restarting MPD Dec 22 12:48:07 sala volumio[18263]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 12:48:07 sala sudo[18701]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 22 12:48:07 sala sudo[18701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 12:48:07 sala sudo[18701]: pam_unix(sudo:session): session closed for user root Dec 22 12:48:07 sala sudo[18703]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 22 12:48:07 sala sudo[18703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 12:48:07 sala volumio[18263]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 22 12:48:07 sala volumio[18263]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 22 12:48:07 sala volumio[18263]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 22 12:48:07 sala volumio[18263]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Plugin multiroom disabled by user. Not starting Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 22 12:48:07 sala volumio[18263]: info: Adding METAVOLUMIO REST API Endpoints Dec 22 12:48:07 sala volumio[18263]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 22 12:48:07 sala volumio[18263]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 22 12:48:07 sala volumio[18263]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 22 12:48:07 sala systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 22 12:48:07 sala volumio[18263]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Plugin cd_controller disabled by user. Not starting Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Plugin smart_inputs disabled by user. Not starting Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 22 12:48:07 sala volumio[18263]: error: Hi Res Audio Failed Login: Missing Login Data Dec 22 12:48:07 sala volumio[18263]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 22 12:48:07 sala volumio[18263]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 22 12:48:07 sala volumio[18263]: info: Refreshing QOBUZ token Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Plugin tidalconnect disabled by user. Not starting Dec 22 12:48:07 sala volumio[18263]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 22 12:48:07 sala volumio[18263]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 22 12:48:07 sala bluetoothd[851]: Path / reserved for Adv Monitor app :1.1446 Dec 22 12:48:07 sala volumio[18263]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 22 12:48:07 sala bluetoothd[851]: Adv Monitor app :1.1446 disconnected from D-Bus Dec 22 12:48:07 sala systemd[1]: mpd.service: Deactivated successfully. Dec 22 12:48:07 sala systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 22 12:48:07 sala systemd[1]: mpd.service: Consumed 1.784s CPU time. Dec 22 12:48:07 sala systemd[1]: mpd.socket: Deactivated successfully. Dec 22 12:48:07 sala systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 22 12:48:07 sala systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 22 12:48:07 sala volumio[18263]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 22 12:48:07 sala volumio[18263]: info: Adding TIDAL REST API Endpoints Dec 22 12:48:07 sala volumio[18263]: info: Successfully Added MyVolumio device Dec 22 12:48:07 sala sudo[18716]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 22 12:48:07 sala sudo[18716]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 12:48:07 sala volumio[18263]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Dec 22 12:48:07 sala volumio[18263]: info: MPD Permissions set Dec 22 12:48:07 sala systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 22 12:48:07 sala systemd[1]: Starting mpd.service - Music Player Daemon... Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 12:48:07 sala sudo[18719]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 22 12:48:07 sala sudo[18719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 12:48:07 sala sudo[18716]: pam_unix(sudo:session): session closed for user root Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 12:48:07 sala sudo[18727]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 22 12:48:07 sala sudo[18727]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 12:48:07 sala sudo[18719]: pam_unix(sudo:session): session closed for user root Dec 22 12:48:07 sala volumio[18263]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::volumioStop Dec 22 12:48:07 sala volumio[18263]: info: CoreStateMachine::stop Dec 22 12:48:07 sala volumio[18263]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 22 12:48:07 sala volumio[18263]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Dec 22 12:48:07 sala volumio[18263]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 22 12:48:07 sala qobuz-connect[17125]: 20251222 12:48:07.412 [17125.17125] INFO SampleApp: Stopping Local configuration server Dec 22 12:48:07 sala systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 22 12:48:07 sala sudo[18720]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 22 12:48:07 sala sudo[18720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 22 12:48:07 sala sudo[18720]: pam_unix(sudo:session): session closed for user root Dec 22 12:48:07 sala volumio[18263]: info: Access Token successfully retrieved Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 12:48:07 sala volumio[18263]: info: [1766404087487] CoreMusicLibrary::Adding element QOBUZ Dec 22 12:48:07 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 12:48:07 sala volumio[18263]: Cannot find translation for source Radio Paradise Dec 22 12:48:07 sala volumio[18263]: Cannot find translation for source QOBUZ Dec 22 12:48:07 sala volumio[18263]: info: Stopping AccessToken refresher cron for QOBUZ Dec 22 12:48:07 sala volumio[18263]: info: AccessToken refresher cron started for QOBUZ Dec 22 12:48:07 sala volumio[18263]: info: Adding QOBUZ REST API Endpoints Dec 22 12:48:07 sala volumio[18263]: info: Successfully Added MyVolumio device Dec 22 12:48:08 sala volumio[18263]: info: Updating MyVolumio device info Dec 22 12:48:08 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 12:48:08 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 12:48:08 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 12:48:08 sala systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 22 12:48:08 sala systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 22 12:48:08 sala systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 22 12:48:08 sala sudo[18727]: pam_unix(sudo:session): session closed for user root Dec 22 12:48:08 sala volumio[18263]: [Metrics] CommandRouter: 23s 303.60ms Dec 22 12:48:08 sala volumio[18263]: info: CoreCommandRouter::volumiosetStartupVolume Dec 22 12:48:08 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 12:48:08 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 12:48:08 sala volumio[18263]: info: CoreCommandRouter::Close All Modals sent Dec 22 12:48:08 sala volumio[18263]: info: CoreCommandRouter::Close All Modals sent Dec 22 12:48:08 sala volumio[18263]: info: Executing endpoint qc_getconfig Dec 22 12:48:08 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 22 12:48:08 sala qobuz-connect[18731]: 20251222 12:48:08.542 [18731.18731] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 22 12:48:08 sala qobuz-connect[18731]: 20251222 12:48:08.546 [18731.18731] INFO VolumeManager: [0x1ed7348]: Setting new playback volume: 75 Dec 22 12:48:08 sala qobuz-connect[18731]: 20251222 12:48:08.546 [18731.18731] INFO VolumeManager: [0x1ed7348]: Setting new mute state: 0 Dec 22 12:48:08 sala qobuz-connect[18731]: 20251222 12:48:08.546 [18731.18731] INFO QobuzConnect: [0x1ed7d18]: Client initialized! Dec 22 12:48:08 sala qobuz-connect[18731]: 20251222 12:48:08.546 [18731.18731] INFO SampleApp: Starting Avahi advertising, name: Sala, service name: _qobuz-connect._tcp Dec 22 12:48:08 sala volumio[18263]: info: Successfully Updated MyVolumio device Dec 22 12:48:08 sala volumio[18263]: info: Successfully Updated MyVolumio device Dec 22 12:48:08 sala volumio[18263]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 22 12:48:08 sala volumio[18263]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 22 12:48:08 sala qobuz-connect[18731]: 20251222 12:48:08.559 [18731.18731] INFO LocalConfigManager: [0x1ed6c28]: Starting Local Configuration server Dec 22 12:48:08 sala qobuz-connect[18731]: 20251222 12:48:08.559 [18731.18731] INFO SampleApp: Starting Local configuration server Dec 22 12:48:08 sala qobuz-connect[18731]: 20251222 12:48:08.560 [18731.18731] INFO SampleApp: Connected to UNIX socket client 0x1ec1818 Dec 22 12:48:08 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 74. Dec 22 12:48:08 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:08 sala qobuz-connect[18731]: 20251222 12:48:08.692 [18731.18731] INFO SampleApp: Playback volume changed: 75 Dec 22 12:48:08 sala volumio[18263]: info: CoreCommandRouter::volumioGetState Dec 22 12:48:08 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:08 sala go-librespot[18739]: go-librespot daemon starting... Dec 22 12:48:08 sala go-librespot[18740]: time="2025-12-22T12:48:08+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:48:08 sala go-librespot[18740]: time="2025-12-22T12:48:08+01:00" level=debug msg="app state loaded" Dec 22 12:48:08 sala go-librespot[18740]: time="2025-12-22T12:48:08+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:48:08 sala systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 11303. Dec 22 12:48:08 sala systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 22 12:48:08 sala go-librespot[18740]: time="2025-12-22T12:48:08+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 22 12:48:08 sala go-librespot[18740]: time="2025-12-22T12:48:08+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 22 12:48:08 sala go-librespot[18740]: time="2025-12-22T12:48:08+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 22 12:48:08 sala go-librespot[18740]: time="2025-12-22T12:48:08+01:00" level=info msg="zeroconf server listening on port 41627" Dec 22 12:48:09 sala systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 22 12:48:09 sala mpd[18730]: 2025-12-22T12:48:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 22 12:48:09 sala systemd[1]: Started mpd.service - Music Player Daemon. Dec 22 12:48:09 sala sudo[18703]: pam_unix(sudo:session): session closed for user root Dec 22 12:48:09 sala volumio[18263]: error: updateQueue error: null Dec 22 12:48:09 sala upmpdcli[18747]: Could not open config: /tmp/upmpdcli.conf Dec 22 12:48:09 sala systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:09 sala systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 22 12:48:09 sala go-librespot[18740]: time="2025-12-22T12:48:09+01:00" level=debug msg="obtained new client token: AABA+d2w0L6hMWKZoSEkvOH+bZvKGQDQImNAjlf1fgCr/kBAyqA378cro7d7NiKJO4XDIElK3mOEN4WDLAGnPih1zb53GlkAMtVtYiXc9vrZ4Jpjd6S+WYF7ZByB0tMx0U746qpV7s7XQC5kC8ThG4YJoJGVa9Wl30t/+Ep1FhaPQm3sKU/0ZPdNp9/Y6wDeRy/fPZ937tcUa6NjJmaR1kQXtlO1OlEb4Kx5zbGNg8lbEMSqOaSK" Dec 22 12:48:09 sala go-librespot[18740]: time="2025-12-22T12:48:09+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:48:09 sala go-librespot[18740]: time="2025-12-22T12:48:09+01:00" level=debug msg="completed keyexchange" Dec 22 12:48:09 sala go-librespot[18740]: time="2025-12-22T12:48:09+01:00" level=debug msg="completed challenge" Dec 22 12:48:09 sala go-librespot[18740]: time="2025-12-22T12:48:09+01: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 22 12:48:09 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:09 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:48:09 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 22 12:48:09 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 22 12:48:09 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 22 12:48:10 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:10 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:11 sala sudo[18756]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 22 12:48:11 sala sudo[18756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 12:48:11 sala autossh[17156]: received signal to exit (15) Dec 22 12:48:11 sala systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Dec 22 12:48:11 sala systemd[1]: sshtunnel.service: Deactivated successfully. Dec 22 12:48:11 sala systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 22 12:48:11 sala systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 22 12:48:11 sala sudo[18756]: pam_unix(sudo:session): session closed for user root Dec 22 12:48:11 sala volumio[18263]: info: Remote SSH Started Dec 22 12:48:11 sala autossh[18759]: port set to 0, monitoring disabled Dec 22 12:48:11 sala autossh[18759]: starting ssh (count 1) Dec 22 12:48:11 sala autossh[18759]: ssh child pid is 18762 Dec 22 12:48:11 sala volumio[18263]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 22 12:48:11 sala volumio[18263]: info: CoreCommandRouter::volumioGetState Dec 22 12:48:11 sala volumio[18263]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.5qI9EprEkMdiIz3z2mzcYHFnhVg1.a25413a38ade311e2ecbf396be54d400.state.status' Dec 22 12:48:11 sala volumiossh-tunnel[18762]: Warning: Permanently added '[eu10.myvolumio.org]:2222' (RSA) to the list of known hosts. Dec 22 12:48:12 sala sudo[18764]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 22 12:48:12 sala sudo[18764]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 12:48:12 sala systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 22 12:48:12 sala systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 22 12:48:12 sala systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 22 12:48:12 sala systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 22 12:48:12 sala sudo[18764]: pam_unix(sudo:session): session closed for user root Dec 22 12:48:12 sala mpd_monitor.sh[18766]: MPD Monitor Service: Starting MPD Monitor Service Dec 22 12:48:12 sala volumio[18263]: info: Successfully started MPD Monitor Dec 22 12:48:12 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 75. Dec 22 12:48:12 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:12 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:12 sala go-librespot[18770]: go-librespot daemon starting... Dec 22 12:48:12 sala go-librespot[18771]: time="2025-12-22T12:48:12+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:48:12 sala go-librespot[18771]: time="2025-12-22T12:48:12+01:00" level=debug msg="app state loaded" Dec 22 12:48:12 sala go-librespot[18771]: time="2025-12-22T12:48:12+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:48:12 sala go-librespot[18771]: time="2025-12-22T12:48:12+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 22 12:48:12 sala go-librespot[18771]: time="2025-12-22T12:48:12+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 22 12:48:12 sala go-librespot[18771]: time="2025-12-22T12:48:12+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 22 12:48:12 sala go-librespot[18771]: time="2025-12-22T12:48:12+01:00" level=info msg="zeroconf server listening on port 38429" Dec 22 12:48:12 sala go-librespot[18771]: time="2025-12-22T12:48:12+01:00" level=debug msg="obtained new client token: AADrtHbO7u8TB/gCuAz7hFPb8GWC/gmd7J3hCBG6GoPtl5CIgzwpqUG3wj5LqntjS+hGh5Pi1UpjC7sA9AwZkPovukpFOiRhen7rtXkkRNiMzFT63gkth6DA2P160U969CprUvhfN+yvuehREyj3KEMb94WaLL2gxjZOGN72y0g5s+1GFOuo6WW/c2yWPmKCJ64Brt8XcDbcWKFObX4amKo8Iz3S1rCwNg/PX6Ds6umW1gFntyVocZY=" Dec 22 12:48:12 sala go-librespot[18771]: time="2025-12-22T12:48:12+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:48:12 sala go-librespot[18771]: time="2025-12-22T12:48:12+01:00" level=debug msg="completed keyexchange" Dec 22 12:48:12 sala go-librespot[18771]: time="2025-12-22T12:48:12+01:00" level=debug msg="completed challenge" Dec 22 12:48:13 sala go-librespot[18771]: time="2025-12-22T12:48:13+01: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 22 12:48:13 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:13 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:48:13 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:13 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:15 sala volumio[18263]: info: BOOT COMPLETED Dec 22 12:48:16 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:16 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:16 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 76. Dec 22 12:48:16 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:16 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:16 sala go-librespot[18778]: go-librespot daemon starting... Dec 22 12:48:16 sala go-librespot[18779]: time="2025-12-22T12:48:16+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:48:16 sala go-librespot[18779]: time="2025-12-22T12:48:16+01:00" level=debug msg="app state loaded" Dec 22 12:48:16 sala go-librespot[18779]: time="2025-12-22T12:48:16+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:48:16 sala go-librespot[18779]: time="2025-12-22T12:48:16+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 22 12:48:16 sala go-librespot[18779]: time="2025-12-22T12:48:16+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 22 12:48:16 sala go-librespot[18779]: time="2025-12-22T12:48:16+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 22 12:48:16 sala go-librespot[18779]: time="2025-12-22T12:48:16+01:00" level=info msg="zeroconf server listening on port 36471" Dec 22 12:48:16 sala go-librespot[18779]: time="2025-12-22T12:48:16+01:00" level=debug msg="obtained new client token: AACnB/Vqt5IeT1m1HZDd0fuNYjrGu7xiCgYYQ2IB0p2YBGEXKuCsisgD2JE5xFTpvwVH1iblMafI0fdc/JH8Zx9zVheX0wkwk5DhkMeMNzc3Liy6N78wQoS2/lY3iLqhlbd7ez8zvLHGnSC8O7r8WvIaG/s5HahU08VAhUh2d8Sb9PnbyXz3/phZM3DIvfj92NfOM9uPPmij4Turez4ev6po8AIgVCpX6QH8nkqDhwl9RL89YzK7rC4=" Dec 22 12:48:16 sala go-librespot[18779]: time="2025-12-22T12:48:16+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Dec 22 12:48:16 sala go-librespot[18779]: time="2025-12-22T12:48:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Dec 22 12:48:16 sala go-librespot[18779]: time="2025-12-22T12:48:16+01:00" level=debug msg="completed keyexchange" Dec 22 12:48:16 sala go-librespot[18779]: time="2025-12-22T12:48:16+01:00" level=debug msg="completed challenge" Dec 22 12:48:16 sala go-librespot[18779]: time="2025-12-22T12:48:16+01: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 22 12:48:16 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:16 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:48:18 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 22 12:48:18 sala volumio[18263]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 22 12:48:18 sala volumio[18263]: info: CoreCommandRouter::volumioGetState Dec 22 12:48:19 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:19 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:19 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 77. Dec 22 12:48:19 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:19 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:19 sala go-librespot[18800]: go-librespot daemon starting... Dec 22 12:48:19 sala go-librespot[18801]: time="2025-12-22T12:48:19+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:48:19 sala go-librespot[18801]: time="2025-12-22T12:48:19+01:00" level=debug msg="app state loaded" Dec 22 12:48:19 sala go-librespot[18801]: time="2025-12-22T12:48:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:48:20 sala go-librespot[18801]: time="2025-12-22T12:48:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 22 12:48:20 sala go-librespot[18801]: time="2025-12-22T12:48:20+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 22 12:48:20 sala go-librespot[18801]: time="2025-12-22T12:48:20+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 22 12:48:20 sala go-librespot[18801]: time="2025-12-22T12:48:20+01:00" level=info msg="zeroconf server listening on port 38685" Dec 22 12:48:20 sala go-librespot[18801]: time="2025-12-22T12:48:20+01:00" level=debug msg="obtained new client token: AAB58Q3NdRnVECFNxsCtp+yJGgnxOEN2j4nUXY3jBh6SBYFXzMkMldmFDw9sfYbUKvMyCBG4S8V8jFvqtFv8bWiv5KlR4TNrallFxRn3LGmBfsEDk/r2sQ1OUylAkERUAa1eZF8iRbFG7CiDGb2fPjH5CQigXbZFQlc5LOj2lWDrdGD/LYc0sV2bN3Es6sc4ZD6rSRhzG1y32ySPK6P+4voQp9DNIQco4PCAB0KjFDpWy0g0wddnGFA=" Dec 22 12:48:20 sala go-librespot[18801]: time="2025-12-22T12:48:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:48:20 sala go-librespot[18801]: time="2025-12-22T12:48:20+01:00" level=debug msg="completed keyexchange" Dec 22 12:48:20 sala go-librespot[18801]: time="2025-12-22T12:48:20+01:00" level=debug msg="completed challenge" Dec 22 12:48:20 sala go-librespot[18801]: time="2025-12-22T12:48:20+01: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 22 12:48:20 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:20 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:48:20 sala nmbd[1210]: [2025/12/22 12:48:20.705280, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Dec 22 12:48:20 sala nmbd[1210]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.65 for name WORKGROUP<1d>. Dec 22 12:48:20 sala nmbd[1210]: This response was from IP 192.168.1.4, reporting an IP address of 192.168.1.4. Dec 22 12:48:21 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 22 12:48:21 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 12:48:21 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 22 12:48:21 sala volumio-remote-updater[804]: Test mode disabled Dec 22 12:48:21 sala volumio-remote-updater[804]: Alpha mode disabled Dec 22 12:48:21 sala volumio-remote-updater[804]: Alpha legacy test mode disabled Dec 22 12:48:21 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 22 12:48:21 sala volumio[18263]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 22 12:48:21 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 22 12:48:22 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:22 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:23 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 12:48:23 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 12:48:23 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 22 12:48:23 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 22 12:48:23 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 22 12:48:23 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 22 12:48:23 sala volumio[18263]: info: CoreCommandRouter::volumioGetBrowseSources Dec 22 12:48:23 sala volumio[18263]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 22 12:48:23 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 78. Dec 22 12:48:23 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:23 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:23 sala go-librespot[18813]: go-librespot daemon starting... Dec 22 12:48:23 sala go-librespot[18814]: time="2025-12-22T12:48:23+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:48:23 sala go-librespot[18814]: time="2025-12-22T12:48:23+01:00" level=debug msg="app state loaded" Dec 22 12:48:23 sala go-librespot[18814]: time="2025-12-22T12:48:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:48:23 sala go-librespot[18814]: time="2025-12-22T12:48:23+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 22 12:48:23 sala go-librespot[18814]: time="2025-12-22T12:48:23+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 22 12:48:23 sala go-librespot[18814]: time="2025-12-22T12:48:23+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 22 12:48:23 sala go-librespot[18814]: time="2025-12-22T12:48:23+01:00" level=info msg="zeroconf server listening on port 41519" Dec 22 12:48:24 sala go-librespot[18814]: time="2025-12-22T12:48:24+01:00" level=debug msg="obtained new client token: AABYnlL0WjVhBZErBvYEP0C1ZFFO3aPnFB7qPaHcCMLPjWciPFjL8xpbF2mV8E8HRdKlCeu9aZW/mWYSg1G/PAJivhRZED5Pd9LjCKyR5r28zQVGCk4s5Yn5HZhQXH2lF9mZemh4AE9tgCRlOM1PGxJP2uodHP7A1b8t7PE1ry4f0mv2OaVwFnTX8lfsUSSPBpUzNHm9Vm2xxQI+cUMXP4XQC0nJQ+R0GOT5ujNbBGJWJt9wCafn" Dec 22 12:48:24 sala go-librespot[18814]: time="2025-12-22T12:48:24+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:48:24 sala systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 11304. Dec 22 12:48:24 sala systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 22 12:48:24 sala go-librespot[18814]: time="2025-12-22T12:48:24+01:00" level=debug msg="completed keyexchange" Dec 22 12:48:24 sala go-librespot[18814]: time="2025-12-22T12:48:24+01:00" level=debug msg="completed challenge" Dec 22 12:48:24 sala systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 22 12:48:24 sala go-librespot[18814]: time="2025-12-22T12:48:24+01: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 22 12:48:24 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:24 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:48:24 sala upmpdcli[18821]: Could not open config: /tmp/upmpdcli.conf Dec 22 12:48:24 sala systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:24 sala systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 22 12:48:25 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:25 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:27 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 79. Dec 22 12:48:27 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:27 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:27 sala go-librespot[18836]: go-librespot daemon starting... Dec 22 12:48:27 sala go-librespot[18837]: time="2025-12-22T12:48:27+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:48:27 sala go-librespot[18837]: time="2025-12-22T12:48:27+01:00" level=debug msg="app state loaded" Dec 22 12:48:27 sala go-librespot[18837]: time="2025-12-22T12:48:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:48:27 sala go-librespot[18837]: time="2025-12-22T12:48:27+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 22 12:48:27 sala go-librespot[18837]: time="2025-12-22T12:48:27+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 22 12:48:27 sala go-librespot[18837]: time="2025-12-22T12:48:27+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 22 12:48:27 sala go-librespot[18837]: time="2025-12-22T12:48:27+01:00" level=info msg="zeroconf server listening on port 35097" Dec 22 12:48:27 sala go-librespot[18837]: time="2025-12-22T12:48:27+01:00" level=debug msg="obtained new client token: AAAlLcVLVbbp+kd74fIfIdksXiDC6hplx2F94rgNDA4n8U/ygjgyeCmCR265KYYzyOQlGg72F4qaxFWqSy/OqRniqoz31t6RAjYFG49Q0HJg23iUNn4Oa6g95pbbIeik9zXncyXw8gV1antQHFtTOC+2+avQr/2lMr272+1SSlOg4o/IDHIascuVo9u0nC/nGBsBVm3bv0K3TzCKMskfoBr3/USXLPggoqoClyJZaBd1lpq0gB7gXlM=" Dec 22 12:48:27 sala go-librespot[18837]: time="2025-12-22T12:48:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:48:27 sala go-librespot[18837]: time="2025-12-22T12:48:27+01:00" level=debug msg="completed keyexchange" Dec 22 12:48:27 sala go-librespot[18837]: time="2025-12-22T12:48:27+01:00" level=debug msg="completed challenge" Dec 22 12:48:27 sala go-librespot[18837]: time="2025-12-22T12:48:27+01: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 22 12:48:27 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:27 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:48:28 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:28 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:31 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:31 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:31 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 80. Dec 22 12:48:31 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:31 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:31 sala go-librespot[18844]: go-librespot daemon starting... Dec 22 12:48:31 sala go-librespot[18845]: time="2025-12-22T12:48:31+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:48:31 sala go-librespot[18845]: time="2025-12-22T12:48:31+01:00" level=debug msg="app state loaded" Dec 22 12:48:31 sala go-librespot[18845]: time="2025-12-22T12:48:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:48:31 sala go-librespot[18845]: time="2025-12-22T12:48:31+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 22 12:48:31 sala go-librespot[18845]: time="2025-12-22T12:48:31+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 22 12:48:31 sala go-librespot[18845]: time="2025-12-22T12:48:31+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 22 12:48:31 sala go-librespot[18845]: time="2025-12-22T12:48:31+01:00" level=info msg="zeroconf server listening on port 34317" Dec 22 12:48:31 sala go-librespot[18845]: time="2025-12-22T12:48:31+01:00" level=debug msg="obtained new client token: AAC+6VJuIYe/wdFJVXpmKlSEcYi8YfiX+ZIrt3ggsDrxxgxnkjlnI06IaEZ1V9Ju9+VcvGCXk0KXa8aqeKOBZytXdSyMm9OKNfIZ+NG2LIA0UjhLmvhPDOOD0leykjUvqa2MrebrvS8x2DiDZZnyLXI39wMcBEbSeN98GlhJIdWnwWU2iwW+YuoLWd4Gs6rpnRCk0eujmfKk5aNSAsoke6whNXzQCu2ggQKr4FC+VuiqODK59IeWHzw=" Dec 22 12:48:31 sala go-librespot[18845]: time="2025-12-22T12:48:31+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:48:31 sala go-librespot[18845]: time="2025-12-22T12:48:31+01:00" level=debug msg="completed keyexchange" Dec 22 12:48:31 sala go-librespot[18845]: time="2025-12-22T12:48:31+01:00" level=debug msg="completed challenge" Dec 22 12:48:31 sala go-librespot[18845]: time="2025-12-22T12:48:31+01: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 22 12:48:31 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:31 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:48:34 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:34 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:34 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 81. Dec 22 12:48:34 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:34 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:34 sala go-librespot[18855]: go-librespot daemon starting... Dec 22 12:48:34 sala go-librespot[18856]: time="2025-12-22T12:48:34+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:48:34 sala go-librespot[18856]: time="2025-12-22T12:48:34+01:00" level=debug msg="app state loaded" Dec 22 12:48:34 sala go-librespot[18856]: time="2025-12-22T12:48:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:48:35 sala go-librespot[18856]: time="2025-12-22T12:48:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 22 12:48:35 sala go-librespot[18856]: time="2025-12-22T12:48:35+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 22 12:48:35 sala go-librespot[18856]: time="2025-12-22T12:48:35+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 22 12:48:35 sala go-librespot[18856]: time="2025-12-22T12:48:35+01:00" level=info msg="zeroconf server listening on port 41477" Dec 22 12:48:35 sala go-librespot[18856]: time="2025-12-22T12:48:35+01:00" level=debug msg="obtained new client token: AAD7NBObaLBEK1cYdTO+Xozt8YvbAZprLwpito1Xd8Ezzt9XwrzaWcPvR6vJG7dMbl2OQ2evl4Neb3ayWFFmGHseJKBN94mgUc7/RojH6xy+8c0Wa392d+RCk83Wgx+0GzymNho/7r366ZwTRh817wGQHOEzGfPLfYdUYDHtW6w1HPRQ/Y2DhxJhhmWIE23H5xQS+GlGi4m80wGL6FjAmJPqwHdJ50hCvJULNOXiwFp5aB6kLGsIqj8=" Dec 22 12:48:35 sala go-librespot[18856]: time="2025-12-22T12:48:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:48:35 sala go-librespot[18856]: time="2025-12-22T12:48:35+01:00" level=debug msg="completed keyexchange" Dec 22 12:48:35 sala go-librespot[18856]: time="2025-12-22T12:48:35+01:00" level=debug msg="completed challenge" Dec 22 12:48:35 sala go-librespot[18856]: time="2025-12-22T12:48:35+01: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 22 12:48:35 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:35 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:48:37 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:37 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:38 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 82. Dec 22 12:48:38 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:38 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:38 sala go-librespot[18877]: go-librespot daemon starting... Dec 22 12:48:38 sala go-librespot[18878]: time="2025-12-22T12:48:38+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:48:38 sala go-librespot[18878]: time="2025-12-22T12:48:38+01:00" level=debug msg="app state loaded" Dec 22 12:48:38 sala go-librespot[18878]: time="2025-12-22T12:48:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:48:38 sala go-librespot[18878]: time="2025-12-22T12:48:38+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 22 12:48:38 sala go-librespot[18878]: time="2025-12-22T12:48:38+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 22 12:48:38 sala go-librespot[18878]: time="2025-12-22T12:48:38+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 22 12:48:38 sala go-librespot[18878]: time="2025-12-22T12:48:38+01:00" level=info msg="zeroconf server listening on port 34729" Dec 22 12:48:39 sala go-librespot[18878]: time="2025-12-22T12:48:39+01:00" level=debug msg="obtained new client token: AAC1pTicWgO+icCf5DTnXDrNyLNzxViTLHfAosaQ3w1i7Ea8WLNvoYknDQtxdNQarNElFF3ohAKqKGrJzDmR8wjVrAXWpXOFuKk7KgEjOPT5694HrCicuHa4mze2quvSBvJzQ8aoDjRLCUK3sr1dLapxq9xWBYwyGtBWnwIKEupYi9bBgeMwxNhYwUwyL1SEm1VUfnxjt3wrOL6wf2sEILvpceXvCUTQekPtgg6nGSpihMouaJLL" Dec 22 12:48:39 sala go-librespot[18878]: time="2025-12-22T12:48:39+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:48:39 sala go-librespot[18878]: time="2025-12-22T12:48:39+01:00" level=debug msg="completed keyexchange" Dec 22 12:48:39 sala go-librespot[18878]: time="2025-12-22T12:48:39+01:00" level=debug msg="completed challenge" Dec 22 12:48:39 sala go-librespot[18878]: time="2025-12-22T12:48:39+01: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 22 12:48:39 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:39 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:48:39 sala systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 11305. Dec 22 12:48:39 sala systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 22 12:48:39 sala systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 22 12:48:39 sala upmpdcli[18885]: Could not open config: /tmp/upmpdcli.conf Dec 22 12:48:39 sala systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:39 sala systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 22 12:48:40 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:40 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:42 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 83. Dec 22 12:48:42 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:42 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:42 sala go-librespot[18886]: go-librespot daemon starting... Dec 22 12:48:42 sala go-librespot[18887]: time="2025-12-22T12:48:42+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:48:42 sala go-librespot[18887]: time="2025-12-22T12:48:42+01:00" level=debug msg="app state loaded" Dec 22 12:48:42 sala go-librespot[18887]: time="2025-12-22T12:48:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:48:42 sala go-librespot[18887]: time="2025-12-22T12:48:42+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 22 12:48:42 sala go-librespot[18887]: time="2025-12-22T12:48:42+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 22 12:48:42 sala go-librespot[18887]: time="2025-12-22T12:48:42+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 22 12:48:42 sala go-librespot[18887]: time="2025-12-22T12:48:42+01:00" level=info msg="zeroconf server listening on port 44857" Dec 22 12:48:42 sala go-librespot[18887]: time="2025-12-22T12:48:42+01:00" level=debug msg="obtained new client token: AAAeKR0uXVog3Hk/xk3E1pheeJJS+K99iOHMyAZMzXGWEMqecJCstzuueueHfH1AEdvmH2tEwkmhQLy+rwm/ZM1mqOardhbM5Zo0L06sxftYLvI4UZEa7Vbe4FEta1fUzpvSZdwQZzyPbn2THamsiprjUOkwJGMz+5ICZ52yNdbWr4b2/HXkCL3AsPz/TBWYZLNGMrGzV209VhStZahExHr3djOtPmMcMOy3oxLtECcT+pq2H60VDdU=" Dec 22 12:48:42 sala go-librespot[18887]: time="2025-12-22T12:48:42+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:48:42 sala go-librespot[18887]: time="2025-12-22T12:48:42+01:00" level=debug msg="completed keyexchange" Dec 22 12:48:42 sala go-librespot[18887]: time="2025-12-22T12:48:42+01:00" level=debug msg="completed challenge" Dec 22 12:48:43 sala go-librespot[18887]: time="2025-12-22T12:48:43+01: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 22 12:48:43 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:43 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:48:43 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:43 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:46 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 84. Dec 22 12:48:46 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:46 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:46 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:46 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:46 sala go-librespot[18895]: go-librespot daemon starting... Dec 22 12:48:46 sala go-librespot[18896]: time="2025-12-22T12:48:46+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:48:46 sala go-librespot[18896]: time="2025-12-22T12:48:46+01:00" level=debug msg="app state loaded" Dec 22 12:48:46 sala go-librespot[18896]: time="2025-12-22T12:48:46+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:48:46 sala go-librespot[18896]: time="2025-12-22T12:48:46+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 22 12:48:46 sala go-librespot[18896]: time="2025-12-22T12:48:46+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 22 12:48:46 sala go-librespot[18896]: time="2025-12-22T12:48:46+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 22 12:48:46 sala go-librespot[18896]: time="2025-12-22T12:48:46+01:00" level=info msg="zeroconf server listening on port 35017" Dec 22 12:48:46 sala go-librespot[18896]: time="2025-12-22T12:48:46+01:00" level=debug msg="obtained new client token: AAC32BvAYYaU6MfbkZOQJzF9uwUBA9o9BlHfupERsS4mT+OemvTk0KpOu/eccnSH2PMN2pb7Cd3PeEMbD0GGSndmf06gYo2826atN5fy1v8HzyHs66gheUw3y5nx22qEeTnIGvb1r/b9McED2uFXXx6Km0gF3GhMG0EnAl3RUaa93xF1JNkT+rPkUia0vZB195mzhBx1m0cKfsI3DcBmRtf/TYgHm1g0nFdVYndIi8v5nuR5L+qO7pw=" Dec 22 12:48:46 sala go-librespot[18896]: time="2025-12-22T12:48:46+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:48:46 sala go-librespot[18896]: time="2025-12-22T12:48:46+01:00" level=debug msg="completed keyexchange" Dec 22 12:48:46 sala go-librespot[18896]: time="2025-12-22T12:48:46+01:00" level=debug msg="completed challenge" Dec 22 12:48:46 sala go-librespot[18896]: time="2025-12-22T12:48:46+01: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 22 12:48:46 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:46 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:48:49 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:49 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:49 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 85. Dec 22 12:48:49 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:49 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:49 sala go-librespot[18917]: go-librespot daemon starting... Dec 22 12:48:49 sala go-librespot[18918]: time="2025-12-22T12:48:49+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:48:49 sala go-librespot[18918]: time="2025-12-22T12:48:49+01:00" level=debug msg="app state loaded" Dec 22 12:48:49 sala go-librespot[18918]: time="2025-12-22T12:48:49+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:48:50 sala go-librespot[18918]: time="2025-12-22T12:48:50+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 22 12:48:50 sala go-librespot[18918]: time="2025-12-22T12:48:50+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 22 12:48:50 sala go-librespot[18918]: time="2025-12-22T12:48:50+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 22 12:48:50 sala go-librespot[18918]: time="2025-12-22T12:48:50+01:00" level=info msg="zeroconf server listening on port 39071" Dec 22 12:48:50 sala go-librespot[18918]: time="2025-12-22T12:48:50+01:00" level=debug msg="obtained new client token: AAB8e4HhgMkDZsINrtFFIYdmHYCT++XLkcd+bFL+ue27qVKKCJ/Gx24NQSUrMBLTCaawQLGabiGPKV8pl9eVOtCP+tpWS0CYCQSX93GgfPHPrG4T7Bsfia1RpsbRAbBdRUTKaTpgNo5AqDfa8PE0PLOr667BNUltmPbBx25S0fSZr+qu6L8nQgEd/9f2QE6dFqCtcnYaz+uCOwxAlMaydYjh4xhwvQe9+cV9WikMKmNsHTUwNDlpT0s=" Dec 22 12:48:50 sala go-librespot[18918]: time="2025-12-22T12:48:50+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:48:50 sala go-librespot[18918]: time="2025-12-22T12:48:50+01:00" level=debug msg="completed keyexchange" Dec 22 12:48:50 sala go-librespot[18918]: time="2025-12-22T12:48:50+01:00" level=debug msg="completed challenge" Dec 22 12:48:50 sala go-librespot[18918]: time="2025-12-22T12:48:50+01: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 22 12:48:50 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:50 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:48:52 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:52 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:53 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 86. Dec 22 12:48:53 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:53 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:53 sala go-librespot[18928]: go-librespot daemon starting... Dec 22 12:48:53 sala go-librespot[18929]: time="2025-12-22T12:48:53+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:48:53 sala go-librespot[18929]: time="2025-12-22T12:48:53+01:00" level=debug msg="app state loaded" Dec 22 12:48:53 sala go-librespot[18929]: time="2025-12-22T12:48:53+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:48:53 sala go-librespot[18929]: time="2025-12-22T12:48:53+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 22 12:48:53 sala go-librespot[18929]: time="2025-12-22T12:48:53+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 22 12:48:53 sala go-librespot[18929]: time="2025-12-22T12:48:53+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 22 12:48:53 sala go-librespot[18929]: time="2025-12-22T12:48:53+01:00" level=info msg="zeroconf server listening on port 37595" Dec 22 12:48:54 sala go-librespot[18929]: time="2025-12-22T12:48:54+01:00" level=debug msg="obtained new client token: AAAwtEwiY/8/kk759lHDh4Hhdengjw+cfmJ/NC/aei+Y6QSVCfsNT4SBgUZFReDfNP3Fojs8Tt1bvbpAsW9n0xMR8y/hLXdKX1lhBxCAiInhe9YyjbR3Ii7R7MZKt+lag+zqceCCDDlbANs+iHWfUf9YuoC41By93po/qejh3qIn9+V0HhAAIirNvtc7QKskOpXX6sM2ahjYHd3322FpFiC+pIIQ3Enp+zQ5+uJEbvgYMezA7s6w" Dec 22 12:48:54 sala go-librespot[18929]: time="2025-12-22T12:48:54+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:48:54 sala systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 11306. Dec 22 12:48:54 sala systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 22 12:48:54 sala systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 22 12:48:54 sala upmpdcli[18936]: Could not open config: /tmp/upmpdcli.conf Dec 22 12:48:54 sala systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:54 sala systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 22 12:48:55 sala go-librespot[18929]: time="2025-12-22T12:48:55+01:00" level=debug msg="completed keyexchange" Dec 22 12:48:55 sala go-librespot[18929]: time="2025-12-22T12:48:55+01:00" level=debug msg="completed challenge" Dec 22 12:48:55 sala go-librespot[18929]: time="2025-12-22T12:48:55+01: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 22 12:48:55 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:55 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:48:55 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:55 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:58 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87. Dec 22 12:48:58 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:58 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:48:58 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:48:58 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:48:58 sala go-librespot[18951]: go-librespot daemon starting... Dec 22 12:48:58 sala go-librespot[18952]: time="2025-12-22T12:48:58+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:48:58 sala go-librespot[18952]: time="2025-12-22T12:48:58+01:00" level=debug msg="app state loaded" Dec 22 12:48:58 sala go-librespot[18952]: time="2025-12-22T12:48:58+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:48:58 sala go-librespot[18952]: time="2025-12-22T12:48:58+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 22 12:48:58 sala go-librespot[18952]: time="2025-12-22T12:48:58+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 22 12:48:58 sala go-librespot[18952]: time="2025-12-22T12:48:58+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 22 12:48:58 sala go-librespot[18952]: time="2025-12-22T12:48:58+01:00" level=info msg="zeroconf server listening on port 38501" Dec 22 12:48:58 sala go-librespot[18952]: time="2025-12-22T12:48:58+01:00" level=debug msg="obtained new client token: AAD+cUvqntvEeLKPeuPOk+U33w0rIYpjhCf5/VF1O4eWjff9WjN/5mnR5u4RPIf7orXJXn/k5AxQZlp8Ag8wl4/Z1L01B+OnE+gVMAAo54zoH/rqECHydEWsVu/OBU9nm7iZmb7a4JEcOvX0NjjjNNN8mYJ3Zhwn9+xiVrn0wWkHiFNXXnT7f8AIiHTeJjAordF/6ovqhoxaCwdUSZ4CnNIO8bcxanJ21lJ0cVtg7yl8KNy9AXo15cQ=" Dec 22 12:48:58 sala go-librespot[18952]: time="2025-12-22T12:48:58+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:48:58 sala go-librespot[18952]: time="2025-12-22T12:48:58+01:00" level=debug msg="completed keyexchange" Dec 22 12:48:58 sala go-librespot[18952]: time="2025-12-22T12:48:58+01:00" level=debug msg="completed challenge" Dec 22 12:48:58 sala go-librespot[18952]: time="2025-12-22T12:48:58+01: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 22 12:48:58 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:48:58 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:49:01 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:49:01 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:49:01 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 88. Dec 22 12:49:01 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:01 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:01 sala go-librespot[18959]: go-librespot daemon starting... Dec 22 12:49:02 sala go-librespot[18960]: time="2025-12-22T12:49:02+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:49:02 sala go-librespot[18960]: time="2025-12-22T12:49:02+01:00" level=debug msg="app state loaded" Dec 22 12:49:02 sala go-librespot[18960]: time="2025-12-22T12:49:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:49:02 sala go-librespot[18960]: time="2025-12-22T12:49:02+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 22 12:49:02 sala go-librespot[18960]: time="2025-12-22T12:49:02+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 22 12:49:02 sala go-librespot[18960]: time="2025-12-22T12:49:02+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 22 12:49:02 sala go-librespot[18960]: time="2025-12-22T12:49:02+01:00" level=info msg="zeroconf server listening on port 33937" Dec 22 12:49:02 sala go-librespot[18960]: time="2025-12-22T12:49:02+01:00" level=debug msg="obtained new client token: AAAnrE6VcSlh9jLoL++OJhP/HdDR+9KiVcREMiSnK0vWKG5UTealTK+r3ICn+nnGQiyAWGX0lRUmX8qdMJlFcL8NLqWq+xtOWyz3TDboWzkIeAauQBSMD4hafIs+80BxDSP5AJFH+N2Bdp577+OGGFUk2zxbeoJfUAk5ibvy369gMbyIGUiMiWiKRVjhipE9Iqvsa6ztgtI9BsjyecvyI1AVX83JxxPTDbmF5XysB6RVU2Jv6K9mLuw=" Dec 22 12:49:02 sala go-librespot[18960]: time="2025-12-22T12:49:02+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:49:02 sala go-librespot[18960]: time="2025-12-22T12:49:02+01:00" level=debug msg="completed keyexchange" Dec 22 12:49:02 sala go-librespot[18960]: time="2025-12-22T12:49:02+01:00" level=debug msg="completed challenge" Dec 22 12:49:02 sala go-librespot[18960]: time="2025-12-22T12:49:02+01: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 22 12:49:02 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:49:02 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:49:04 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:49:04 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:49:05 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 89. Dec 22 12:49:05 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:05 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:05 sala go-librespot[18969]: go-librespot daemon starting... Dec 22 12:49:05 sala go-librespot[18970]: time="2025-12-22T12:49:05+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:49:05 sala go-librespot[18970]: time="2025-12-22T12:49:05+01:00" level=debug msg="app state loaded" Dec 22 12:49:05 sala go-librespot[18970]: time="2025-12-22T12:49:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:49:05 sala go-librespot[18970]: time="2025-12-22T12:49:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 22 12:49:05 sala go-librespot[18970]: time="2025-12-22T12:49:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 22 12:49:05 sala go-librespot[18970]: time="2025-12-22T12:49:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 22 12:49:05 sala go-librespot[18970]: time="2025-12-22T12:49:05+01:00" level=info msg="zeroconf server listening on port 44019" Dec 22 12:49:06 sala go-librespot[18970]: time="2025-12-22T12:49:06+01:00" level=debug msg="obtained new client token: AAAKohru7l+Ow7pLHsTC1zUwuMdmiBDHvRHlYRJouyqyaLOgD9EZR/AFiIXz9lRMlIubeHs6VTREggJnXWRD6oO64YWXykc03TDCNWVY09CTi5tihVmdwYL8mXVWPnKgC44ZyVgwbQIfo1koBFd6tMv18LKAcgQ2WVt7Qqfgip7UUUxaImYFQQ/nvatALptuLY5iSIG5DnqkQ7UM4idsF5qSvzKCV0EGJJoEQQrxjOTR/OGckn/5" Dec 22 12:49:06 sala go-librespot[18970]: time="2025-12-22T12:49:06+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:49:06 sala go-librespot[18970]: time="2025-12-22T12:49:06+01:00" level=debug msg="completed keyexchange" Dec 22 12:49:06 sala go-librespot[18970]: time="2025-12-22T12:49:06+01:00" level=debug msg="completed challenge" Dec 22 12:49:06 sala go-librespot[18970]: time="2025-12-22T12:49:06+01: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 22 12:49:06 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:49:06 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:49:07 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:49:07 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:49:09 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 90. Dec 22 12:49:09 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:09 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:09 sala go-librespot[18991]: go-librespot daemon starting... Dec 22 12:49:09 sala go-librespot[18992]: time="2025-12-22T12:49:09+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:49:09 sala go-librespot[18992]: time="2025-12-22T12:49:09+01:00" level=debug msg="app state loaded" Dec 22 12:49:09 sala go-librespot[18992]: time="2025-12-22T12:49:09+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:49:09 sala systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 11307. Dec 22 12:49:09 sala systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 22 12:49:09 sala go-librespot[18992]: time="2025-12-22T12:49:09+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 22 12:49:09 sala go-librespot[18992]: time="2025-12-22T12:49:09+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 22 12:49:09 sala go-librespot[18992]: time="2025-12-22T12:49:09+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 22 12:49:09 sala go-librespot[18992]: time="2025-12-22T12:49:09+01:00" level=info msg="zeroconf server listening on port 35475" Dec 22 12:49:09 sala systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 22 12:49:09 sala upmpdcli[18999]: Could not open config: /tmp/upmpdcli.conf Dec 22 12:49:09 sala systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:49:09 sala systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 22 12:49:09 sala go-librespot[18992]: time="2025-12-22T12:49:09+01:00" level=debug msg="obtained new client token: AAACQJHnMLo/2zD97w8hA//IePukUSb+NWB+f739J8p1zenxARydw9KbXnlxVK5v/r28ftLUFbYksWuFMK410EzFrxW6COL+gwepuBfl5iXTWZEFwYqThMfFNKiqSkkZj86r7t1GLORSP2KfCeLU1yBRaU1VnWcg4ZKfNna5apjgYMYn0VIgEfp+VI9oPMcSSgOJaLfx13YZ73Q/NqcJBbleRLz+B4SVlrSDCRRgm8bVu34Zd1Td8R4=" Dec 22 12:49:09 sala go-librespot[18992]: time="2025-12-22T12:49:09+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:49:09 sala go-librespot[18992]: time="2025-12-22T12:49:09+01:00" level=debug msg="completed keyexchange" Dec 22 12:49:09 sala go-librespot[18992]: time="2025-12-22T12:49:09+01:00" level=debug msg="completed challenge" Dec 22 12:49:10 sala go-librespot[18992]: time="2025-12-22T12:49:10+01: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 22 12:49:10 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:49:10 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:49:10 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:49:10 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:49:13 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 91. Dec 22 12:49:13 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:13 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:49:13 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:49:13 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:13 sala go-librespot[19003]: go-librespot daemon starting... Dec 22 12:49:13 sala go-librespot[19004]: time="2025-12-22T12:49:13+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:49:13 sala go-librespot[19004]: time="2025-12-22T12:49:13+01:00" level=debug msg="app state loaded" Dec 22 12:49:13 sala go-librespot[19004]: time="2025-12-22T12:49:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:49:13 sala go-librespot[19004]: time="2025-12-22T12:49:13+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 22 12:49:13 sala go-librespot[19004]: time="2025-12-22T12:49:13+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 22 12:49:13 sala go-librespot[19004]: time="2025-12-22T12:49:13+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 22 12:49:13 sala go-librespot[19004]: time="2025-12-22T12:49:13+01:00" level=info msg="zeroconf server listening on port 33619" Dec 22 12:49:13 sala go-librespot[19004]: time="2025-12-22T12:49:13+01:00" level=debug msg="obtained new client token: AADSHLl5ZQh92bRWpAsr7OkdYVNmIIz7YghSfQfrrmtLTJ0kBroMZy2Kchk2kR86y54Q7SH3FvV52U19ewVfepHmPzq2ssQAtjbaeEriLV3T0/x6rnHrNHXUJVnv4fP+JeftuxFxL716b2hTIwjgkp9nI9diPVrwpVNMrDsCjiBeuc+Ics6qF5BjvHSX3NdQRXtnLDF/WKXzvhawXO7VwHzD6GOMCk5t6URKZSdKn2GhlCENhtCH0kk=" Dec 22 12:49:13 sala go-librespot[19004]: time="2025-12-22T12:49:13+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Dec 22 12:49:13 sala go-librespot[19004]: time="2025-12-22T12:49:13+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Dec 22 12:49:13 sala go-librespot[19004]: time="2025-12-22T12:49:13+01:00" level=debug msg="completed keyexchange" Dec 22 12:49:13 sala go-librespot[19004]: time="2025-12-22T12:49:13+01:00" level=debug msg="completed challenge" Dec 22 12:49:13 sala go-librespot[19004]: time="2025-12-22T12:49:13+01: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 22 12:49:13 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:49:13 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:49:16 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:49:16 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:49:16 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 92. Dec 22 12:49:16 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:16 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:16 sala go-librespot[19025]: go-librespot daemon starting... Dec 22 12:49:16 sala go-librespot[19026]: time="2025-12-22T12:49:16+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:49:16 sala go-librespot[19026]: time="2025-12-22T12:49:16+01:00" level=debug msg="app state loaded" Dec 22 12:49:16 sala go-librespot[19026]: time="2025-12-22T12:49:16+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:49:17 sala go-librespot[19026]: time="2025-12-22T12:49:17+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 22 12:49:17 sala go-librespot[19026]: time="2025-12-22T12:49:17+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 22 12:49:17 sala go-librespot[19026]: time="2025-12-22T12:49:17+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 22 12:49:17 sala go-librespot[19026]: time="2025-12-22T12:49:17+01:00" level=info msg="zeroconf server listening on port 45557" Dec 22 12:49:17 sala go-librespot[19026]: time="2025-12-22T12:49:17+01:00" level=debug msg="obtained new client token: AAAeXaMgp32AJzUIudK+1SfEkONV6lxO3y3sGHPIgvC6MUzfXPSneFIFUpKT8VmCGJHt6WQ0pLusVXHa6TZFDsLtOMUB7anFCmykQWuo3OPFDDBtwreceTQ1tBRn64sE5PmqFl1f73rB2ALFPGZ0jZrbDemVk8cnEDL2KGdXEgIoibUHfmomJdCL9LNNnfAnJVefaWtHiBZ4O4rYANZvZCLdNOmjBHxcNAG0ShgmQpnj6OQlLSQblyU=" Dec 22 12:49:17 sala go-librespot[19026]: time="2025-12-22T12:49:17+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:49:17 sala go-librespot[19026]: time="2025-12-22T12:49:17+01:00" level=debug msg="completed keyexchange" Dec 22 12:49:17 sala go-librespot[19026]: time="2025-12-22T12:49:17+01:00" level=debug msg="completed challenge" Dec 22 12:49:17 sala go-librespot[19026]: time="2025-12-22T12:49:17+01: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 22 12:49:17 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:49:17 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:49:19 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:49:19 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:49:20 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93. Dec 22 12:49:20 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:20 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:20 sala go-librespot[19033]: go-librespot daemon starting... Dec 22 12:49:20 sala go-librespot[19034]: time="2025-12-22T12:49:20+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:49:20 sala go-librespot[19034]: time="2025-12-22T12:49:20+01:00" level=debug msg="app state loaded" Dec 22 12:49:20 sala go-librespot[19034]: time="2025-12-22T12:49:20+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:49:20 sala go-librespot[19034]: time="2025-12-22T12:49:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 22 12:49:20 sala go-librespot[19034]: time="2025-12-22T12:49:20+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 22 12:49:20 sala go-librespot[19034]: time="2025-12-22T12:49:20+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 22 12:49:20 sala go-librespot[19034]: time="2025-12-22T12:49:20+01:00" level=info msg="zeroconf server listening on port 43425" Dec 22 12:49:21 sala go-librespot[19034]: time="2025-12-22T12:49:21+01:00" level=debug msg="obtained new client token: AAA3rn2bmn1aAFVoHz4wYKI0+Bgl20GrIWPpoFJb0hxki6TwRli6KZ14EogeFhbTHTVwjy0t/50PvDYwm8MMlBOkTRtcGaTvIJbKLH9lur4pKbaxwymFWGZ47i1kWywx4Rr8adf/C0CZUR1ZdRJqSRzNjY60rl7AFymAWyvepp3yw6oaisnbfUg6AG77jTfkNlu4P3upgqoKDDA+VdhP8DxIP37bm+2YcD/CUZpebfFxajYNG5Zh" Dec 22 12:49:21 sala go-librespot[19034]: time="2025-12-22T12:49:21+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:49:21 sala go-librespot[19034]: time="2025-12-22T12:49:21+01:00" level=debug msg="completed keyexchange" Dec 22 12:49:21 sala go-librespot[19034]: time="2025-12-22T12:49:21+01:00" level=debug msg="completed challenge" Dec 22 12:49:21 sala go-librespot[19034]: time="2025-12-22T12:49:21+01: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 22 12:49:21 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:49:21 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:49:22 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:49:22 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:49:24 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 94. Dec 22 12:49:24 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:24 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:24 sala go-librespot[19042]: go-librespot daemon starting... Dec 22 12:49:24 sala go-librespot[19043]: time="2025-12-22T12:49:24+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:49:24 sala go-librespot[19043]: time="2025-12-22T12:49:24+01:00" level=debug msg="app state loaded" Dec 22 12:49:24 sala go-librespot[19043]: time="2025-12-22T12:49:24+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:49:24 sala go-librespot[19043]: time="2025-12-22T12:49:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 22 12:49:24 sala go-librespot[19043]: time="2025-12-22T12:49:24+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 22 12:49:24 sala go-librespot[19043]: time="2025-12-22T12:49:24+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 22 12:49:24 sala go-librespot[19043]: time="2025-12-22T12:49:24+01:00" level=info msg="zeroconf server listening on port 46293" Dec 22 12:49:24 sala go-librespot[19043]: time="2025-12-22T12:49:24+01:00" level=debug msg="obtained new client token: AADv2+Qgt/oENkf/Qckqs1FUVD9WJKV2l97+uzUhrsp5gs9dLHqO4KHmwHnxnp3aedHJwUxPdXn1G503uYil++eheWl/+2VzKJEpkTiN7o8wgMaDygbg+VTs6npkzvf8AZa6joPR4ewzKXAfj+cV7HxGAqElUItKxrkOETf1nWQDs0eDzNEc1GUlJQFflGSmebvjpuBfYQXiEzCtmrccKcLNEViighBBd3Il7YsdQ/hG96rHLk9UiMc=" Dec 22 12:49:24 sala systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 11308. Dec 22 12:49:24 sala systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 22 12:49:24 sala go-librespot[19043]: time="2025-12-22T12:49:24+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:49:24 sala go-librespot[19043]: time="2025-12-22T12:49:24+01:00" level=debug msg="completed keyexchange" Dec 22 12:49:24 sala go-librespot[19043]: time="2025-12-22T12:49:24+01:00" level=debug msg="completed challenge" Dec 22 12:49:24 sala systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 22 12:49:25 sala upmpdcli[19050]: Could not open config: /tmp/upmpdcli.conf Dec 22 12:49:25 sala systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:49:25 sala systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 22 12:49:25 sala go-librespot[19043]: time="2025-12-22T12:49:25+01: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 22 12:49:25 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:49:25 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:49:25 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:49:25 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:49:28 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 95. Dec 22 12:49:28 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:28 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:28 sala go-librespot[19065]: go-librespot daemon starting... Dec 22 12:49:28 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:49:28 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:49:28 sala go-librespot[19066]: time="2025-12-22T12:49:28+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:49:28 sala go-librespot[19066]: time="2025-12-22T12:49:28+01:00" level=debug msg="app state loaded" Dec 22 12:49:28 sala go-librespot[19066]: time="2025-12-22T12:49:28+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:49:28 sala go-librespot[19066]: time="2025-12-22T12:49:28+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 22 12:49:28 sala go-librespot[19066]: time="2025-12-22T12:49:28+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 22 12:49:28 sala go-librespot[19066]: time="2025-12-22T12:49:28+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 22 12:49:28 sala go-librespot[19066]: time="2025-12-22T12:49:28+01:00" level=info msg="zeroconf server listening on port 34233" Dec 22 12:49:28 sala go-librespot[19066]: time="2025-12-22T12:49:28+01:00" level=debug msg="obtained new client token: AAB77o+HO397h0x0t6OJ+W78MzacPm6ZNegEUOPvfDyGJ6zh/RHznLvMqGlONAHrwF/E9Ws7LiG9XBl5behRBPUqwQtHk9qNjvbKw+pSxachC8crIGN914nnVlge0eN/w9jqexJqzwAooz93ZDcLu8y46yE/BCC+lDK9+vN8yFbh6UBQtb9daOHdPWzfpl9t8Ecd4fIkSID1i5vzVZe6HDUveWqhN7y8zdtk4QkZpZkwYxjxoafGYYg=" Dec 22 12:49:28 sala go-librespot[19066]: time="2025-12-22T12:49:28+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Dec 22 12:49:28 sala go-librespot[19066]: time="2025-12-22T12:49:28+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Dec 22 12:49:28 sala go-librespot[19066]: time="2025-12-22T12:49:28+01:00" level=debug msg="completed keyexchange" Dec 22 12:49:28 sala go-librespot[19066]: time="2025-12-22T12:49:28+01:00" level=debug msg="completed challenge" Dec 22 12:49:28 sala go-librespot[19066]: time="2025-12-22T12:49:28+01: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 22 12:49:28 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:49:28 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:49:31 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:49:31 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:49:31 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 96. Dec 22 12:49:31 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:31 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:31 sala go-librespot[19073]: go-librespot daemon starting... Dec 22 12:49:31 sala go-librespot[19074]: time="2025-12-22T12:49:31+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:49:31 sala go-librespot[19074]: time="2025-12-22T12:49:31+01:00" level=debug msg="app state loaded" Dec 22 12:49:31 sala go-librespot[19074]: time="2025-12-22T12:49:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:49:32 sala go-librespot[19074]: time="2025-12-22T12:49:32+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 22 12:49:32 sala go-librespot[19074]: time="2025-12-22T12:49:32+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 22 12:49:32 sala go-librespot[19074]: time="2025-12-22T12:49:32+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 22 12:49:32 sala go-librespot[19074]: time="2025-12-22T12:49:32+01:00" level=info msg="zeroconf server listening on port 45165" Dec 22 12:49:32 sala go-librespot[19074]: time="2025-12-22T12:49:32+01:00" level=debug msg="obtained new client token: AADJ6OrbA+KDO7ukQwGdiI25v610jdLKv8WxtkbRA9Z4gjHEQYEpXkqs47myjMtvb3oKi/4cpT9X/d7Wj5eWO+0kJ0WxCqgzp/uWTBouZPbPlNysj3sDSw99gBDRJCXGP6u9glugRJ7b2BMp7R72sit8UzLYwqsomHGZVzQtzMOAsjMmROPhC1+YiJz8EVZZ7qmqKeXnCJp95h+rRtUIUkFv/7b7MUyNPchL7+L6FKkrffmaoTmYGxY=" Dec 22 12:49:32 sala go-librespot[19074]: time="2025-12-22T12:49:32+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:49:32 sala go-librespot[19074]: time="2025-12-22T12:49:32+01:00" level=debug msg="completed keyexchange" Dec 22 12:49:32 sala go-librespot[19074]: time="2025-12-22T12:49:32+01:00" level=debug msg="completed challenge" Dec 22 12:49:32 sala go-librespot[19074]: time="2025-12-22T12:49:32+01: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 22 12:49:32 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:49:32 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:49:34 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:49:34 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:49:35 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 97. Dec 22 12:49:35 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:35 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:35 sala go-librespot[19084]: go-librespot daemon starting... Dec 22 12:49:35 sala go-librespot[19085]: time="2025-12-22T12:49:35+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:49:35 sala go-librespot[19085]: time="2025-12-22T12:49:35+01:00" level=debug msg="app state loaded" Dec 22 12:49:35 sala go-librespot[19085]: time="2025-12-22T12:49:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:49:35 sala go-librespot[19085]: time="2025-12-22T12:49:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 22 12:49:35 sala go-librespot[19085]: time="2025-12-22T12:49:35+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 22 12:49:35 sala go-librespot[19085]: time="2025-12-22T12:49:35+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 22 12:49:35 sala go-librespot[19085]: time="2025-12-22T12:49:35+01:00" level=info msg="zeroconf server listening on port 34929" Dec 22 12:49:36 sala go-librespot[19085]: time="2025-12-22T12:49:36+01:00" level=debug msg="obtained new client token: AAB7TaMQ5aNEQoyv/WZ5mWcBjm8DDeTCMkut/iQ7tNppDACQ23CTEjWf0F7KAgomouTqbd6jIo2Wl3qvCbGJp4D7BVfy+3SKsf9YzgBW149Ymfp8+sCbqmrxrkj9EC/FanU0kRNVdEHbd+yX/rjwq4v2ayIEOuztig0NPPgxqpH+mD7wS4sVtCRIGS3BujU2w6wgB8QtVba5LsycgL/6vNSY11fTzjaY61j1fv4VBz4UKEC/M6IM" Dec 22 12:49:36 sala go-librespot[19085]: time="2025-12-22T12:49:36+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:49:36 sala go-librespot[19085]: time="2025-12-22T12:49:36+01:00" level=debug msg="completed keyexchange" Dec 22 12:49:36 sala go-librespot[19085]: time="2025-12-22T12:49:36+01:00" level=debug msg="completed challenge" Dec 22 12:49:36 sala go-librespot[19085]: time="2025-12-22T12:49:36+01: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 22 12:49:36 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:49:36 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:49:37 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:49:37 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:49:39 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 98. Dec 22 12:49:39 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:39 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:39 sala go-librespot[19106]: go-librespot daemon starting... Dec 22 12:49:39 sala go-librespot[19107]: time="2025-12-22T12:49:39+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:49:39 sala go-librespot[19107]: time="2025-12-22T12:49:39+01:00" level=debug msg="app state loaded" Dec 22 12:49:39 sala go-librespot[19107]: time="2025-12-22T12:49:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:49:39 sala go-librespot[19107]: time="2025-12-22T12:49:39+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 22 12:49:39 sala go-librespot[19107]: time="2025-12-22T12:49:39+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 22 12:49:39 sala go-librespot[19107]: time="2025-12-22T12:49:39+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 22 12:49:39 sala go-librespot[19107]: time="2025-12-22T12:49:39+01:00" level=info msg="zeroconf server listening on port 36917" Dec 22 12:49:39 sala go-librespot[19107]: time="2025-12-22T12:49:39+01:00" level=debug msg="obtained new client token: AAA4V1YHE0Zfh2hKlpFLr0rw8Z0W6lE75h9r+zTK+QWWP6orUrSf2KhXaCojkcR6bpCPEouwxAiFa9kZwDUEjhB8Y+QMewNiZVIF86oLVnCv2zlmBmgQoiXvCgkNo2Q8cRIvwVtKgaUtKokFbUoKPSFQmt8NSYnyb1PF/qDaVCFguN+tWQo6YwLJUgu/NgAm2KzvL/cAySVjRQ+w1r48wuOAVBhJxEewqXYKTN9uJ/xAF6LgcRruV3A=" Dec 22 12:49:39 sala go-librespot[19107]: time="2025-12-22T12:49:39+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:49:39 sala go-librespot[19107]: time="2025-12-22T12:49:39+01:00" level=debug msg="completed keyexchange" Dec 22 12:49:39 sala go-librespot[19107]: time="2025-12-22T12:49:39+01:00" level=debug msg="completed challenge" Dec 22 12:49:40 sala go-librespot[19107]: time="2025-12-22T12:49:40+01: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 22 12:49:40 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:49:40 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:49:40 sala systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 11309. Dec 22 12:49:40 sala systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 22 12:49:40 sala systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 22 12:49:40 sala upmpdcli[19114]: Could not open config: /tmp/upmpdcli.conf Dec 22 12:49:40 sala systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:49:40 sala systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 22 12:49:40 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:49:40 sala volumio[18263]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:49:43 sala systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99. Dec 22 12:49:43 sala systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:43 sala systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 12:49:43 sala go-librespot[19116]: go-librespot daemon starting... Dec 22 12:49:43 sala go-librespot[19117]: time="2025-12-22T12:49:43+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 12:49:43 sala go-librespot[19117]: time="2025-12-22T12:49:43+01:00" level=debug msg="app state loaded" Dec 22 12:49:43 sala go-librespot[19117]: time="2025-12-22T12:49:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 12:49:43 sala volumio[18263]: info: Initializing connection to go-librespot Websocket Dec 22 12:49:43 sala go-librespot[19117]: time="2025-12-22T12:49:43+01:00" level=debug msg="new websocket client" Dec 22 12:49:43 sala volumio[18263]: info: Connection to go-librespot Websocket established Dec 22 12:49:43 sala go-librespot[19117]: time="2025-12-22T12:49:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 22 12:49:43 sala go-librespot[19117]: time="2025-12-22T12:49:43+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 22 12:49:43 sala go-librespot[19117]: time="2025-12-22T12:49:43+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 22 12:49:43 sala go-librespot[19117]: time="2025-12-22T12:49:43+01:00" level=info msg="zeroconf server listening on port 45673" Dec 22 12:49:43 sala go-librespot[19117]: time="2025-12-22T12:49:43+01:00" level=debug msg="obtained new client token: AADWWuOLvE4AcgKauJltJGKqyk/5aQaOv4xiyJPenFCWrSIihuK+OximOoD31ZyXqax4zCWdENYrAW7T6yXenlXa7L1CwheVYuuY01RwubQGQBL6K8ej5dIRAk2IBYorFEnCyLtI2Vu9BLbpwtBlXry+/ZcUYeSHY9wSUPxHBajLu3C56hjgACjuwM26urhnBthzjmTs81A4tYpGFMNKsdzuWDBmx2MEyLwcxL2fKN80JpJYOjyrv6g=" Dec 22 12:49:43 sala go-librespot[19117]: time="2025-12-22T12:49:43+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 12:49:43 sala go-librespot[19117]: time="2025-12-22T12:49:43+01:00" level=debug msg="completed keyexchange" Dec 22 12:49:43 sala go-librespot[19117]: time="2025-12-22T12:49:43+01:00" level=debug msg="completed challenge" Dec 22 12:49:43 sala go-librespot[19117]: time="2025-12-22T12:49:43+01: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 22 12:49:43 sala systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 12:49:43 sala systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 12:49:43 sala volumio[18263]: info: Connection to go-librespot Websocket closed Dec 22 12:49:46 sala volumio[18263]: info: Getting Spotify volume Dec 22 12:49:46 sala volumio[18263]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 12:49:46 sala volumio[18263]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 12:49:46 sala volumio[18263]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 22 12:49:46 sala volumio[18263]: errno: -111, Dec 22 12:49:46 sala volumio[18263]: code: 'ECONNREFUSED', Dec 22 12:49:46 sala volumio[18263]: syscall: 'connect', Dec 22 12:49:46 sala volumio[18263]: address: '127.0.0.1', Dec 22 12:49:46 sala volumio[18263]: port: 9879, Dec 22 12:49:46 sala volumio[18263]: response: undefined Dec 22 12:49:46 sala volumio[18263]: } Dec 22 12:49:46 sala volumio[18263]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 12:49:46 sala sudo[19138]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-22 12:48' Dec 22 12:49:46 sala sudo[19138]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"