Dec 07 19:02:00 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 5 Dec 07 19:02:00 volumiomom sudo[1381]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 07 19:02:00 volumiomom volumio[1188]: info: Discovery: adding 50cf48f0-f0ab-43fd-b5d2-dbffc24cf830 Dec 07 19:02:00 volumiomom volumio[1188]: info: Discovery: Found device VolumioMOM Dec 07 19:02:00 volumiomom volumio[1188]: info: CoreCommandRouter::volumioGetState Dec 07 19:02:00 volumiomom volumio[1188]: info: CorePlayQueue::getTrack 0 Dec 07 19:02:00 volumiomom sudo[1381]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 19:02:00 volumiomom volumio[1188]: info: Discovery: adding 19b40875-e050-4d62-a067-10819903cdd9 Dec 07 19:02:00 volumiomom volumio[1188]: info: Discovery: Found device Volumio Kitchen Dec 07 19:02:01 volumiomom volumio[1188]: info: Discovery: Connecting to remote: 192.168.1.167 Dec 07 19:02:01 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 6 Dec 07 19:02:01 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 7 Dec 07 19:02:02 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 07 19:02:02 volumiomom volumio[1188]: info: Discovery: this is already registered, 50cf48f0-f0ab-43fd-b5d2-dbffc24cf830 Dec 07 19:02:02 volumiomom volumio[1188]: info: Discovery: Found device VolumioMOM Dec 07 19:02:02 volumiomom volumio[1188]: info: CoreCommandRouter::volumioGetState Dec 07 19:02:02 volumiomom volumio[1188]: info: CorePlayQueue::getTrack 0 Dec 07 19:02:02 volumiomom volumio[1188]: info: Discovery: Connected to remote: 192.168.1.167 Dec 07 19:02:03 volumiomom volumio[1188]: info: Completed loading Core Plugins Dec 07 19:02:03 volumiomom volumio[1188]: info: Preparing to generate the ALSA configuration file Dec 07 19:02:03 volumiomom systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 4. Dec 07 19:02:03 volumiomom systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 07 19:02:03 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Dec 07 19:02:03 volumiomom systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 07 19:02:03 volumiomom sudo[1381]: pam_unix(sudo:session): session closed for user root Dec 07 19:02:04 volumiomom volumio[1188]: info: Upmpdcli Daemon Started Dec 07 19:02:04 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 10 Dec 07 19:02:04 volumiomom volumio-remote-updater[692]: [2025-12-07 19:02:04] [connect] Successful connection Dec 07 19:02:04 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Dec 07 19:02:05 volumiomom volumio[1188]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Dec 07 19:02:05 volumiomom volumio[1188]: info: Asound.conf file unchanged, so no further update is needed Dec 07 19:02:05 volumiomom volumio[1188]: info: Output device has changed, restarting MPD Dec 07 19:02:05 volumiomom volumio[1188]: info: Output device has changed, restarting Shairport Sync Dec 07 19:02:05 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:05 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:02:05 volumiomom sudo[1395]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 07 19:02:05 volumiomom sudo[1395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 19:02:05 volumiomom sudo[1395]: pam_unix(sudo:session): session closed for user root Dec 07 19:02:05 volumiomom sudo[1397]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 07 19:02:05 volumiomom sudo[1397]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 19:02:05 volumiomom volumio[1188]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 19:02:05 volumiomom volumio[1188]: info: ___________ START PLUGINS ___________ Dec 07 19:02:05 volumiomom volumio[1188]: info: ControllerMpd::onStart: Initializing MPD Dec 07 19:02:05 volumiomom volumio[1188]: info: Creating MPD Configuration file Dec 07 19:02:06 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 07 19:02:06 volumiomom volumio[1188]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 19:02:06 volumiomom volumio[1188]: info: [1765152126249] CoreMusicLibrary::Adding element Media Servers Dec 07 19:02:06 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 19:02:06 volumiomom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 07 19:02:06 volumiomom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 07 19:02:06 volumiomom sudo[1408]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 07 19:02:06 volumiomom sudo[1405]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 07 19:02:06 volumiomom volumio[1188]: info: UPNP Browser: Client initialized successfully Dec 07 19:02:06 volumiomom sudo[1408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 19:02:06 volumiomom sudo[1405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 19:02:06 volumiomom sudo[1409]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 07 19:02:06 volumiomom sudo[1409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 07 19:02:06 volumiomom sudo[1412]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 07 19:02:06 volumiomom sudo[1409]: pam_unix(sudo:session): session closed for user root Dec 07 19:02:06 volumiomom sudo[1405]: pam_unix(sudo:session): session closed for user root Dec 07 19:02:07 volumiomom systemd[1]: mpd.service: Deactivated successfully. Dec 07 19:02:07 volumiomom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 07 19:02:07 volumiomom systemd[1]: mpd.socket: Deactivated successfully. Dec 07 19:02:07 volumiomom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 07 19:02:07 volumiomom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 07 19:02:07 volumiomom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 07 19:02:07 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:07 volumiomom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 07 19:02:07 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:02:07 volumiomom volumio[1188]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 19:02:07 volumiomom sudo[1416]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 07 19:02:07 volumiomom sudo[1416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 07 19:02:07 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:07 volumiomom sudo[1429]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 07 19:02:07 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:02:07 volumiomom sudo[1416]: pam_unix(sudo:session): session closed for user root Dec 07 19:02:08 volumiomom volumio[1188]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 19:02:08 volumiomom volumio[1188]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 19:02:08 volumiomom volumio[1188]: info: [1765152128279] CoreMusicLibrary::Adding element Last_100 Dec 07 19:02:08 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 19:02:08 volumiomom volumio[1188]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 19:02:08 volumiomom volumio[1188]: info: [1765152128371] CoreMusicLibrary::Adding element Webradio Dec 07 19:02:08 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 19:02:08 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 19:02:08 volumiomom volumio[1188]: info: Initializing BBC Radios Dec 07 19:02:09 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 19:02:09 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:02:09 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 19:02:09 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 19:02:09 volumiomom volumio[1188]: info: Discovery: Getting this device information Dec 07 19:02:09 volumiomom volumio[1188]: info: CoreCommandRouter::volumioGetState Dec 07 19:02:09 volumiomom volumio[1188]: info: CorePlayQueue::getTrack 0 Dec 07 19:02:09 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 19:02:10 volumiomom volumio[1188]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 19:02:10 volumiomom volumio[1188]: info: [1765152130039] CoreMusicLibrary::Adding element Jellyfin Dec 07 19:02:10 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 19:02:10 volumiomom volumio[1188]: Cannot find translation for source Jellyfin Dec 07 19:02:10 volumiomom volumio[1188]: info: [jellyfin] Initialized plugin with device info: {"host":"http://192.168.1.168","id":"50cf48f0-f0ab-43fd-b5d2-dbffc24cf830","name":"VolumioMOM","serviceName":"Volumio","state":{"albumart":"http://cdn-profiles.tunein.com/s22917/images/logoq.png?t=153114","mute":false,"status":"stop","track":"96.1 SOX","volume":86},"type":"device"} Dec 07 19:02:10 volumiomom volumio[1188]: info: Creating Spotify config file Dec 07 19:02:10 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:17 volumiomom volumio[1188]: info: Volumio Calling Home Dec 07 19:02:18 volumiomom volumio[1342]: Starting albumart workers Dec 07 19:02:19 volumiomom volumio-remote-updater[692]: [2025-12-07 19:02:19] [connect] Successful connection Dec 07 19:02:20 volumiomom mpd[1430]: 2025-12-07T19:02:20 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 07 19:02:20 volumiomom systemd[1]: Started mpd.service - Music Player Daemon. Dec 07 19:02:20 volumiomom sudo[1397]: pam_unix(sudo:session): session closed for user root Dec 07 19:02:20 volumiomom sudo[1408]: pam_unix(sudo:session): session closed for user root Dec 07 19:02:20 volumiomom volumio[1346]: Starting albumart workers Dec 07 19:02:21 volumiomom volumio[1344]: Starting albumart workers Dec 07 19:02:23 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 12 Dec 07 19:02:24 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 13 Dec 07 19:02:24 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Dec 07 19:02:25 volumiomom volumio[1188]: info: Completed starting Core Plugins Dec 07 19:02:25 volumiomom volumio[1188]: info: ------------------------------------------- Dec 07 19:02:25 volumiomom volumio[1188]: info: ----- MyVolumio plugins startup ---- Dec 07 19:02:25 volumiomom volumio[1188]: info: ------------------------------------------- Dec 07 19:02:25 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 07 19:02:26 volumiomom volumio[1188]: info: MPD Permissions set Dec 07 19:02:26 volumiomom volumio[1188]: info: MPD Permissions set Dec 07 19:02:26 volumiomom volumio[1188]: info: Discovery: Disconnected from remote: 192.168.1.167 Dec 07 19:02:26 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 Dec 07 19:02:27 volumiomom volumio[1188]: info: Volumio called home Dec 07 19:02:27 volumiomom volumio[1188]: info: Spotify config file written Dec 07 19:02:27 volumiomom sudo[1480]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 07 19:02:27 volumiomom sudo[1480]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 19:02:28 volumiomom systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 07 19:02:28 volumiomom systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 07 19:02:28 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:02:28 volumiomom go-librespot[1482]: go-librespot daemon starting... Dec 07 19:02:28 volumiomom sudo[1480]: pam_unix(sudo:session): session closed for user root Dec 07 19:02:28 volumiomom go-librespot[1483]: time="2025-12-07T19:02:28-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:02:28 volumiomom go-librespot[1483]: time="2025-12-07T19:02:28-05:00" level=debug msg="app state loaded" Dec 07 19:02:28 volumiomom go-librespot[1483]: time="2025-12-07T19:02:28-05:00" level=debug msg="stored credentials not found" Dec 07 19:02:28 volumiomom go-librespot[1483]: time="2025-12-07T19:02:28-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:02:29 volumiomom go-librespot[1483]: time="2025-12-07T19:02:29-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 19:02:29 volumiomom go-librespot[1483]: time="2025-12-07T19:02:29-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 19:02:29 volumiomom go-librespot[1483]: time="2025-12-07T19:02:29-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 19:02:29 volumiomom go-librespot[1483]: time="2025-12-07T19:02:29-05:00" level=info msg="zeroconf server listening on port 38987" Dec 07 19:02:29 volumiomom go-librespot[1483]: time="2025-12-07T19:02:29-05:00" level=debug msg="obtained new client token: AABlMadpApTugvcSD9zKcp3919vgt5uSuL63Uss00N4pM7UbCvgUUqBqLIeIjEnBEl4IjP1KEorByUcsPObuZqtqgATSQ7j4TWM0kUZGACgw8P+XRbJtXWDsZm9+ZtKZsffheKi+b3V2fcd/5zOCX8xJ4c+i2p+Rs7BuNJQqvfjsekdXDqKRu3NuVc67KYqbRmKjYPkBj1yu++j4yqHZ447Csqe8UVSrysBYIiYzdXOpucsS4CSQcmKV" Dec 07 19:02:30 volumiomom go-librespot[1483]: time="2025-12-07T19:02:30-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:02:30 volumiomom go-librespot[1483]: time="2025-12-07T19:02:30-05:00" level=debug msg="completed keyexchange" Dec 07 19:02:30 volumiomom go-librespot[1483]: time="2025-12-07T19:02:30-05:00" level=debug msg="completed challenge" Dec 07 19:02:30 volumiomom go-librespot[1483]: time="2025-12-07T19:02:30-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:02:30 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:02:30 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:02:32 volumiomom volumio[1188]: error: MPD error: The expression evaluated to a falsy value: Dec 07 19:02:32 volumiomom volumio[1188]: assert.ok(self.idling) Dec 07 19:02:32 volumiomom volumio[1188]: error: The expression evaluated to a falsy value: Dec 07 19:02:32 volumiomom volumio[1188]: assert.ok(self.idling) Dec 07 19:02:32 volumiomom volumio[1188]: info: MPD running with PID1430 Dec 07 19:02:32 volumiomom volumio[1188]: ,establishing connection Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:33 volumiomom sudo[1523]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 07 19:02:33 volumiomom sudo[1523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 19:02:33 volumiomom sudo[1525]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 07 19:02:33 volumiomom sudo[1525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:02:33 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 07 19:02:33 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:33 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:02:33 volumiomom go-librespot[1533]: go-librespot daemon starting... Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:33 volumiomom go-librespot[1534]: time="2025-12-07T19:02:33-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:02:33 volumiomom go-librespot[1534]: time="2025-12-07T19:02:33-05:00" level=debug msg="app state loaded" Dec 07 19:02:33 volumiomom go-librespot[1534]: time="2025-12-07T19:02:33-05:00" level=debug msg="stored credentials not found" Dec 07 19:02:33 volumiomom go-librespot[1534]: time="2025-12-07T19:02:33-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:02:33 volumiomom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 07 19:02:33 volumiomom sudo[1523]: pam_unix(sudo:session): session closed for user root Dec 07 19:02:33 volumiomom mpd_monitor.sh[1542]: MPD Monitor Service: Starting MPD Monitor Service Dec 07 19:02:33 volumiomom sudo[1525]: pam_unix(sudo:session): session closed for user root Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:02:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:02:33 volumiomom volumio[1188]: info: No need to fix Spotify hosts Dec 07 19:02:34 volumiomom go-librespot[1534]: time="2025-12-07T19:02:34-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 19:02:34 volumiomom go-librespot[1534]: time="2025-12-07T19:02:34-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 19:02:34 volumiomom go-librespot[1534]: time="2025-12-07T19:02:34-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 19:02:34 volumiomom go-librespot[1534]: time="2025-12-07T19:02:34-05:00" level=info msg="zeroconf server listening on port 46235" Dec 07 19:02:34 volumiomom go-librespot[1534]: time="2025-12-07T19:02:34-05:00" level=debug msg="obtained new client token: AADfgZDLDHENVol/6HPpcqJGMNY+EU572lO+21+1gO4lRa9VI+pidORvBdnwuCEfoYy1RCh0L2w/TjVKh+D+IMC+nFHt1bQeRA0Q2s6qHc+9kTuxGYhynCBxiVUOLm/DQ46cth7eYN39pLbvPnz/2N7UZGdj7HVf9GLwZKOR0u1jDHHMYg6Rp/sFvmbV/f9K17f1IBf34Hr791yBDr8mudKYdjuMHt7zHAfWAdCDe7sFHIJ6McuzGizobI4=" Dec 07 19:02:34 volumiomom go-librespot[1534]: time="2025-12-07T19:02:34-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:02:34 volumiomom go-librespot[1534]: time="2025-12-07T19:02:34-05:00" level=debug msg="completed keyexchange" Dec 07 19:02:34 volumiomom go-librespot[1534]: time="2025-12-07T19:02:34-05:00" level=debug msg="completed challenge" Dec 07 19:02:34 volumiomom volumio[1188]: error: updateQueue error: null Dec 07 19:02:34 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 16 Dec 07 19:02:34 volumiomom volumio-remote-updater[692]: [2025-12-07 19:02:34] [connect] Successful connection Dec 07 19:02:35 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 17 Dec 07 19:02:35 volumiomom volumio[1188]: info: Discovery: Connected to remote: 192.168.1.167 Dec 07 19:02:35 volumiomom volumio[1188]: info: Successfully started MPD Monitor Dec 07 19:02:35 volumiomom volumio[1188]: info: Successfully started MPD Monitor Dec 07 19:02:35 volumiomom volumio[1188]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 07 19:02:35 volumiomom volumio[1188]: SPOTIFY: BQB9SvimXXxoZocHaN8ZGR6LUD_evQ4xGmQAZ6o3b4j21D6STwv5q_6OsqZQRs9PrqjQ9lIgEAhxIlR-odVkLpzFzsuOKirEglCrsBC-iW_LQqiS8qVtwuOVj0_3eNJYguG9hHi_yuA3PH3gKFgGEbCkz48d3axCjvQ5Lcg0qp_s27h_8JvPRIKJSGPbzI5uCBPDTMd9knI0Bqz6jgYW50T5cJvD5hlsEKVt7IpKGnj8egMitIYFuYoMO-kGvCOFiNHbNadi8UliV7XXALuKrZEeqYXlZTCyNk4 Dec 07 19:02:35 volumiomom volumio[1188]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 07 19:02:35 volumiomom volumio[1188]: info: New Spotify access token = BQB9SvimXXxoZocHaN8ZGR6LUD_evQ4xGmQAZ6o3b4j21D6STwv5q_6OsqZQRs9PrqjQ9lIgEAhxIlR-odVkLpzFzsuOKirEglCrsBC-iW_LQqiS8qVtwuOVj0_3eNJYguG9hHi_yuA3PH3gKFgGEbCkz48d3axCjvQ5Lcg0qp_s27h_8JvPRIKJSGPbzI5uCBPDTMd9knI0Bqz6jgYW50T5cJvD5hlsEKVt7IpKGnj8egMitIYFuYoMO-kGvCOFiNHbNadi8UliV7XXALuKrZEeqYXlZTCyNk4 Dec 07 19:02:35 volumiomom volumio[1188]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 07 19:02:35 volumiomom volumio[1188]: error: updateQueue error: null Dec 07 19:02:35 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 18 Dec 07 19:02:35 volumiomom volumio[1188]: info: Starting Shairport Sync Dec 07 19:02:35 volumiomom volumio[1188]: info: Starting Shairport Sync Dec 07 19:02:36 volumiomom volumio[1188]: info: Starting Shairport Sync Dec 07 19:02:36 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 19 Dec 07 19:02:36 volumiomom sudo[1552]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 19:02:36 volumiomom sudo[1552]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 19:02:36 volumiomom sudo[1554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 19:02:36 volumiomom sudo[1554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 19:02:36 volumiomom sudo[1556]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 19:02:36 volumiomom sudo[1556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 19:02:36 volumiomom go-librespot[1534]: time="2025-12-07T19:02:36-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:02:36 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:02:36 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:02:36 volumiomom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 07 19:02:36 volumiomom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 07 19:02:36 volumiomom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 19:02:36 volumiomom systemd[1]: shairport-sync.service: Consumed 2.885s CPU time. Dec 07 19:02:36 volumiomom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 19:02:36 volumiomom sudo[1552]: pam_unix(sudo:session): session closed for user root Dec 07 19:02:36 volumiomom sudo[1554]: pam_unix(sudo:session): session closed for user root Dec 07 19:02:36 volumiomom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 07 19:02:36 volumiomom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 07 19:02:36 volumiomom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 19:02:36 volumiomom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 19:02:36 volumiomom sudo[1556]: pam_unix(sudo:session): session closed for user root Dec 07 19:02:37 volumiomom volumio[1188]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 07 19:02:37 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 20 Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 07 19:02:37 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 07 19:02:37 volumiomom volumio[1188]: info: Adding plugin bluetooth to MyMusic Plugins Dec 07 19:02:37 volumiomom volumio[1188]: info: Adding plugin multiroom to MyMusic Plugins Dec 07 19:02:38 volumiomom volumio[1188]: info: Adding plugin metavolumio to MyMusic Plugins Dec 07 19:02:38 volumiomom volumio[1188]: info: Adding plugin cd_controller to MyMusic Plugins Dec 07 19:02:38 volumiomom volumio[1188]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 07 19:02:38 volumiomom volumio[1188]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 07 19:02:38 volumiomom volumio[1188]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 07 19:02:38 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 07 19:02:39 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 07 19:02:39 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:02:39 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:02:39 volumiomom go-librespot[1586]: go-librespot daemon starting... Dec 07 19:02:39 volumiomom go-librespot[1590]: time="2025-12-07T19:02:39-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:02:39 volumiomom go-librespot[1590]: time="2025-12-07T19:02:39-05:00" level=debug msg="app state loaded" Dec 07 19:02:39 volumiomom go-librespot[1590]: time="2025-12-07T19:02:39-05:00" level=debug msg="stored credentials not found" Dec 07 19:02:39 volumiomom go-librespot[1590]: time="2025-12-07T19:02:39-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:02:40 volumiomom go-librespot[1590]: time="2025-12-07T19:02:40-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 07 19:02:40 volumiomom go-librespot[1590]: time="2025-12-07T19:02:40-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 07 19:02:40 volumiomom go-librespot[1590]: time="2025-12-07T19:02:40-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 07 19:02:40 volumiomom go-librespot[1590]: time="2025-12-07T19:02:40-05:00" level=info msg="zeroconf server listening on port 39785" Dec 07 19:02:40 volumiomom go-librespot[1590]: time="2025-12-07T19:02:40-05:00" level=debug msg="obtained new client token: AAC6NMjjRWG4WEvlWaV0XMm9kIZFY+/lC6QXa0vF5jpD4WNJF0TNLgFT2+vznTM4sEQFAVju7/pr313u1+tErB0yrImYN/es3ZX1xyN5RYfVyXyKRvD55b7lQqUPV1zb4csd84Fi9WP6G082cZlR7nCoCcmMULUNt+pKrkub2l52a2Oh2bwFA8PEcvOHRNYVoDOVetLHVLiePOnb0CiGUQW80eiI6JjWdvmRC+BXT4WICPO6H7jFOp/6Bk4=" Dec 07 19:02:40 volumiomom go-librespot[1590]: time="2025-12-07T19:02:40-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:02:40 volumiomom go-librespot[1590]: time="2025-12-07T19:02:40-05:00" level=debug msg="completed keyexchange" Dec 07 19:02:40 volumiomom go-librespot[1590]: time="2025-12-07T19:02:40-05:00" level=debug msg="completed challenge" Dec 07 19:02:40 volumiomom go-librespot[1590]: time="2025-12-07T19:02:40-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:02:40 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:02:40 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:02:43 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 07 19:02:43 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:02:43 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:02:43 volumiomom go-librespot[1598]: go-librespot daemon starting... Dec 07 19:02:44 volumiomom go-librespot[1599]: time="2025-12-07T19:02:44-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:02:44 volumiomom go-librespot[1599]: time="2025-12-07T19:02:44-05:00" level=debug msg="app state loaded" Dec 07 19:02:44 volumiomom go-librespot[1599]: time="2025-12-07T19:02:44-05:00" level=debug msg="stored credentials not found" Dec 07 19:02:44 volumiomom go-librespot[1599]: time="2025-12-07T19:02:44-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:02:44 volumiomom go-librespot[1599]: time="2025-12-07T19:02:44-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 19:02:44 volumiomom go-librespot[1599]: time="2025-12-07T19:02:44-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 19:02:44 volumiomom go-librespot[1599]: time="2025-12-07T19:02:44-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 19:02:44 volumiomom go-librespot[1599]: time="2025-12-07T19:02:44-05:00" level=info msg="zeroconf server listening on port 38707" Dec 07 19:02:44 volumiomom go-librespot[1599]: time="2025-12-07T19:02:44-05:00" level=debug msg="obtained new client token: AADnuUBi+fB7r+VOvIjTWHGd/C/6+JgQvqg/tan5XoDAa3izUzL10m1UI9v4oKTbyy3B7vWqKhjYAq3/x9j7sqp93T3HUCvuK6FK/vqSzpVKYTmAo1ksqbyDaL9Ht5jwbOVdr83rXMoet7ABg2aO64zFkZlJNyjNWrTfoX5RGZMXgJ8hozhzI2ES9gyJKUvTODokCQBGfhHqBBpM6NxPBbTxGkS+CBzSjsuRtCaT3pWAJ6XJBFWhMoZI7Rk=" Dec 07 19:02:44 volumiomom go-librespot[1599]: time="2025-12-07T19:02:44-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:02:44 volumiomom go-librespot[1599]: time="2025-12-07T19:02:44-05:00" level=debug msg="completed keyexchange" Dec 07 19:02:44 volumiomom go-librespot[1599]: time="2025-12-07T19:02:44-05:00" level=debug msg="completed challenge" Dec 07 19:02:44 volumiomom go-librespot[1599]: time="2025-12-07T19:02:44-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:02:44 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:02:44 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:02:48 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 07 19:02:48 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:02:48 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:02:48 volumiomom go-librespot[1607]: go-librespot daemon starting... Dec 07 19:02:48 volumiomom go-librespot[1608]: time="2025-12-07T19:02:48-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:02:48 volumiomom go-librespot[1608]: time="2025-12-07T19:02:48-05:00" level=debug msg="app state loaded" Dec 07 19:02:48 volumiomom go-librespot[1608]: time="2025-12-07T19:02:48-05:00" level=debug msg="stored credentials not found" Dec 07 19:02:48 volumiomom go-librespot[1608]: time="2025-12-07T19:02:48-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:02:48 volumiomom go-librespot[1608]: time="2025-12-07T19:02:48-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 19:02:48 volumiomom go-librespot[1608]: time="2025-12-07T19:02:48-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 19:02:48 volumiomom go-librespot[1608]: time="2025-12-07T19:02:48-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 19:02:48 volumiomom go-librespot[1608]: time="2025-12-07T19:02:48-05:00" level=info msg="zeroconf server listening on port 44567" Dec 07 19:02:49 volumiomom go-librespot[1608]: time="2025-12-07T19:02:49-05:00" level=debug msg="obtained new client token: AAA2zOFW2uNF+B9PBP1KWY9XY5RV0y+xKC1L7QVB8Mx1KN+hA/xJ/4oHbW/ZPTzvVkw8qv+wRuGLUz3Mc8icG/t7usb6j6HL2YJEFrk8fe1bGMtER//c9jjmwYbcRdFZPxYraqhU21eRNHs1LWefUJ8vaINFcJ8mZDAGh6rtRIUqVrIQPMFE6kBKrj0O3dMSabRqHyr7O87J2b5O2h00Za8YEF2usnM+WqP1Q/Cu6GEhHKjKcZxypDtG" Dec 07 19:02:49 volumiomom go-librespot[1608]: time="2025-12-07T19:02:49-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:02:49 volumiomom go-librespot[1608]: time="2025-12-07T19:02:49-05:00" level=debug msg="completed keyexchange" Dec 07 19:02:49 volumiomom go-librespot[1608]: time="2025-12-07T19:02:49-05:00" level=debug msg="completed challenge" Dec 07 19:02:49 volumiomom go-librespot[1608]: time="2025-12-07T19:02:49-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:02:49 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:02:49 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:02:49 volumiomom volumio-remote-updater[692]: [2025-12-07 19:02:49] [connect] Successful connection Dec 07 19:02:51 volumiomom volumio[1188]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 07 19:02:51 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 07 19:02:51 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:02:51 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:02:51 volumiomom volumio[1188]: info: Starting MyVolumio Remote Streaming Endpoints Dec 07 19:02:51 volumiomom volumio[1188]: info: MyVolumio login type: Token Dec 07 19:02:51 volumiomom volumio[1188]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 07 19:02:51 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 07 19:02:52 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 07 19:02:52 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:02:52 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:02:52 volumiomom go-librespot[1630]: go-librespot daemon starting... Dec 07 19:02:52 volumiomom go-librespot[1631]: time="2025-12-07T19:02:52-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:02:52 volumiomom go-librespot[1631]: time="2025-12-07T19:02:52-05:00" level=debug msg="app state loaded" Dec 07 19:02:52 volumiomom go-librespot[1631]: time="2025-12-07T19:02:52-05:00" level=debug msg="stored credentials not found" Dec 07 19:02:52 volumiomom go-librespot[1631]: time="2025-12-07T19:02:52-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:02:52 volumiomom go-librespot[1631]: time="2025-12-07T19:02:52-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 19:02:52 volumiomom go-librespot[1631]: time="2025-12-07T19:02:52-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 19:02:52 volumiomom go-librespot[1631]: time="2025-12-07T19:02:52-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 19:02:52 volumiomom go-librespot[1631]: time="2025-12-07T19:02:52-05:00" level=info msg="zeroconf server listening on port 45145" Dec 07 19:02:53 volumiomom go-librespot[1631]: time="2025-12-07T19:02:53-05:00" level=debug msg="obtained new client token: AABFZb/TIE3f5vxK1zb0ntaN/4ulC8UNugzcP1VxR7D5u3CZBfJYHS/eQa1l4KFIQ8WHbA7xujIuHp+U/ue0jLu6vJvvzpTrtbnzcOP/f3FV74GErzOJuM0et2QdcUbJ3F1/I1NmKq6iUbpSQVHHyueuX4RcfKObjqj9EWjNamPhGGOHccTgN6L31tinlCauaNVB9DxQpIA83QDmlY2yDmbEaF6115R6Wk2AzENrFOP8NW1FCxm1R/Bs" Dec 07 19:02:53 volumiomom go-librespot[1631]: time="2025-12-07T19:02:53-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:02:53 volumiomom go-librespot[1631]: time="2025-12-07T19:02:53-05:00" level=debug msg="completed keyexchange" Dec 07 19:02:53 volumiomom go-librespot[1631]: time="2025-12-07T19:02:53-05:00" level=debug msg="completed challenge" Dec 07 19:02:53 volumiomom go-librespot[1631]: time="2025-12-07T19:02:53-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:02:53 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:02:53 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:02:56 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 07 19:02:56 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:02:56 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:02:56 volumiomom go-librespot[1642]: go-librespot daemon starting... Dec 07 19:02:56 volumiomom go-librespot[1643]: time="2025-12-07T19:02:56-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:02:56 volumiomom go-librespot[1643]: time="2025-12-07T19:02:56-05:00" level=debug msg="app state loaded" Dec 07 19:02:56 volumiomom go-librespot[1643]: time="2025-12-07T19:02:56-05:00" level=debug msg="stored credentials not found" Dec 07 19:02:56 volumiomom go-librespot[1643]: time="2025-12-07T19:02:56-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:02:57 volumiomom go-librespot[1643]: time="2025-12-07T19:02:57-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 07 19:02:57 volumiomom go-librespot[1643]: time="2025-12-07T19:02:57-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 07 19:02:57 volumiomom go-librespot[1643]: time="2025-12-07T19:02:57-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 07 19:02:57 volumiomom go-librespot[1643]: time="2025-12-07T19:02:57-05:00" level=info msg="zeroconf server listening on port 33843" Dec 07 19:02:57 volumiomom go-librespot[1643]: time="2025-12-07T19:02:57-05:00" level=debug msg="obtained new client token: AADPqSV31UxXz28lX15O4tt0ZUABzLJaeUWQKkhjBh96sfCERZWvIb9Z8xLf6/Z3GxZdHsFj5Kvg3o9p1wvCXj9axIsw07kiBi+pLCWxGxZntiGmQlYeSivcUYPpjXx91MdHYm/PAjsi4Y44LA2tcbPSfRTYk+IM5QvyAJs99iq5g+D9yEOfglsQGb3cATzuUG6DeF0uwA7mTwKsYs+zv1LUyKY5YjhvWgTOMUptNFGA9ByB0qIYswU2vEE=" Dec 07 19:02:57 volumiomom go-librespot[1643]: time="2025-12-07T19:02:57-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:02:57 volumiomom go-librespot[1643]: time="2025-12-07T19:02:57-05:00" level=debug msg="completed keyexchange" Dec 07 19:02:57 volumiomom go-librespot[1643]: time="2025-12-07T19:02:57-05:00" level=debug msg="completed challenge" Dec 07 19:02:57 volumiomom go-librespot[1643]: time="2025-12-07T19:02:57-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:02:57 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:02:57 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:03:00 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Dec 07 19:03:00 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:00 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:00 volumiomom go-librespot[1665]: go-librespot daemon starting... Dec 07 19:03:00 volumiomom go-librespot[1666]: time="2025-12-07T19:03:00-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:03:00 volumiomom go-librespot[1666]: time="2025-12-07T19:03:00-05:00" level=debug msg="app state loaded" Dec 07 19:03:00 volumiomom go-librespot[1666]: time="2025-12-07T19:03:00-05:00" level=debug msg="stored credentials not found" Dec 07 19:03:00 volumiomom go-librespot[1666]: time="2025-12-07T19:03:00-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:03:01 volumiomom go-librespot[1666]: time="2025-12-07T19:03:01-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 07 19:03:01 volumiomom go-librespot[1666]: time="2025-12-07T19:03:01-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 07 19:03:01 volumiomom go-librespot[1666]: time="2025-12-07T19:03:01-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 07 19:03:01 volumiomom go-librespot[1666]: time="2025-12-07T19:03:01-05:00" level=info msg="zeroconf server listening on port 35327" Dec 07 19:03:01 volumiomom go-librespot[1666]: time="2025-12-07T19:03:01-05:00" level=debug msg="obtained new client token: AAAW2a3tojzwppEn0diHBRJSiUsjzxK1KzQJuFJbDIBz6tpn3ppBeGYIZqGvTdfyYKHtyQcr/9SForap1lmPRogTbRHJ6k8W1swR9hGlufXz72jfvsA9nIZBeWOvtymv94gwTI0vU5eEFbAQm23z1UF4eDIEBl8efB4TMoarh7IBVllWFKVWGoH5+ZrauZ494eFzsITGR3VryJTMg+8z7BPI5myOotcfJgRWfI4N8OjD1k9szR1KJxKt9jM=" Dec 07 19:03:01 volumiomom go-librespot[1666]: time="2025-12-07T19:03:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:03:01 volumiomom go-librespot[1666]: time="2025-12-07T19:03:01-05:00" level=debug msg="completed keyexchange" Dec 07 19:03:01 volumiomom go-librespot[1666]: time="2025-12-07T19:03:01-05:00" level=debug msg="completed challenge" Dec 07 19:03:01 volumiomom go-librespot[1666]: time="2025-12-07T19:03:01-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:03:01 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:03:01 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:03:04 volumiomom volumio-remote-updater[692]: [2025-12-07 19:03:04] [connect] Successful connection Dec 07 19:03:05 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 07 19:03:05 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:05 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:05 volumiomom go-librespot[1673]: go-librespot daemon starting... Dec 07 19:03:05 volumiomom go-librespot[1674]: time="2025-12-07T19:03:05-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:03:05 volumiomom go-librespot[1674]: time="2025-12-07T19:03:05-05:00" level=debug msg="app state loaded" Dec 07 19:03:05 volumiomom go-librespot[1674]: time="2025-12-07T19:03:05-05:00" level=debug msg="stored credentials not found" Dec 07 19:03:05 volumiomom go-librespot[1674]: time="2025-12-07T19:03:05-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:03:05 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 07 19:03:05 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 07 19:03:05 volumiomom volumio[1188]: info: Streaming services startup Dec 07 19:03:05 volumiomom volumio[1188]: info: Starting Streaming Daemon Dec 07 19:03:05 volumiomom go-librespot[1674]: time="2025-12-07T19:03:05-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 19:03:05 volumiomom go-librespot[1674]: time="2025-12-07T19:03:05-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 19:03:05 volumiomom go-librespot[1674]: time="2025-12-07T19:03:05-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 19:03:05 volumiomom go-librespot[1674]: time="2025-12-07T19:03:05-05:00" level=info msg="zeroconf server listening on port 43669" Dec 07 19:03:05 volumiomom sudo[1682]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 07 19:03:05 volumiomom sudo[1682]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 19:03:05 volumiomom volumio[1188]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 07 19:03:05 volumiomom go-librespot[1674]: time="2025-12-07T19:03:05-05:00" level=debug msg="obtained new client token: AABPaXgSAoqrJE1S010gxlCVo7FeBHWKbLTttlj6vf6+Kp7xFl89pxB4W+abCV9oxejKHdThKTseGCUpiJpVpV/gZ52J6SIZJMSmM1dtOcnwG1qlzz1ywtmOAH/dHodY2lk1Q4UaDmrkdGb7b/JgrubiZqGXZxANQs6UU/YTasv5onRGXZlYJsdffPa0ZelwLDR6f/8ql5Z1krrmsCBAJPKPYChU8bPVOAAeqE1T1r0MaNzeKveGyQwcP7U=" Dec 07 19:03:05 volumiomom go-librespot[1674]: time="2025-12-07T19:03:05-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:03:06 volumiomom go-librespot[1674]: time="2025-12-07T19:03:06-05:00" level=debug msg="completed keyexchange" Dec 07 19:03:06 volumiomom go-librespot[1674]: time="2025-12-07T19:03:06-05:00" level=debug msg="completed challenge" Dec 07 19:03:06 volumiomom go-librespot[1674]: time="2025-12-07T19:03:06-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:03:06 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:03:06 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:03:06 volumiomom sudo[1682]: pam_unix(sudo:session): session closed for user root Dec 07 19:03:06 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 21 Dec 07 19:03:07 volumiomom volumio[1188]: info: Shairport-Sync Started Dec 07 19:03:07 volumiomom volumio[1188]: Error adding Membership: Error: addMembership EINVAL Dec 07 19:03:07 volumiomom volumio[1188]: info: Shairport-Sync Started Dec 07 19:03:07 volumiomom volumio[1188]: info: Shairport-Sync Started Dec 07 19:03:07 volumiomom volumio[1188]: info: go-librespot daemon successfully initialized Dec 07 19:03:07 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 19:03:07 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:03:07 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 07 19:03:07 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 07 19:03:07 volumiomom volumio[1188]: error: Failed to retrieve user informations: Error: socket hang up Dec 07 19:03:07 volumiomom volumio[1188]: error: Spotify credentials failed to read user data: Dec 07 19:03:07 volumiomom volumio[1188]: info: An error occurred while initializing Spotify Browsing facility: Dec 07 19:03:07 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 22 Dec 07 19:03:08 volumiomom volumio[1188]: error: Cannot start Volumio Streaming Daemon Dec 07 19:03:08 volumiomom volumio[1188]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 07 19:03:08 volumiomom volumio[1188]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 07 19:03:08 volumiomom volumio[1188]: info: Discovery: Disconnected from remote: 192.168.1.167 Dec 07 19:03:08 volumiomom volumio[1188]: info: Discovery: Disconnected from remote: 192.168.1.167 Dec 07 19:03:09 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 23 Dec 07 19:03:09 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Dec 07 19:03:09 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:09 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 24 Dec 07 19:03:09 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:09 volumiomom go-librespot[1692]: go-librespot daemon starting... Dec 07 19:03:09 volumiomom go-librespot[1693]: time="2025-12-07T19:03:09-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:03:09 volumiomom go-librespot[1693]: time="2025-12-07T19:03:09-05:00" level=debug msg="app state loaded" Dec 07 19:03:09 volumiomom go-librespot[1693]: time="2025-12-07T19:03:09-05:00" level=debug msg="stored credentials not found" Dec 07 19:03:09 volumiomom go-librespot[1693]: time="2025-12-07T19:03:09-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:03:10 volumiomom go-librespot[1693]: time="2025-12-07T19:03:10-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 19:03:10 volumiomom go-librespot[1693]: time="2025-12-07T19:03:10-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 19:03:10 volumiomom go-librespot[1693]: time="2025-12-07T19:03:10-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 19:03:10 volumiomom go-librespot[1693]: time="2025-12-07T19:03:10-05:00" level=info msg="zeroconf server listening on port 41909" Dec 07 19:03:10 volumiomom go-librespot[1693]: time="2025-12-07T19:03:10-05:00" level=debug msg="obtained new client token: AADx3BUh0Zb25SA/AQf1/fSlhN1ZTz2VilApvdsVVd548vE0D6dW3wXpJEUIj/fRkapGiUOCo5GwUxBPiRcSZDZYc7xMAVIuJswP8L/DawCXm+NdQAUdiGyrgTRUsqHRJy2g+nBFol0IPUGCQo5qPoMQreGY0qTixd6rkeSJ3iwJGFkhRFZVRpuWPPPbPJoDFDeK23kZiqWVjqWkyLy+VbE3HsdSeijmndYOAtJQsArIJRUrBgNeUpT2AJo=" Dec 07 19:03:10 volumiomom go-librespot[1693]: time="2025-12-07T19:03:10-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:03:10 volumiomom volumio[1188]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 25 Dec 07 19:03:10 volumiomom go-librespot[1693]: time="2025-12-07T19:03:10-05:00" level=debug msg="completed keyexchange" Dec 07 19:03:10 volumiomom go-librespot[1693]: time="2025-12-07T19:03:10-05:00" level=debug msg="completed challenge" Dec 07 19:03:10 volumiomom go-librespot[1693]: time="2025-12-07T19:03:10-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:03:10 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:03:10 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:03:10 volumiomom volumio[1188]: info: Initializing connection to go-librespot Websocket Dec 07 19:03:10 volumiomom volumio[1188]: error: MyVolumio Custom Token format not valid, refreshing it Dec 07 19:03:11 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 26 Dec 07 19:03:11 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 27 Dec 07 19:03:11 volumiomom volumio[1188]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 19:03:12 volumiomom volumio[1188]: info: Discovery: Connected to remote: 192.168.1.167 Dec 07 19:03:12 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:03:12 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:03:12 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 07 19:03:12 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 07 19:03:12 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 07 19:03:12 volumiomom volumio[1188]: info: CoreCommandRouter::volumioGetBrowseSources Dec 07 19:03:12 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 19:03:12 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 28 Dec 07 19:03:13 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 07 19:03:13 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Dec 07 19:03:13 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:13 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:13 volumiomom go-librespot[1714]: go-librespot daemon starting... Dec 07 19:03:13 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 29 Dec 07 19:03:13 volumiomom go-librespot[1715]: time="2025-12-07T19:03:13-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:03:13 volumiomom go-librespot[1715]: time="2025-12-07T19:03:13-05:00" level=debug msg="app state loaded" Dec 07 19:03:13 volumiomom go-librespot[1715]: time="2025-12-07T19:03:13-05:00" level=debug msg="stored credentials not found" Dec 07 19:03:13 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 30 Dec 07 19:03:13 volumiomom go-librespot[1715]: time="2025-12-07T19:03:13-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:03:14 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 31 Dec 07 19:03:14 volumiomom go-librespot[1715]: time="2025-12-07T19:03:14-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 19:03:14 volumiomom go-librespot[1715]: time="2025-12-07T19:03:14-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 19:03:14 volumiomom go-librespot[1715]: time="2025-12-07T19:03:14-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 19:03:14 volumiomom go-librespot[1715]: time="2025-12-07T19:03:14-05:00" level=info msg="zeroconf server listening on port 46715" Dec 07 19:03:14 volumiomom go-librespot[1715]: time="2025-12-07T19:03:14-05:00" level=debug msg="obtained new client token: AADddclqYX0jCdq1wgLXnGGj1tiDEY4itzZz04kQGglOZWv+loBs7gbzI0kPE/KxyZn8Wx9a8NnSylSO+rY5YpXmsyqnHAiB9Q8JERpnRpNBYkHakPRzq4pTptRNsGOEeyzts0d/HDlCXm8ECerbuO5Zh9VXqFJe/1HY31qiKwXnQuH/GCl+X+dgsaBBkGKRcDSoGNebJ3iGzMrCLVxinFTxLKYX0RAI8oOyHfxDrsz9wEC4eSSWMmSZ2JM=" Dec 07 19:03:14 volumiomom go-librespot[1715]: time="2025-12-07T19:03:14-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:03:14 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 32 Dec 07 19:03:14 volumiomom go-librespot[1715]: time="2025-12-07T19:03:14-05:00" level=debug msg="completed keyexchange" Dec 07 19:03:14 volumiomom go-librespot[1715]: time="2025-12-07T19:03:14-05:00" level=debug msg="completed challenge" Dec 07 19:03:14 volumiomom go-librespot[1715]: time="2025-12-07T19:03:14-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:03:14 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:03:14 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:03:14 volumiomom volumio[1188]: info: Initializing connection to go-librespot Websocket Dec 07 19:03:15 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 33 Dec 07 19:03:15 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 34 Dec 07 19:03:15 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 35 Dec 07 19:03:15 volumiomom volumio[1188]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 19:03:15 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 36 Dec 07 19:03:15 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 37 Dec 07 19:03:16 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 38 Dec 07 19:03:16 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 39 Dec 07 19:03:16 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 40 Dec 07 19:03:16 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 41 Dec 07 19:03:16 volumiomom volumio[1188]: info: MyVolumio login type: Token Dec 07 19:03:16 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 42 Dec 07 19:03:17 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 43 Dec 07 19:03:17 volumiomom volumio[1188]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 44 Dec 07 19:03:17 volumiomom volumio[1188]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 45 Dec 07 19:03:18 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Dec 07 19:03:18 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:18 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:18 volumiomom go-librespot[1732]: go-librespot daemon starting... Dec 07 19:03:18 volumiomom go-librespot[1733]: time="2025-12-07T19:03:18-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:03:18 volumiomom go-librespot[1733]: time="2025-12-07T19:03:18-05:00" level=debug msg="app state loaded" Dec 07 19:03:18 volumiomom go-librespot[1733]: time="2025-12-07T19:03:18-05:00" level=debug msg="stored credentials not found" Dec 07 19:03:18 volumiomom go-librespot[1733]: time="2025-12-07T19:03:18-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:03:18 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 46 Dec 07 19:03:18 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 47 Dec 07 19:03:18 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 48 Dec 07 19:03:18 volumiomom go-librespot[1733]: time="2025-12-07T19:03:18-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 19:03:18 volumiomom go-librespot[1733]: time="2025-12-07T19:03:18-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 19:03:18 volumiomom go-librespot[1733]: time="2025-12-07T19:03:18-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 19:03:18 volumiomom volumio[1188]: info: Initializing connection to go-librespot Websocket Dec 07 19:03:18 volumiomom go-librespot[1733]: time="2025-12-07T19:03:18-05:00" level=info msg="zeroconf server listening on port 45987" Dec 07 19:03:19 volumiomom go-librespot[1733]: time="2025-12-07T19:03:19-05:00" level=debug msg="obtained new client token: AACvH8cC+abw0jd7evmDjvYYsFuf/Nz3Ov8vGGLvCwXo598hf82RKb6JN/hM0BZJZjvzc2fXIV7rinCH2DLBGJelLYidfpD71FVAhcy4BoA1Sp6LC55MOk0HKVuibpijzD7uL5AaMeP9wp7dVk0zmd1Es7nGmQeIbLUfWdncHm5EPPXHaqRKKj0pHr4fLkyrEdG47AE3cUlqHZThPfegQedxi8EhgE8zMFW8GpkEWJK1o8D/jnAy2iKM" Dec 07 19:03:19 volumiomom go-librespot[1733]: time="2025-12-07T19:03:19-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:03:19 volumiomom go-librespot[1733]: time="2025-12-07T19:03:19-05:00" level=debug msg="completed keyexchange" Dec 07 19:03:19 volumiomom go-librespot[1733]: time="2025-12-07T19:03:19-05:00" level=debug msg="completed challenge" Dec 07 19:03:19 volumiomom go-librespot[1733]: time="2025-12-07T19:03:19-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:03:19 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:03:19 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:03:19 volumiomom volumio[1188]: info: Error connecting to go-librespot Websocket: Error: socket hang up Dec 07 19:03:19 volumiomom volumio-remote-updater[692]: [2025-12-07 19:03:19] [connect] Successful connection Dec 07 19:03:20 volumiomom volumio[1188]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 07 19:03:21 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Dec 07 19:03:21 volumiomom volumio[1188]: info: CoreCommandRouter::volumioGetState Dec 07 19:03:21 volumiomom volumio[1188]: info: CorePlayQueue::getTrack 0 Dec 07 19:03:21 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168:3000 from 192.168.1.167 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 49 Dec 07 19:03:21 volumiomom volumio-remote-updater[692]: [2025-12-07 19:03:21] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765152199 101 Dec 07 19:03:21 volumiomom volumio[1188]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 50 Dec 07 19:03:21 volumiomom volumio[1188]: info: MyVolumio token set successfully Dec 07 19:03:21 volumiomom volumio[1188]: info: MYVOLUMIO: Adding device Dec 07 19:03:21 volumiomom volumio[1188]: info: MYVOLUMIO: Evaluating Server Dec 07 19:03:22 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Dec 07 19:03:22 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:22 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:22 volumiomom go-librespot[1758]: go-librespot daemon starting... Dec 07 19:03:22 volumiomom go-librespot[1760]: time="2025-12-07T19:03:22-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:03:22 volumiomom go-librespot[1760]: time="2025-12-07T19:03:22-05:00" level=debug msg="app state loaded" Dec 07 19:03:22 volumiomom go-librespot[1760]: time="2025-12-07T19:03:22-05:00" level=debug msg="stored credentials not found" Dec 07 19:03:22 volumiomom go-librespot[1760]: time="2025-12-07T19:03:22-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:03:23 volumiomom go-librespot[1760]: time="2025-12-07T19:03:23-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 19:03:23 volumiomom go-librespot[1760]: time="2025-12-07T19:03:23-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 19:03:23 volumiomom go-librespot[1760]: time="2025-12-07T19:03:23-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 19:03:23 volumiomom go-librespot[1760]: time="2025-12-07T19:03:23-05:00" level=info msg="zeroconf server listening on port 45139" Dec 07 19:03:23 volumiomom go-librespot[1760]: time="2025-12-07T19:03:23-05:00" level=debug msg="obtained new client token: AADZDLVgzPr9vA2g2i523tP15ctFsG0JZWuPraxEiqNDcykxA4h1cowBD4devaBWyS/mh1xIcRL0eQ9Uw5/mCk4Wg/2mLsOKA9o/mdG3nKwMky8aWvd3IKqxCkQNcBBh9YROqnWPZqMh4M2h7HrPmz0pPpN0Xme01yUaEJxFWQAx0KhVYNQho1FdugxnmQpk1T8oOXbtpRsWSRJ1IwT6b0dU5+JM47PxPzdsEnPjwUUhWbRxDcrfd1F0xRc=" Dec 07 19:03:23 volumiomom go-librespot[1760]: time="2025-12-07T19:03:23-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:03:23 volumiomom go-librespot[1760]: time="2025-12-07T19:03:23-05:00" level=debug msg="completed keyexchange" Dec 07 19:03:23 volumiomom go-librespot[1760]: time="2025-12-07T19:03:23-05:00" level=debug msg="completed challenge" Dec 07 19:03:23 volumiomom go-librespot[1760]: time="2025-12-07T19:03:23-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:03:23 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:03:23 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:03:24 volumiomom volumio[1188]: info: CoreCommandRouter::volumioGetState Dec 07 19:03:24 volumiomom volumio[1188]: info: CorePlayQueue::getTrack 0 Dec 07 19:03:24 volumiomom volumio[1188]: info: Initializing connection to go-librespot Websocket Dec 07 19:03:24 volumiomom volumio[1188]: info: MyVolumio status changed Dec 07 19:03:24 volumiomom volumio[1188]: info: Streaming services startup Dec 07 19:03:24 volumiomom volumio[1188]: info: Starting Streaming Daemon Dec 07 19:03:24 volumiomom volumio[1188]: info: Removing browser output: myVolumio user plan is not superstar Dec 07 19:03:24 volumiomom volumio[1188]: info: Removing audio output: Dec 07 19:03:24 volumiomom volumio[1188]: info: Stoppping Tunnel 1 Dec 07 19:03:25 volumiomom sudo[1786]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 07 19:03:25 volumiomom sudo[1788]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 07 19:03:25 volumiomom sudo[1786]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 19:03:25 volumiomom sudo[1788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 19:03:25 volumiomom systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 07 19:03:25 volumiomom systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 07 19:03:25 volumiomom systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 07 19:03:25 volumiomom systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 07 19:03:25 volumiomom systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 07 19:03:25 volumiomom systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 07 19:03:25 volumiomom sudo[1786]: pam_unix(sudo:session): session closed for user root Dec 07 19:03:25 volumiomom systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 07 19:03:25 volumiomom systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 07 19:03:25 volumiomom sudo[1788]: pam_unix(sudo:session): session closed for user root Dec 07 19:03:25 volumiomom volumio[1188]: error: MyVolumio Plugin failed to authenticate in a timely fashion Dec 07 19:03:25 volumiomom volumio[1188]: info: Completed starting MyVolumio Plugin Dec 07 19:03:25 volumiomom volumio[1188]: [Metrics] CommandRouter: 118s 292.61ms Dec 07 19:03:25 volumiomom volumio[1188]: info: CoreCommandRouter::volumiosetStartupVolume Dec 07 19:03:25 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 19:03:25 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:03:26 volumiomom volumio[1188]: info: CoreCommandRouter::Close All Modals sent Dec 07 19:03:26 volumiomom volumio[1188]: info: CoreCommandRouter::Close All Modals sent Dec 07 19:03:26 volumiomom volumio[1188]: info: Setting Geolocation for MyVolumio to us4 Dec 07 19:03:26 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:03:26 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:03:26 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:03:26 volumiomom volumio[1188]: info: CoreCommandRouter::volumioGetState Dec 07 19:03:26 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Dec 07 19:03:26 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:26 volumiomom volumio[1188]: info: CorePlayQueue::getTrack 0 Dec 07 19:03:26 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:26 volumiomom go-librespot[1793]: go-librespot daemon starting... Dec 07 19:03:26 volumiomom go-librespot[1794]: time="2025-12-07T19:03:26-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:03:26 volumiomom go-librespot[1794]: time="2025-12-07T19:03:26-05:00" level=debug msg="app state loaded" Dec 07 19:03:26 volumiomom go-librespot[1794]: time="2025-12-07T19:03:26-05:00" level=debug msg="stored credentials not found" Dec 07 19:03:26 volumiomom go-librespot[1794]: time="2025-12-07T19:03:26-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:03:26 volumiomom volumio[1188]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 19:03:27 volumiomom volumio[1188]: info: Remote SSH Stopped Dec 07 19:03:27 volumiomom volumio[1188]: error: Cannot start Volumio Streaming Daemon Dec 07 19:03:27 volumiomom volumio[1188]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 07 19:03:27 volumiomom volumio[1188]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 07 19:03:27 volumiomom go-librespot[1794]: time="2025-12-07T19:03:27-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 19:03:27 volumiomom go-librespot[1794]: time="2025-12-07T19:03:27-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 19:03:27 volumiomom go-librespot[1794]: time="2025-12-07T19:03:27-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 19:03:27 volumiomom go-librespot[1794]: time="2025-12-07T19:03:27-05:00" level=info msg="zeroconf server listening on port 43189" Dec 07 19:03:27 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 07 19:03:27 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 07 19:03:27 volumiomom go-librespot[1794]: time="2025-12-07T19:03:27-05:00" level=debug msg="obtained new client token: AADjEgS8M7I4QRB1Dh+lGQXMDDQJY1NyUb7PPmFmTTIt5irJpIILyGpRUwX0uDOPKAgzuVCQ5WFieFeCRq0FCu6wri4mE51Cgoj8hKGwgesVgcvLRNcmpHPmclwWln2VrBzbiw6Xu1sFOEBFH+5PcyARb5pUTa79y4OD2acDsGShI8k4Txnmy0H/i1GrpWDVzuqTCJ+ZwWyLBnUBetS6AnpKmtzZOOLiRy1+YDpa0LE3avA/jdHidfyN8uo=" Dec 07 19:03:27 volumiomom go-librespot[1794]: time="2025-12-07T19:03:27-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:03:27 volumiomom go-librespot[1794]: time="2025-12-07T19:03:27-05:00" level=debug msg="completed keyexchange" Dec 07 19:03:27 volumiomom go-librespot[1794]: time="2025-12-07T19:03:27-05:00" level=debug msg="completed challenge" Dec 07 19:03:27 volumiomom go-librespot[1794]: time="2025-12-07T19:03:27-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:03:27 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:03:27 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:03:27 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 07 19:03:28 volumiomom volumio[1188]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 07 19:03:28 volumiomom volumio[1188]: info: Updating MyVolumio device info Dec 07 19:03:28 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:03:28 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:03:28 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:03:29 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Dec 07 19:03:29 volumiomom volumio[1188]: info: CoreCommandRouter::volumioGetState Dec 07 19:03:29 volumiomom volumio[1188]: info: CorePlayQueue::getTrack 0 Dec 07 19:03:29 volumiomom volumio[1188]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 07 19:03:30 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 41 Dec 07 19:03:30 volumiomom volumio[1188]: info: Initializing connection to go-librespot Websocket Dec 07 19:03:30 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 41 Dec 07 19:03:30 volumiomom volumio[1188]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 19:03:30 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Dec 07 19:03:30 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:30 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:30 volumiomom go-librespot[1804]: go-librespot daemon starting... Dec 07 19:03:31 volumiomom go-librespot[1805]: time="2025-12-07T19:03:31-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:03:31 volumiomom go-librespot[1805]: time="2025-12-07T19:03:31-05:00" level=debug msg="app state loaded" Dec 07 19:03:31 volumiomom go-librespot[1805]: time="2025-12-07T19:03:31-05:00" level=debug msg="stored credentials not found" Dec 07 19:03:31 volumiomom go-librespot[1805]: time="2025-12-07T19:03:31-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:03:31 volumiomom go-librespot[1805]: time="2025-12-07T19:03:31-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 07 19:03:31 volumiomom go-librespot[1805]: time="2025-12-07T19:03:31-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 07 19:03:31 volumiomom go-librespot[1805]: time="2025-12-07T19:03:31-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 07 19:03:31 volumiomom go-librespot[1805]: time="2025-12-07T19:03:31-05:00" level=info msg="zeroconf server listening on port 37591" Dec 07 19:03:31 volumiomom go-librespot[1805]: time="2025-12-07T19:03:31-05:00" level=debug msg="obtained new client token: AAAQMYfdU7Hp7uJAGnQUvqorOkWUI34rrAz3EUpSs8IikjBdIhmloa4Akz13SQYBnQjYPMQCMFh2L197lwRNh7oH2I6U546w/ZAm9V1YsNpz9XLbqcSsbiRmBAoToKtto9P0qnyIRWp/SJ56aE1Q5q061wqlsDb0L9vKhXD3HTqCvGScQEbHvxr94CJNqD1DNCQ+NngQltjTrMBvZdP3LRn2K6v4PebYXfleHoA7dY5W/mOh/erQgslH" Dec 07 19:03:32 volumiomom go-librespot[1805]: time="2025-12-07T19:03:32-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:03:32 volumiomom go-librespot[1805]: time="2025-12-07T19:03:32-05:00" level=debug msg="completed keyexchange" Dec 07 19:03:32 volumiomom go-librespot[1805]: time="2025-12-07T19:03:32-05:00" level=debug msg="completed challenge" Dec 07 19:03:32 volumiomom go-librespot[1805]: time="2025-12-07T19:03:32-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:03:32 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:03:32 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:03:32 volumiomom volumio[1188]: info: MYVOLUMIO: Adding device Dec 07 19:03:32 volumiomom volumio[1188]: info: MYVOLUMIO: Evaluating Server Dec 07 19:03:33 volumiomom volumio[1188]: info: BOOT COMPLETED Dec 07 19:03:33 volumiomom volumio[1188]: info: Initializing connection to go-librespot Websocket Dec 07 19:03:33 volumiomom volumio[1188]: info: Setting Geolocation for MyVolumio to us1 Dec 07 19:03:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:03:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:03:33 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:03:34 volumiomom volumio[1188]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 19:03:34 volumiomom volumio[1188]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 07 19:03:34 volumiomom volumio[1188]: verbose: New Socket.io Connection to 192.168.1.168 from 192.168.1.193 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 42 Dec 07 19:03:34 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 07 19:03:34 volumiomom volumio[1188]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 07 19:03:34 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 07 19:03:35 volumiomom volumio[1188]: info: Received Get System Version Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 19:03:35 volumiomom volumio[1188]: info: Received Get System Info Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 19:03:35 volumiomom volumio[1188]: info: Discovery: Getting this device information Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::volumioGetState Dec 07 19:03:35 volumiomom volumio[1188]: info: CorePlayQueue::getTrack 0 Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 07 19:03:35 volumiomom volumio[1188]: info: Received Get System Info Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 19:03:35 volumiomom volumio[1188]: info: Discovery: Getting this device information Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::volumioGetState Dec 07 19:03:35 volumiomom volumio[1188]: info: CorePlayQueue::getTrack 0 Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 07 19:03:35 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Dec 07 19:03:35 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::volumioGetVisibleSources Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 19:03:35 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:35 volumiomom go-librespot[1848]: go-librespot daemon starting... Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::volumioGetState Dec 07 19:03:35 volumiomom volumio[1188]: info: CorePlayQueue::getTrack 0 Dec 07 19:03:35 volumiomom go-librespot[1849]: time="2025-12-07T19:03:35-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:03:35 volumiomom go-librespot[1849]: time="2025-12-07T19:03:35-05:00" level=debug msg="app state loaded" Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::volumioGetState Dec 07 19:03:35 volumiomom volumio[1188]: info: CorePlayQueue::getTrack 0 Dec 07 19:03:35 volumiomom go-librespot[1849]: time="2025-12-07T19:03:35-05:00" level=debug msg="stored credentials not found" Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 07 19:03:35 volumiomom go-librespot[1849]: time="2025-12-07T19:03:35-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:03:35 volumiomom volumio[1188]: info: Received Get System Info Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 19:03:35 volumiomom volumio[1188]: info: Discovery: Getting this device information Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::volumioGetState Dec 07 19:03:35 volumiomom volumio[1188]: info: CorePlayQueue::getTrack 0 Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 19:03:35 volumiomom volumio[1188]: info: CoreCommandRouter::volumioGetState Dec 07 19:03:35 volumiomom volumio[1188]: info: CorePlayQueue::getTrack 0 Dec 07 19:03:35 volumiomom volumio[1188]: info: Listing playlists Dec 07 19:03:36 volumiomom volumio[1188]: info: Updating MyVolumio device info Dec 07 19:03:36 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:03:36 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:03:36 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 19:03:36 volumiomom go-librespot[1849]: time="2025-12-07T19:03:36-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 19:03:36 volumiomom go-librespot[1849]: time="2025-12-07T19:03:36-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 19:03:36 volumiomom go-librespot[1849]: time="2025-12-07T19:03:36-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 19:03:36 volumiomom go-librespot[1849]: time="2025-12-07T19:03:36-05:00" level=info msg="zeroconf server listening on port 41589" Dec 07 19:03:36 volumiomom go-librespot[1849]: time="2025-12-07T19:03:36-05:00" level=debug msg="obtained new client token: AABHUcnwnqa6cxD3uZQmQfvfBqdhothqCpRpmwCEItV9RJxy7UU/0grEdMEBxOKPUnfoFgqAintbY5ez6moFizsH9wR37pKV0/KORylN4ffl4/Dh/e+EkBXdzkHRqCS3jRf1AKR1IxVT5TAXckAXK6LO+oMt2cTWf/zQt8qYHRSIBMdlI8c0kd8ZRfN4Br3erKK77Gl+I4plzB4oYfzBwifBe1fSfNGTeFw/8D/8Pq9Kvcd1vdquWC+Pt84=" Dec 07 19:03:36 volumiomom go-librespot[1849]: time="2025-12-07T19:03:36-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:03:36 volumiomom go-librespot[1849]: time="2025-12-07T19:03:36-05:00" level=debug msg="completed keyexchange" Dec 07 19:03:36 volumiomom go-librespot[1849]: time="2025-12-07T19:03:36-05:00" level=debug msg="completed challenge" Dec 07 19:03:36 volumiomom go-librespot[1849]: time="2025-12-07T19:03:36-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:03:36 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:03:36 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:03:36 volumiomom volumio[1188]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 07 19:03:37 volumiomom volumio[1188]: info: Initializing connection to go-librespot Websocket Dec 07 19:03:37 volumiomom volumio[1188]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 07 19:03:37 volumiomom volumio[1188]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 19:03:39 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Dec 07 19:03:39 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:39 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:39 volumiomom go-librespot[1857]: go-librespot daemon starting... Dec 07 19:03:40 volumiomom go-librespot[1858]: time="2025-12-07T19:03:40-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:03:40 volumiomom go-librespot[1858]: time="2025-12-07T19:03:40-05:00" level=debug msg="app state loaded" Dec 07 19:03:40 volumiomom go-librespot[1858]: time="2025-12-07T19:03:40-05:00" level=debug msg="stored credentials not found" Dec 07 19:03:40 volumiomom go-librespot[1858]: time="2025-12-07T19:03:40-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:03:40 volumiomom volumio[1188]: info: Initializing connection to go-librespot Websocket Dec 07 19:03:40 volumiomom go-librespot[1858]: time="2025-12-07T19:03:40-05:00" level=debug msg="new websocket client" Dec 07 19:03:40 volumiomom go-librespot[1858]: time="2025-12-07T19:03:40-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 19:03:40 volumiomom go-librespot[1858]: time="2025-12-07T19:03:40-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 19:03:40 volumiomom go-librespot[1858]: time="2025-12-07T19:03:40-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 19:03:40 volumiomom volumio[1188]: info: Connection to go-librespot Websocket established Dec 07 19:03:40 volumiomom go-librespot[1858]: time="2025-12-07T19:03:40-05:00" level=info msg="zeroconf server listening on port 39957" Dec 07 19:03:40 volumiomom go-librespot[1858]: time="2025-12-07T19:03:40-05:00" level=debug msg="obtained new client token: AAAv2PePdLgcheZ4HrrjJSbPoZAfvLf2zGV0dnVeyAVUkdJhJpVduHyye9j5cp84d34H9bV41/rPo1w9JHQV0quchEJrtmR6nO13oq7K048B7q1Fnh3PU6OJs2ffESHc5ajNBVsCNFCKEPiceya1vhrO36/DIaYZqaP9UU0nxNvK6O09fLrjA+HPHJe7pCx/R5vUFISTrwwf5hTx5JyHFPm7GFcuk/A4XE7eWLAhLOma8ONjrDkmtouNA+k=" Dec 07 19:03:40 volumiomom go-librespot[1858]: time="2025-12-07T19:03:40-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:03:41 volumiomom go-librespot[1858]: time="2025-12-07T19:03:41-05:00" level=debug msg="completed keyexchange" Dec 07 19:03:41 volumiomom go-librespot[1858]: time="2025-12-07T19:03:41-05:00" level=debug msg="completed challenge" Dec 07 19:03:41 volumiomom go-librespot[1858]: time="2025-12-07T19:03:41-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:03:41 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:03:41 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:03:41 volumiomom volumio[1188]: info: Connection to go-librespot Websocket closed Dec 07 19:03:44 volumiomom volumio[1188]: info: Getting Spotify volume Dec 07 19:03:44 volumiomom volumio[1188]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 19:03:44 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Dec 07 19:03:44 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:44 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:44 volumiomom go-librespot[1879]: go-librespot daemon starting... Dec 07 19:03:44 volumiomom volumio[1188]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 19:03:44 volumiomom volumio[1188]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 07 19:03:44 volumiomom volumio[1188]: errno: -111, Dec 07 19:03:44 volumiomom volumio[1188]: code: 'ECONNREFUSED', Dec 07 19:03:44 volumiomom volumio[1188]: syscall: 'connect', Dec 07 19:03:44 volumiomom volumio[1188]: address: '127.0.0.1', Dec 07 19:03:44 volumiomom volumio[1188]: port: 9879, Dec 07 19:03:44 volumiomom volumio[1188]: response: undefined Dec 07 19:03:44 volumiomom volumio[1188]: } Dec 07 19:03:44 volumiomom go-librespot[1880]: time="2025-12-07T19:03:44-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:03:44 volumiomom go-librespot[1880]: time="2025-12-07T19:03:44-05:00" level=debug msg="app state loaded" Dec 07 19:03:44 volumiomom go-librespot[1880]: time="2025-12-07T19:03:44-05:00" level=debug msg="stored credentials not found" Dec 07 19:03:44 volumiomom go-librespot[1880]: time="2025-12-07T19:03:44-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:03:44 volumiomom volumio[1188]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 19:03:44 volumiomom go-librespot[1880]: time="2025-12-07T19:03:44-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 19:03:44 volumiomom go-librespot[1880]: time="2025-12-07T19:03:44-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 19:03:44 volumiomom go-librespot[1880]: time="2025-12-07T19:03:44-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 19:03:44 volumiomom go-librespot[1880]: time="2025-12-07T19:03:44-05:00" level=info msg="zeroconf server listening on port 42721" Dec 07 19:03:45 volumiomom go-librespot[1880]: time="2025-12-07T19:03:45-05:00" level=debug msg="obtained new client token: AACCRKkS42j3KsOgKsQZ+fDIebDfGQGLTDZI3EXwIlI9BJHqIf2thNh2r5hX271KZ+XamVOJYnrqi5gm+DP9sFheJEOkzjrdM9r8T8xH+WADhklkJuXKLxxshCkZTatsaABzXF93nF9s5pXe6S7NtXEHnw1a6Ll8+FYQVyyGHASAk8+tBLwvfYk+QHXlI+U0z8tg6ar3K9rCXrMZAc72jwU/a8ddjg4YrhgdC08bqJmBrbZnKEiSsZX9" Dec 07 19:03:45 volumiomom go-librespot[1880]: time="2025-12-07T19:03:45-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:03:45 volumiomom go-librespot[1880]: time="2025-12-07T19:03:45-05:00" level=debug msg="completed keyexchange" Dec 07 19:03:45 volumiomom go-librespot[1880]: time="2025-12-07T19:03:45-05:00" level=debug msg="completed challenge" Dec 07 19:03:45 volumiomom go-librespot[1880]: time="2025-12-07T19:03:45-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:03:45 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:03:45 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:03:48 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Dec 07 19:03:48 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:48 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:48 volumiomom go-librespot[1899]: go-librespot daemon starting... Dec 07 19:03:48 volumiomom go-librespot[1900]: time="2025-12-07T19:03:48-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:03:48 volumiomom go-librespot[1900]: time="2025-12-07T19:03:48-05:00" level=debug msg="app state loaded" Dec 07 19:03:48 volumiomom go-librespot[1900]: time="2025-12-07T19:03:48-05:00" level=debug msg="stored credentials not found" Dec 07 19:03:48 volumiomom go-librespot[1900]: time="2025-12-07T19:03:48-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:03:49 volumiomom go-librespot[1900]: time="2025-12-07T19:03:49-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 19:03:49 volumiomom go-librespot[1900]: time="2025-12-07T19:03:49-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 19:03:49 volumiomom go-librespot[1900]: time="2025-12-07T19:03:49-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 19:03:49 volumiomom go-librespot[1900]: time="2025-12-07T19:03:49-05:00" level=info msg="zeroconf server listening on port 39989" Dec 07 19:03:49 volumiomom go-librespot[1900]: time="2025-12-07T19:03:49-05:00" level=debug msg="obtained new client token: AABWh6BC0FqMss7IWIrc3ptxWtxxHCwwBWX7pEe5QHm/Q65TQQSsbVC3blEoBIvs5dRZa9I/4JGEYOvdCapiDcrBHDv0Ma72lcqCmykZNChmVjwcV2dHjpYEa7Yca16FIcZZT6AWhOU9Y/pCd3CHnpqBGFQcbAPf88rBHySbsfzb93c4RFje+l7WMKrrpXTV3KW/JOSWcSsKh23aKmBOvKaMcA3Ye+y5+d5mBWr0BBo0z5LgCWhShVUG+Zc=" Dec 07 19:03:49 volumiomom go-librespot[1900]: time="2025-12-07T19:03:49-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:03:49 volumiomom go-librespot[1900]: time="2025-12-07T19:03:49-05:00" level=debug msg="completed keyexchange" Dec 07 19:03:49 volumiomom go-librespot[1900]: time="2025-12-07T19:03:49-05:00" level=debug msg="completed challenge" Dec 07 19:03:49 volumiomom go-librespot[1900]: time="2025-12-07T19:03:49-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:03:49 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:03:49 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:03:52 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Dec 07 19:03:52 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:52 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:52 volumiomom go-librespot[1913]: go-librespot daemon starting... Dec 07 19:03:53 volumiomom go-librespot[1918]: time="2025-12-07T19:03:53-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:03:53 volumiomom go-librespot[1918]: time="2025-12-07T19:03:53-05:00" level=debug msg="app state loaded" Dec 07 19:03:53 volumiomom go-librespot[1918]: time="2025-12-07T19:03:53-05:00" level=debug msg="stored credentials not found" Dec 07 19:03:53 volumiomom go-librespot[1918]: time="2025-12-07T19:03:53-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:03:53 volumiomom go-librespot[1918]: time="2025-12-07T19:03:53-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 19:03:53 volumiomom go-librespot[1918]: time="2025-12-07T19:03:53-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 19:03:53 volumiomom go-librespot[1918]: time="2025-12-07T19:03:53-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 19:03:53 volumiomom go-librespot[1918]: time="2025-12-07T19:03:53-05:00" level=info msg="zeroconf server listening on port 46459" Dec 07 19:03:53 volumiomom go-librespot[1918]: time="2025-12-07T19:03:53-05:00" level=debug msg="obtained new client token: AADsZvrDLt7wmjC7JZrxhPWDPd1DBHclRmd7M5n8LE7nuKfCJo1Yz4vyhh5oVTiSaoMUAgImn3+yRRrwIarPho2VzNtrJxTImT/AXXFjATlOe+i4U1qwAdvBhRDrNPX6lqdsIcj0ITZbmHi/QovNuCuVQ3qwlKhWtZOQRFhBG8pHzjwAlJDYT5xNMMtuDlKQeTsjdkelE3RncB/aFlZvn6oiH8a5w8HFhxXpYHd++SXwMFTHalQUKdmUtp0=" Dec 07 19:03:53 volumiomom go-librespot[1918]: time="2025-12-07T19:03:53-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:03:54 volumiomom go-librespot[1918]: time="2025-12-07T19:03:54-05:00" level=debug msg="completed keyexchange" Dec 07 19:03:54 volumiomom go-librespot[1918]: time="2025-12-07T19:03:54-05:00" level=debug msg="completed challenge" Dec 07 19:03:54 volumiomom go-librespot[1918]: time="2025-12-07T19:03:54-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:03:54 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:03:54 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:03:57 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Dec 07 19:03:57 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:57 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:03:57 volumiomom go-librespot[1935]: go-librespot daemon starting... Dec 07 19:03:57 volumiomom go-librespot[1936]: time="2025-12-07T19:03:57-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:03:57 volumiomom go-librespot[1936]: time="2025-12-07T19:03:57-05:00" level=debug msg="app state loaded" Dec 07 19:03:57 volumiomom go-librespot[1936]: time="2025-12-07T19:03:57-05:00" level=debug msg="stored credentials not found" Dec 07 19:03:57 volumiomom go-librespot[1936]: time="2025-12-07T19:03:57-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 19:03:57 volumiomom upmpdcli[1942]: writing RSA key Dec 07 19:03:58 volumiomom go-librespot[1936]: time="2025-12-07T19:03:58-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 19:03:58 volumiomom go-librespot[1936]: time="2025-12-07T19:03:58-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 19:03:58 volumiomom go-librespot[1936]: time="2025-12-07T19:03:58-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 19:03:58 volumiomom go-librespot[1936]: time="2025-12-07T19:03:58-05:00" level=info msg="zeroconf server listening on port 37487" Dec 07 19:03:58 volumiomom go-librespot[1936]: time="2025-12-07T19:03:58-05:00" level=debug msg="obtained new client token: AADIU6igV6nnn7nlfRduBBahoZVrPW7JsR+g5XINBf60UyRhB8GmOtvJ3G1FzLJK1Gg2FCcfa2wPQ3co52VaSrKOcqg379yyWnhHnBESYsz5yyKlhqKUerEd32p36rifbp5rH3PhUTbyRFZJF1vphMFNZ7//52T1RxzXC3/MjcKQpAqBLYHrzfRxIrA6gHdlbXt3bRO3yzcoA1/rJOEfQ5ycGYot/FQ5FBZYwxFR+4L0HNnDZl9YsuVrjdI=" Dec 07 19:03:58 volumiomom go-librespot[1936]: time="2025-12-07T19:03:58-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 19:03:58 volumiomom go-librespot[1936]: time="2025-12-07T19:03:58-05:00" level=debug msg="completed keyexchange" Dec 07 19:03:58 volumiomom go-librespot[1936]: time="2025-12-07T19:03:58-05:00" level=debug msg="completed challenge" Dec 07 19:03:58 volumiomom go-librespot[1936]: time="2025-12-07T19:03:58-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 19:03:58 volumiomom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 19:03:58 volumiomom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 19:04:00 volumiomom sudo[1953]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-07 19:02' Dec 07 19:04:00 volumiomom sudo[1953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 19:04:01 volumiomom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Dec 07 19:04:01 volumiomom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:04:01 volumiomom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 19:04:01 volumiomom go-librespot[1955]: go-librespot daemon starting... Dec 07 19:04:01 volumiomom go-librespot[1956]: time="2025-12-07T19:04:01-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 19:04:01 volumiomom go-librespot[1956]: time="2025-12-07T19:04:01-05:00" level=debug msg="app state loaded" Dec 07 19:04:01 volumiomom go-librespot[1956]: time="2025-12-07T19:04:01-05:00" level=debug msg="stored credentials not found" Dec 07 19:04:01 volumiomom go-librespot[1956]: time="2025-12-07T19:04:01-05:00" level=info msg="api server listening on 127.0.0.1:9879" 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"