Feb 26 22:12:00 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 26 22:12:00 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:00 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:00 loe go-librespot[1691]: go-librespot daemon starting... Feb 26 22:12:00 loe go-librespot[1692]: time="2026-02-26T22:12:00+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:12:00 loe go-librespot[1692]: time="2026-02-26T22:12:00+01:00" level=debug msg="app state loaded" Feb 26 22:12:00 loe go-librespot[1692]: time="2026-02-26T22:12:00+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:12:01 loe go-librespot[1692]: time="2026-02-26T22:12:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:12:01 loe go-librespot[1692]: time="2026-02-26T22:12:01+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:12:01 loe go-librespot[1692]: time="2026-02-26T22:12:01+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:12:01 loe go-librespot[1692]: time="2026-02-26T22:12:01+01:00" level=info msg="zeroconf server listening on port 43811" Feb 26 22:12:01 loe go-librespot[1692]: time="2026-02-26T22:12:01+01:00" level=debug msg="obtained new client token: AAA1cGtgNUeSy23kkVeRxRbhiYKS89mbJCnU3+63/xO/bLczOkhr8wFrdlHhI5MMm+Fv1UHjN6MuHiVnKOMH4DQqDzdo34IXL9uCfWKtVuQU4Uu6TDXcAtYPjro9eQitUSJUpPfz6A4vgGRwN4OoZi9hRu4bKQAMssgooF0ZkjPkgtzbg1DUNYZN/t3AlDXXbkImMueknBSTxUgPSsWwkSaFuvSBnOnQ9w+9vBy4zWkHs1I3sfm8P4Cfbg==" Feb 26 22:12:01 loe go-librespot[1692]: time="2026-02-26T22:12:01+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:12:01 loe go-librespot[1692]: time="2026-02-26T22:12:01+01:00" level=debug msg="completed keyexchange" Feb 26 22:12:01 loe go-librespot[1692]: time="2026-02-26T22:12:01+01:00" level=debug msg="completed challenge" Feb 26 22:12:01 loe go-librespot[1692]: time="2026-02-26T22:12:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:12:01 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:12:01 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:12:03 loe volumio[1251]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 26 22:12:03 loe volumio[1251]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 26 22:12:03 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:12:03 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:12:03 loe volumio[1251]: info: Starting MyVolumio Remote Streaming Endpoints Feb 26 22:12:03 loe volumio[1251]: info: MyVolumio login type: Token Feb 26 22:12:03 loe volumio[1251]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 26 22:12:03 loe volumio[1251]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 26 22:12:04 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 26 22:12:04 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:04 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:04 loe go-librespot[1700]: go-librespot daemon starting... Feb 26 22:12:04 loe go-librespot[1701]: time="2026-02-26T22:12:04+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:12:04 loe go-librespot[1701]: time="2026-02-26T22:12:04+01:00" level=debug msg="app state loaded" Feb 26 22:12:04 loe go-librespot[1701]: time="2026-02-26T22:12:04+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:12:05 loe go-librespot[1701]: time="2026-02-26T22:12:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:12:05 loe go-librespot[1701]: time="2026-02-26T22:12:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:12:05 loe go-librespot[1701]: time="2026-02-26T22:12:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:12:05 loe go-librespot[1701]: time="2026-02-26T22:12:05+01:00" level=info msg="zeroconf server listening on port 44861" Feb 26 22:12:05 loe go-librespot[1701]: time="2026-02-26T22:12:05+01:00" level=debug msg="obtained new client token: AABN//c1VFpVS/tDJgB1+ygZLg2ylWWlO0X+QBANTpyrRtUCqjOW2vlgkgidd7DpeueouNDVSI7Rnzd9VfmEPCXv40qkqI1eWFPK66AmnDCvPQXS1YWhIGthDSm6Qva3ZC+yPsCKFxotRv/aOTCa6apX7sgGtqp3kM26aHKKoZUqSvSzsn6286dYnrbJsZ+IN+ZzvkQ2izSNAJI9fL1bWpBe9uPzD6Dy3XD5fKpBPe3eXouJ3oPB+SquSw==" Feb 26 22:12:05 loe go-librespot[1701]: time="2026-02-26T22:12:05+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:12:05 loe go-librespot[1701]: time="2026-02-26T22:12:05+01:00" level=debug msg="completed keyexchange" Feb 26 22:12:05 loe go-librespot[1701]: time="2026-02-26T22:12:05+01:00" level=debug msg="completed challenge" Feb 26 22:12:05 loe go-librespot[1701]: time="2026-02-26T22:12:05+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:12:05 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:12:05 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:12:08 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 26 22:12:08 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:09 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:09 loe go-librespot[1723]: go-librespot daemon starting... Feb 26 22:12:09 loe go-librespot[1724]: time="2026-02-26T22:12:09+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:12:09 loe go-librespot[1724]: time="2026-02-26T22:12:09+01:00" level=debug msg="app state loaded" Feb 26 22:12:09 loe go-librespot[1724]: time="2026-02-26T22:12:09+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:12:09 loe volumio-remote-updater[708]: [2026-02-26 22:12:09] [connect] Successful connection Feb 26 22:12:09 loe go-librespot[1724]: time="2026-02-26T22:12:09+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:12:09 loe go-librespot[1724]: time="2026-02-26T22:12:09+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:12:09 loe go-librespot[1724]: time="2026-02-26T22:12:09+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:12:09 loe go-librespot[1724]: time="2026-02-26T22:12:09+01:00" level=info msg="zeroconf server listening on port 33001" Feb 26 22:12:09 loe go-librespot[1724]: time="2026-02-26T22:12:09+01:00" level=debug msg="obtained new client token: AAAiE0UPEQGC1WHWpKmjJZn9aD6+q6kzCViM6cHHys8jTf20CvEnw9kHjQgNb3wda07wEe4r8hdZebCSVVhXXIYAcajU9FGGkW+Vj0X3Jm8LsxK5id0+y72pAw1euJljTKvpkMQMzYrW2VQhKxTXcJj9S+WxLZbO1lq9jgmy3LBm9fH5Svz6BCljMjoPcTVczz7lZtUPNq3Ru2OR6pmef6KqVx+Bk6vByQjtajo+1i1n3bGRImgvXUNJ1Q==" Feb 26 22:12:10 loe go-librespot[1724]: time="2026-02-26T22:12:10+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:12:10 loe go-librespot[1724]: time="2026-02-26T22:12:10+01:00" level=debug msg="completed keyexchange" Feb 26 22:12:10 loe go-librespot[1724]: time="2026-02-26T22:12:10+01:00" level=debug msg="completed challenge" Feb 26 22:12:10 loe go-librespot[1724]: time="2026-02-26T22:12:10+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:12:10 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:12:10 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:12:13 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 26 22:12:13 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:13 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:13 loe go-librespot[1731]: go-librespot daemon starting... Feb 26 22:12:13 loe go-librespot[1732]: time="2026-02-26T22:12:13+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:12:13 loe go-librespot[1732]: time="2026-02-26T22:12:13+01:00" level=debug msg="app state loaded" Feb 26 22:12:13 loe go-librespot[1732]: time="2026-02-26T22:12:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:12:13 loe go-librespot[1732]: time="2026-02-26T22:12:13+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 26 22:12:13 loe go-librespot[1732]: time="2026-02-26T22:12:13+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 26 22:12:13 loe go-librespot[1732]: time="2026-02-26T22:12:13+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 26 22:12:13 loe go-librespot[1732]: time="2026-02-26T22:12:13+01:00" level=info msg="zeroconf server listening on port 45007" Feb 26 22:12:14 loe go-librespot[1732]: time="2026-02-26T22:12:14+01:00" level=debug msg="obtained new client token: AADuVx8wAMyTpV5BAA7kzrkhLtHJSzrl0yjsNJRrASNcUlmpwj/ar6qDdlatmRXWlUFfpoiOoR8rSuSC2rZh5GQ/fj8CZ1tL1WJaat6CKw3eDMMvXpjPKs47UPeOYUWIufwJEv0kSfJfYcqhIlHl+8Hkdp3IxsEeRXnSbUAAF5c/KT2soKNcQQVYw34ThCzAzw6HmScVnLIbjqT0X8MwyqzjfjbEhKFztA6PypY7eps6F/vzfd0415E=" Feb 26 22:12:14 loe go-librespot[1732]: time="2026-02-26T22:12:14+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:12:14 loe go-librespot[1732]: time="2026-02-26T22:12:14+01:00" level=debug msg="completed keyexchange" Feb 26 22:12:14 loe go-librespot[1732]: time="2026-02-26T22:12:14+01:00" level=debug msg="completed challenge" Feb 26 22:12:14 loe go-librespot[1732]: time="2026-02-26T22:12:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:12:14 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:12:14 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:12:14 loe volumio[1251]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 26 22:12:14 loe volumio[1251]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 26 22:12:14 loe volumio[1251]: info: Streaming services startup Feb 26 22:12:14 loe volumio[1251]: info: Starting Streaming Daemon Feb 26 22:12:15 loe volumio[1251]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 26 22:12:15 loe sudo[1741]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 26 22:12:15 loe sudo[1741]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:12:15 loe sudo[1741]: pam_unix(sudo:session): session closed for user root Feb 26 22:12:15 loe volumio[1251]: info: Initializing connection to go-librespot Websocket Feb 26 22:12:15 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 26 22:12:16 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:12:16 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 26 22:12:16 loe volumio[1251]: error: Cannot start Volumio Streaming Daemon Feb 26 22:12:16 loe volumio[1251]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 26 22:12:16 loe volumio[1251]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 26 22:12:16 loe volumio[1251]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 22:12:17 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 26 22:12:17 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:17 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:17 loe go-librespot[1764]: go-librespot daemon starting... Feb 26 22:12:17 loe go-librespot[1765]: time="2026-02-26T22:12:17+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:12:17 loe go-librespot[1765]: time="2026-02-26T22:12:17+01:00" level=debug msg="app state loaded" Feb 26 22:12:17 loe go-librespot[1765]: time="2026-02-26T22:12:17+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:12:18 loe go-librespot[1765]: time="2026-02-26T22:12:18+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:12:18 loe go-librespot[1765]: time="2026-02-26T22:12:18+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:12:18 loe go-librespot[1765]: time="2026-02-26T22:12:18+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:12:18 loe go-librespot[1765]: time="2026-02-26T22:12:18+01:00" level=info msg="zeroconf server listening on port 39465" Feb 26 22:12:18 loe go-librespot[1765]: time="2026-02-26T22:12:18+01:00" level=debug msg="obtained new client token: AAA3O2GesFguT97hTrdHxt6JEgV1cPbgMLj9BBSx7L57cGQkwgBs/ZfixPBogkpJE+zZN++AihFFl1PZXZWNCCWlxgQZ54CxbgMMMMTpBGTbxnxgYzcF+kIvEHio2WQ6r+ksELvxG5y+wvcWImz3TxAemECmsqy/64bP9PTc3bwimEeXaFB/X9bGelkFgcU2wRvJiFP89Iu+oG5g/3S43dgl2EA9MGzRGPkn1o62vp0M6mTLnDV9+jbv6g==" Feb 26 22:12:18 loe go-librespot[1765]: time="2026-02-26T22:12:18+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:12:18 loe go-librespot[1765]: time="2026-02-26T22:12:18+01:00" level=debug msg="completed keyexchange" Feb 26 22:12:18 loe go-librespot[1765]: time="2026-02-26T22:12:18+01:00" level=debug msg="completed challenge" Feb 26 22:12:18 loe go-librespot[1765]: time="2026-02-26T22:12:18+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:12:18 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:12:18 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:12:18 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 26 22:12:19 loe volumio[1251]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 26 22:12:19 loe volumio[1251]: info: Initializing connection to go-librespot Websocket Feb 26 22:12:20 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 26 22:12:20 loe volumio[1251]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 22:12:20 loe volumio[1251]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 26 22:12:20 loe volumio5-onboarding[1587]: failed to bootstrap state: failed to check for software update: could not check for updates: context deadline exceeded Feb 26 22:12:20 loe systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:12:20 loe systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Feb 26 22:12:20 loe systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 3. Feb 26 22:12:20 loe systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 26 22:12:21 loe systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 26 22:12:21 loe volumio5-onboarding[1772]: time=2026-02-26T22:12:21.155+01:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Feb 26 22:12:21 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 26 22:12:21 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:21 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:21 loe go-librespot[1779]: go-librespot daemon starting... Feb 26 22:12:22 loe go-librespot[1780]: time="2026-02-26T22:12:22+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:12:22 loe go-librespot[1780]: time="2026-02-26T22:12:22+01:00" level=debug msg="app state loaded" Feb 26 22:12:22 loe go-librespot[1780]: time="2026-02-26T22:12:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:12:22 loe volumio[1251]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Feb 26 22:12:22 loe volumio[1251]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Feb 26 22:12:22 loe volumio[1251]: info: Received Get System Info Feb 26 22:12:22 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 22:12:22 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 22:12:22 loe volumio[1251]: info: Discovery: Getting this device information Feb 26 22:12:22 loe volumio[1251]: info: CoreCommandRouter::volumioGetState Feb 26 22:12:22 loe volumio[1251]: info: CorePlayQueue::getTrack 0 Feb 26 22:12:22 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 22:12:22 loe volumio5-onboarding[1772]: time=2026-02-26T22:12:22.445+01:00 level=INFO msg="system info for a53384b16fd4d7a180fdac1b5068092c" deviceName=Loe deviceVariant=volumio deviceModel= softwareVersion=4.096 Feb 26 22:12:22 loe volumio[1251]: info: MyVolumio token set successfully Feb 26 22:12:22 loe volumio[1251]: info: MYVOLUMIO: Adding device Feb 26 22:12:22 loe volumio[1251]: info: MYVOLUMIO: Evaluating Server Feb 26 22:12:22 loe go-librespot[1780]: time="2026-02-26T22:12:22+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:12:22 loe go-librespot[1780]: time="2026-02-26T22:12:22+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:12:22 loe go-librespot[1780]: time="2026-02-26T22:12:22+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:12:22 loe go-librespot[1780]: time="2026-02-26T22:12:22+01:00" level=info msg="zeroconf server listening on port 46853" Feb 26 22:12:22 loe volumio[1251]: info: Received Get System Info Feb 26 22:12:22 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 22:12:22 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 22:12:22 loe volumio[1251]: info: Discovery: Getting this device information Feb 26 22:12:22 loe volumio[1251]: info: CoreCommandRouter::volumioGetState Feb 26 22:12:22 loe volumio[1251]: info: CorePlayQueue::getTrack 0 Feb 26 22:12:22 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 22:12:22 loe go-librespot[1780]: time="2026-02-26T22:12:22+01:00" level=debug msg="obtained new client token: AACYRZrldoaCU7jmqShapoS5npat5j4PWEQc4pR0AzvLIhMyOexBSwhKxoNT/hjdFQBYOl5I0y2HBGNZRcboSXgUSXSKjhH9ZdzOsTckvxSuPaFOzU1dgoBZ//L9EOwuYg+jqYSUnyBpoynbcyS2mRefamKLaVe0OtaAiZHloxTiHU5gPJiPoGL+IxuFLJVV/ThQGVX6koOrCuvo4DM5Lp2CiQRorZ/Yg4HBIJbLJQcDdM/IhVB3T6E8LQ==" Feb 26 22:12:22 loe go-librespot[1780]: time="2026-02-26T22:12:22+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:12:22 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 26 22:12:22 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 26 22:12:22 loe go-librespot[1780]: time="2026-02-26T22:12:22+01:00" level=debug msg="completed keyexchange" Feb 26 22:12:22 loe go-librespot[1780]: time="2026-02-26T22:12:22+01:00" level=debug msg="completed challenge" Feb 26 22:12:23 loe volumio5-onboarding[1772]: time=2026-02-26T22:12:23.000+01:00 level=INFO msg="enabling local network discovery" Feb 26 22:12:23 loe go-librespot[1780]: time="2026-02-26T22:12:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:12:23 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:12:23 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:12:23 loe volumio5-onboarding[1772]: time=2026-02-26T22:12:23.085+01:00 level=INFO msg="bootstrapping state" hasInternet=true Feb 26 22:12:24 loe volumio[1251]: info: MyVolumio Plan changed: premium Feb 26 22:12:24 loe volumio[1251]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Feb 26 22:12:24 loe volumio[1251]: info: Removing browser output: myVolumio user plan is not superstar Feb 26 22:12:24 loe volumio[1251]: info: Removing audio output: Feb 26 22:12:24 loe volumio[1251]: info: MYVOLUMIO: Adding device Feb 26 22:12:24 loe volumio[1251]: info: MYVOLUMIO: Evaluating Server Feb 26 22:12:24 loe volumio[1251]: info: Initializing connection to go-librespot Websocket Feb 26 22:12:24 loe volumio-remote-updater[708]: [2026-02-26 22:12:24] [connect] Successful connection Feb 26 22:12:24 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:12:24 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:12:24 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 26 22:12:24 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 26 22:12:24 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 26 22:12:24 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 26 22:12:24 loe volumio[1251]: info: CoreCommandRouter::volumioGetBrowseSources Feb 26 22:12:24 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 26 22:12:24 loe volumio[1251]: info: Received Get System Info Feb 26 22:12:24 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 22:12:24 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 22:12:24 loe volumio[1251]: info: Discovery: Getting this device information Feb 26 22:12:24 loe volumio[1251]: info: CoreCommandRouter::volumioGetState Feb 26 22:12:24 loe volumio[1251]: info: CorePlayQueue::getTrack 0 Feb 26 22:12:24 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 22:12:26 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 26 22:12:26 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:26 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:26 loe go-librespot[1844]: go-librespot daemon starting... Feb 26 22:12:26 loe go-librespot[1846]: time="2026-02-26T22:12:26+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:12:26 loe go-librespot[1846]: time="2026-02-26T22:12:26+01:00" level=debug msg="app state loaded" Feb 26 22:12:26 loe go-librespot[1846]: time="2026-02-26T22:12:26+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:12:26 loe go-librespot[1846]: time="2026-02-26T22:12:26+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:12:26 loe go-librespot[1846]: time="2026-02-26T22:12:26+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:12:26 loe go-librespot[1846]: time="2026-02-26T22:12:26+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:12:26 loe go-librespot[1846]: time="2026-02-26T22:12:26+01:00" level=info msg="zeroconf server listening on port 45385" Feb 26 22:12:27 loe volumio[1251]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 22:12:27 loe volumio-remote-updater[708]: [2026-02-26 22:12:27] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772140344 101 Feb 26 22:12:27 loe volumio[1251]: 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: 4 Feb 26 22:12:27 loe volumio[1251]: info: CoreCommandRouter::volumioGetState Feb 26 22:12:27 loe volumio[1251]: info: CorePlayQueue::getTrack 0 Feb 26 22:12:27 loe volumio[1251]: info: Remote config written successfully Feb 26 22:12:27 loe volumio[1251]: info: Starting Tunnel 1 Feb 26 22:12:27 loe volumio[1251]: info: Starting Tunnel Connection Checker Feb 26 22:12:27 loe volumio[1251]: info: Completed starting MyVolumio Plugin Feb 26 22:12:27 loe volumio[1251]: info: MYVolumio Device enabled Feb 26 22:12:27 loe volumio[1251]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Feb 26 22:12:27 loe volumio[1251]: info: MyVolumio status changed Feb 26 22:12:27 loe volumio[1251]: info: Streaming services startup Feb 26 22:12:27 loe volumio[1251]: info: Starting Streaming Daemon Feb 26 22:12:27 loe sudo[1854]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 26 22:12:27 loe sudo[1854]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:12:28 loe volumio[1251]: info: Setting Geolocation for MyVolumio to eu2 Feb 26 22:12:28 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:12:28 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:12:28 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:12:28 loe sudo[1854]: pam_unix(sudo:session): session closed for user root Feb 26 22:12:28 loe volumio[1251]: error: Cannot start Volumio Streaming Daemon Feb 26 22:12:28 loe volumio[1251]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 26 22:12:28 loe volumio[1251]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 26 22:12:28 loe volumio[1251]: info: Successfully Added MyVolumio device Feb 26 22:12:28 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Feb 26 22:12:28 loe volumio[1251]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Feb 26 22:12:31 loe volumio[1251]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Feb 26 22:12:31 loe volumio[1251]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Feb 26 22:12:32 loe go-librespot[1846]: time="2026-02-26T22:12:32+01:00" level=debug msg="obtained new client token: AACx2ugzHVsarFHFdR2RGZcozADy7HUsiZ5AEzzXvNPpgzCiGslHm1mjJA6nZw8Efv9VNn5tKmF5jDJM1aYlQ+NTGsXojXL0WxfglmgKmQj1Ys5GuzzHAnL5OeSVP3Eg22xTnHdnmZ74Q9zQDw8ZXb4HDBbXH+bn46tNxv6Z8N+9nLidEdQIp6BwM2MP+cOU4If2IRoHkkqnes9ze8KNljBliHuOt4Ppx7UaMKvZrHByg3TddoGC3H0=" Feb 26 22:12:32 loe go-librespot[1846]: time="2026-02-26T22:12:32+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Feb 26 22:12:32 loe go-librespot[1846]: time="2026-02-26T22:12:32+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 26 22:12:32 loe go-librespot[1846]: time="2026-02-26T22:12:32+01:00" level=debug msg="completed keyexchange" Feb 26 22:12:32 loe go-librespot[1846]: time="2026-02-26T22:12:32+01:00" level=debug msg="completed challenge" Feb 26 22:12:32 loe go-librespot[1846]: time="2026-02-26T22:12:32+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:12:32 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:12:32 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:12:35 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 26 22:12:35 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:35 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:35 loe go-librespot[1857]: go-librespot daemon starting... Feb 26 22:12:35 loe go-librespot[1858]: time="2026-02-26T22:12:35+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:12:35 loe go-librespot[1858]: time="2026-02-26T22:12:35+01:00" level=debug msg="app state loaded" Feb 26 22:12:35 loe go-librespot[1858]: time="2026-02-26T22:12:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:12:36 loe go-librespot[1858]: time="2026-02-26T22:12:36+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:12:36 loe go-librespot[1858]: time="2026-02-26T22:12:36+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:12:36 loe go-librespot[1858]: time="2026-02-26T22:12:36+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:12:36 loe go-librespot[1858]: time="2026-02-26T22:12:36+01:00" level=info msg="zeroconf server listening on port 41009" Feb 26 22:12:36 loe go-librespot[1858]: time="2026-02-26T22:12:36+01:00" level=debug msg="obtained new client token: AACDi4YBlTN+rsd8uJuoS0bAejzUfH16ZgeR3b1tmomploxWRaBNdd0hBZBwB+YwjzS5obvD8K9efgcavGazHq8+17582Y3Gj6tJIerhGtm0lnpMDwQW40Tn9XB3VoOiMOfQooLuPWu/hB/GUDeihlc7WLnB1gmXcTkc8zZTD2MAyavm7Ych4h2nCemX5S0tqBqAegFz9BzReUkh+DA3HQ+H8CWexE2kWI9XHQYJjZFrCbHapZmA+c7mMA==" Feb 26 22:12:36 loe go-librespot[1858]: time="2026-02-26T22:12:36+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:12:36 loe go-librespot[1858]: time="2026-02-26T22:12:36+01:00" level=debug msg="completed keyexchange" Feb 26 22:12:36 loe go-librespot[1858]: time="2026-02-26T22:12:36+01:00" level=debug msg="completed challenge" Feb 26 22:12:36 loe go-librespot[1858]: time="2026-02-26T22:12:36+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:12:36 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:12:36 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:12:39 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 26 22:12:39 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:39 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:39 loe go-librespot[1880]: go-librespot daemon starting... Feb 26 22:12:39 loe go-librespot[1881]: time="2026-02-26T22:12:39+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:12:39 loe go-librespot[1881]: time="2026-02-26T22:12:39+01:00" level=debug msg="app state loaded" Feb 26 22:12:39 loe go-librespot[1881]: time="2026-02-26T22:12:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:12:40 loe go-librespot[1881]: time="2026-02-26T22:12:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:12:40 loe go-librespot[1881]: time="2026-02-26T22:12:40+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:12:40 loe go-librespot[1881]: time="2026-02-26T22:12:40+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:12:40 loe go-librespot[1881]: time="2026-02-26T22:12:40+01:00" level=info msg="zeroconf server listening on port 41103" Feb 26 22:12:40 loe go-librespot[1881]: time="2026-02-26T22:12:40+01:00" level=debug msg="obtained new client token: AADgXtQy3dlq7yxIXmPRUzDwwq8ojVcU6Ta5L7zwdt6uSrMyCD5rUpJ5YXn7G4f/ZhBHvf2TeQ4rqDa9YUKQe7PcpZBi5IMzHqVH2atlHg8D986Bg0eCf6reGsI2klnuMNXijcxHLlZW7LS1fE0qvLKfWFkW+TXz8UuL6g5mtYe/SbOx3tiFeohv4Y/vu9M+J8Ok64SZhUkgmOpLKaGYY47e4ALsdoKyZF73bdK1EOffBI03sa+rxp1eQw==" Feb 26 22:12:40 loe go-librespot[1881]: time="2026-02-26T22:12:40+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:12:40 loe go-librespot[1881]: time="2026-02-26T22:12:40+01:00" level=debug msg="completed keyexchange" Feb 26 22:12:40 loe go-librespot[1881]: time="2026-02-26T22:12:40+01:00" level=debug msg="completed challenge" Feb 26 22:12:40 loe go-librespot[1881]: time="2026-02-26T22:12:40+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:12:41 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:12:41 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:12:44 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 26 22:12:44 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:44 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:44 loe go-librespot[1888]: go-librespot daemon starting... Feb 26 22:12:44 loe go-librespot[1889]: time="2026-02-26T22:12:44+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:12:44 loe go-librespot[1889]: time="2026-02-26T22:12:44+01:00" level=debug msg="app state loaded" Feb 26 22:12:44 loe go-librespot[1889]: time="2026-02-26T22:12:44+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:12:45 loe go-librespot[1889]: time="2026-02-26T22:12:45+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:12:45 loe go-librespot[1889]: time="2026-02-26T22:12:45+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:12:45 loe go-librespot[1889]: time="2026-02-26T22:12:45+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:12:45 loe go-librespot[1889]: time="2026-02-26T22:12:45+01:00" level=info msg="zeroconf server listening on port 40699" Feb 26 22:12:45 loe go-librespot[1889]: time="2026-02-26T22:12:45+01:00" level=debug msg="obtained new client token: AADxrWvRmV5vhVG42YzdNPaSrpT1JFW+w6eTY7AjJgKk4zz6ynLVWFyx4efRjrazHn52XDRECG/+Ega27k4wfOXtUFJr5SILBQjpeL7+D371oPa4pak0lMy6Nbf6OC7QX1A5315o4FLLwtYMVvAI00i3vzPcyJ5lRc68s9xRjcHsNg5qVgEKYH4lQLmCSMieQo8OxRPi4TD3tdmbcZKGcga1XRHaP2z4FLNFcr9ZREsPNQSDF79Btgs=" Feb 26 22:12:45 loe go-librespot[1889]: time="2026-02-26T22:12:45+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:12:45 loe go-librespot[1889]: time="2026-02-26T22:12:45+01:00" level=debug msg="completed keyexchange" Feb 26 22:12:45 loe go-librespot[1889]: time="2026-02-26T22:12:45+01:00" level=debug msg="completed challenge" Feb 26 22:12:45 loe go-librespot[1889]: time="2026-02-26T22:12:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:12:45 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:12:45 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:12:47 loe volumio[1251]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Feb 26 22:12:48 loe sudo[1913]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Feb 26 22:12:48 loe sudo[1913]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:12:48 loe sudo[1913]: pam_unix(sudo:session): session closed for user root Feb 26 22:12:48 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 26 22:12:48 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:48 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:48 loe go-librespot[1919]: go-librespot daemon starting... Feb 26 22:12:48 loe go-librespot[1922]: time="2026-02-26T22:12:48+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:12:48 loe go-librespot[1922]: time="2026-02-26T22:12:48+01:00" level=debug msg="app state loaded" Feb 26 22:12:48 loe go-librespot[1922]: time="2026-02-26T22:12:48+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:12:49 loe volumio[1251]: info: MRS: MultiRoom plugin initialized Feb 26 22:12:49 loe volumio[1251]: info: MRS: STOPPING SNAPCLIENT Feb 26 22:12:49 loe volumio[1251]: info: MRS: Snap server stop Feb 26 22:12:49 loe volumio[1251]: info: MRS: STOPPING volumioStreaming Feb 26 22:12:49 loe go-librespot[1922]: time="2026-02-26T22:12:49+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 26 22:12:49 loe go-librespot[1922]: time="2026-02-26T22:12:49+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 26 22:12:49 loe go-librespot[1922]: time="2026-02-26T22:12:49+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 26 22:12:49 loe go-librespot[1922]: time="2026-02-26T22:12:49+01:00" level=info msg="zeroconf server listening on port 45067" Feb 26 22:12:49 loe sudo[1937]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Feb 26 22:12:49 loe sudo[1937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:12:49 loe sudo[1940]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Feb 26 22:12:49 loe sudo[1940]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:12:49 loe go-librespot[1922]: time="2026-02-26T22:12:49+01:00" level=debug msg="obtained new client token: AAAe2DMjGsQU1ciS9a0cTvxQh8PfvfZwSeHzvn5yh71Jmus65kT8GawxcQrg7JQQFAAUyrwW8ny+4Qq4CIAEWmdTWSzSuHeB7BXOi4OMxifnSoH6Ph6IhRtFSQ2rCnrJe5dnR+E3f6jj7kt41qdVUn/hknhZCOxaAEXOxYdFUb+HvYiBLqjjlEewkJZjR8u65Z3DmSz9yPKrr8/bw+NjCxJ4c8YbjEVW7SVminfnUHqozpB0/X6Lyjh/8A==" Feb 26 22:12:49 loe go-librespot[1922]: time="2026-02-26T22:12:49+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:12:49 loe sudo[1937]: pam_unix(sudo:session): session closed for user root Feb 26 22:12:49 loe go-librespot[1922]: time="2026-02-26T22:12:49+01:00" level=debug msg="completed keyexchange" Feb 26 22:12:49 loe go-librespot[1922]: time="2026-02-26T22:12:49+01:00" level=debug msg="completed challenge" Feb 26 22:12:49 loe sudo[1942]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Feb 26 22:12:49 loe go-librespot[1922]: time="2026-02-26T22:12:49+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:12:50 loe sudo[1942]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:12:50 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:12:50 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:12:50 loe volumio[1251]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Feb 26 22:12:50 loe sudo[1940]: pam_unix(sudo:session): session closed for user root Feb 26 22:12:50 loe volumio[1251]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Feb 26 22:12:50 loe sudo[1942]: pam_unix(sudo:session): session closed for user root Feb 26 22:12:50 loe sudo[1947]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Feb 26 22:12:50 loe sudo[1947]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:12:50 loe sudo[1947]: pam_unix(sudo:session): session closed for user root Feb 26 22:12:50 loe volumio[1251]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Feb 26 22:12:50 loe volumio[1251]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Feb 26 22:12:50 loe volumio[1251]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Feb 26 22:12:51 loe volumio[1251]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Feb 26 22:12:51 loe volumio[1251]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Feb 26 22:12:51 loe volumio[1251]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Feb 26 22:12:51 loe volumio[1251]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Feb 26 22:12:52 loe volumio[1251]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Feb 26 22:12:52 loe volumio[1251]: info: Preparing to generate the ALSA configuration file Feb 26 22:12:52 loe volumio[1251]: info: Updating MyVolumio device info Feb 26 22:12:52 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:12:52 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:12:52 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:12:52 loe volumio[1251]: info: Initializing connection to go-librespot Websocket Feb 26 22:12:53 loe volumio[1251]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Feb 26 22:12:53 loe volumio[1251]: info: Reading ALSA contributions from plugins. Feb 26 22:12:53 loe volumio5-onboarding[1772]: failed to bootstrap state: failed to check for software update: could not check for updates: context deadline exceeded Feb 26 22:12:53 loe systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:12:53 loe systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Feb 26 22:12:53 loe volumio[1251]: info: Setting Geolocation for MyVolumio to eu12 Feb 26 22:12:53 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 26 22:12:53 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:53 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:12:53 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:12:53 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:12:53 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:53 loe systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 4. Feb 26 22:12:53 loe go-librespot[1949]: go-librespot daemon starting... Feb 26 22:12:53 loe systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 26 22:12:53 loe systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 26 22:12:53 loe go-librespot[1950]: time="2026-02-26T22:12:53+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:12:53 loe go-librespot[1950]: time="2026-02-26T22:12:53+01:00" level=debug msg="app state loaded" Feb 26 22:12:53 loe go-librespot[1950]: time="2026-02-26T22:12:53+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:12:53 loe volumio5-onboarding[1951]: time=2026-02-26T22:12:53.391+01:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Feb 26 22:12:53 loe volumio[1251]: info: MRS: Removed streaming files Feb 26 22:12:53 loe volumio[1251]: info: MRS: volumioStreaming STOPPED Feb 26 22:12:53 loe volumio[1251]: info: MRS: SNAPSERVER STOPPED Feb 26 22:12:53 loe volumio[1251]: info: MRS: SNAPCLIENT STOPPED Feb 26 22:12:53 loe go-librespot[1950]: time="2026-02-26T22:12:53+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:12:53 loe go-librespot[1950]: time="2026-02-26T22:12:53+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:12:53 loe go-librespot[1950]: time="2026-02-26T22:12:53+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:12:53 loe go-librespot[1950]: time="2026-02-26T22:12:53+01:00" level=info msg="zeroconf server listening on port 44803" Feb 26 22:12:53 loe go-librespot[1950]: time="2026-02-26T22:12:53+01:00" level=debug msg="obtained new client token: AAB85lYuXiY6Wj6wCVZvIQqRSWC48nehf7b1S1lWIuyBLUs5rPF1bMS7s13lYfmA3wLJZpBaVsz7r29v7gnDzgY1az513NBy80Wuc0NrCzsEh0NiRgr2FnnrBTxSizA+6eTOn8sFxiHZO5ctC6Bhl9Zm86GaQnaVP6qgOpNTLDpLgrw8LA4GxQeHEjMWECKO0ChGfLw42LhvtnoIJ8TJN3W2sE+yKtNVnZdQFdb8mteqi7d3iQInehkptg==" Feb 26 22:12:54 loe go-librespot[1950]: time="2026-02-26T22:12:54+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:12:54 loe go-librespot[1950]: time="2026-02-26T22:12:54+01:00" level=debug msg="completed keyexchange" Feb 26 22:12:54 loe go-librespot[1950]: time="2026-02-26T22:12:54+01:00" level=debug msg="completed challenge" Feb 26 22:12:54 loe volumio[1251]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 22:12:54 loe go-librespot[1950]: time="2026-02-26T22:12:54+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:12:54 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:12:54 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:12:54 loe volumio[1251]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Feb 26 22:12:54 loe volumio[1251]: info: Updating MyVolumio device info Feb 26 22:12:54 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:12:54 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:12:54 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:12:55 loe volumio[1251]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Feb 26 22:12:55 loe volumio[1251]: info: Received Get System Info Feb 26 22:12:55 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 22:12:55 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 22:12:55 loe volumio[1251]: info: Discovery: Getting this device information Feb 26 22:12:55 loe volumio[1251]: info: CoreCommandRouter::volumioGetState Feb 26 22:12:55 loe volumio[1251]: info: CorePlayQueue::getTrack 0 Feb 26 22:12:55 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 22:12:55 loe volumio5-onboarding[1951]: time=2026-02-26T22:12:55.246+01:00 level=INFO msg="system info for a53384b16fd4d7a180fdac1b5068092c" deviceName=Loe deviceVariant=volumio deviceModel= softwareVersion=4.096 Feb 26 22:12:55 loe volumio[1251]: info: Received Get System Info Feb 26 22:12:55 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 22:12:55 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 22:12:55 loe volumio[1251]: info: Discovery: Getting this device information Feb 26 22:12:55 loe volumio[1251]: info: CoreCommandRouter::volumioGetState Feb 26 22:12:55 loe volumio[1251]: info: CorePlayQueue::getTrack 0 Feb 26 22:12:55 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 22:12:55 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 26 22:12:55 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 26 22:12:55 loe volumio5-onboarding[1951]: time=2026-02-26T22:12:55.867+01:00 level=INFO msg="enabling local network discovery" Feb 26 22:12:55 loe volumio5-onboarding[1951]: time=2026-02-26T22:12:55.950+01:00 level=INFO msg="bootstrapping state" hasInternet=true Feb 26 22:12:55 loe volumio[1251]: info: Successfully Updated MyVolumio device Feb 26 22:12:56 loe sudo[1974]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Feb 26 22:12:56 loe sudo[1974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:12:56 loe volumio[1251]: info: Received Get System Info Feb 26 22:12:56 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 22:12:56 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 22:12:56 loe 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. Feb 26 22:12:56 loe 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. Feb 26 22:12:56 loe volumio[1251]: info: Discovery: Getting this device information Feb 26 22:12:56 loe volumio[1251]: info: CoreCommandRouter::volumioGetState Feb 26 22:12:56 loe volumio[1251]: info: CorePlayQueue::getTrack 0 Feb 26 22:12:56 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 22:12:56 loe systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Feb 26 22:12:56 loe sudo[1974]: pam_unix(sudo:session): session closed for user root Feb 26 22:12:56 loe volumio[1251]: info: Successfully Added MyVolumio device Feb 26 22:12:56 loe autossh[1979]: port set to 0, monitoring disabled Feb 26 22:12:56 loe autossh[1979]: starting ssh (count 1) Feb 26 22:12:56 loe autossh[1979]: ssh child pid is 1982 Feb 26 22:12:56 loe volumio-remote-updater[708]: Test mode disabled Feb 26 22:12:56 loe volumio-remote-updater[708]: Alpha mode disabled Feb 26 22:12:56 loe volumio-remote-updater[708]: Alpha legacy test mode disabled Feb 26 22:12:56 loe volumio[1251]: info: Remote SSH Started Feb 26 22:12:56 loe volumiossh-tunnel[1982]: Warning: Permanently added '[eu2.myvolumio.org]:2222' (RSA) to the list of known hosts. Feb 26 22:12:57 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 26 22:12:57 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:57 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:12:57 loe go-librespot[1998]: go-librespot daemon starting... Feb 26 22:12:57 loe go-librespot[1999]: time="2026-02-26T22:12:57+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:12:57 loe go-librespot[1999]: time="2026-02-26T22:12:57+01:00" level=debug msg="app state loaded" Feb 26 22:12:57 loe go-librespot[1999]: time="2026-02-26T22:12:57+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:12:58 loe go-librespot[1999]: time="2026-02-26T22:12:58+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:12:58 loe go-librespot[1999]: time="2026-02-26T22:12:58+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:12:58 loe go-librespot[1999]: time="2026-02-26T22:12:58+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:12:58 loe go-librespot[1999]: time="2026-02-26T22:12:58+01:00" level=info msg="zeroconf server listening on port 39037" Feb 26 22:12:58 loe go-librespot[1999]: time="2026-02-26T22:12:58+01:00" level=debug msg="obtained new client token: AACrevAUTvHWS9Jv/xC5kJcMzdh5+f9Dbi13Hxw3QHRBVGWFMrNrKJgMViPpR9kDu0YlTutQS3//JvgKIZ2m0kp+jXeUvOdaPtndFffjkzvzd3h5KY65ymKX3JaPwjmo1a06v89HcGyEsLCedIzaKUd6u41FZ9Naxrw5xhUNjMvfaXtZZxU4b0eOoKWKBDJGqhAXEOVAaJkHnmXwt2KuzmJse+uMRlCL+KoGmLV/y5sTnE1Dr4Q0eB4=" Feb 26 22:12:58 loe go-librespot[1999]: time="2026-02-26T22:12:58+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Feb 26 22:12:58 loe go-librespot[1999]: time="2026-02-26T22:12:58+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 26 22:12:58 loe go-librespot[1999]: time="2026-02-26T22:12:58+01:00" level=debug msg="completed keyexchange" Feb 26 22:12:58 loe go-librespot[1999]: time="2026-02-26T22:12:58+01:00" level=debug msg="completed challenge" Feb 26 22:12:58 loe go-librespot[1999]: time="2026-02-26T22:12:58+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:12:58 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:12:58 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:12:59 loe volumio[1251]: info: Initializing connection to go-librespot Websocket Feb 26 22:12:59 loe volumio[1251]: error: MyVolumio Plugins failed to start in a timely fashion Feb 26 22:12:59 loe volumio[1251]: [Metrics] CommandRouter: 124s 901.37ms Feb 26 22:12:59 loe volumio[1251]: info: CoreCommandRouter::volumiosetStartupVolume Feb 26 22:12:59 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:12:59 loe volumio[1251]: info: VolumeController:: Setting startup Volume 5 Feb 26 22:12:59 loe volumio[1251]: info: VolumeController::SetAlsaVolume5 Feb 26 22:12:59 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:12:59 loe volumio[1251]: info: CoreCommandRouter::Close All Modals sent Feb 26 22:12:59 loe volumio[1251]: info: CoreCommandRouter::Close All Modals sent Feb 26 22:12:59 loe volumio[1251]: info: CoreStateMachine::pushState Feb 26 22:12:59 loe volumio[1251]: info: CorePlayQueue::getTrack 0 Feb 26 22:12:59 loe volumio[1251]: info: CoreCommandRouter::volumioPushState Feb 26 22:12:59 loe volumio[1251]: info: Successfully Updated MyVolumio device Feb 26 22:12:59 loe volumio[1251]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 26 22:12:59 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 26 22:13:00 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 26 22:13:00 loe volumio[1251]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 22:13:00 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Feb 26 22:13:00 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 26 22:13:00 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Feb 26 22:13:00 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 26 22:13:00 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 26 22:13:01 loe volumio[1251]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Feb 26 22:13:01 loe volumio[1251]: info: Asound.conf file written Feb 26 22:13:01 loe sudo[2011]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Feb 26 22:13:01 loe sudo[2011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:01 loe sudo[2011]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:01 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 26 22:13:01 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:01 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:01 loe go-librespot[2015]: go-librespot daemon starting... Feb 26 22:13:01 loe go-librespot[2017]: time="2026-02-26T22:13:01+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:13:01 loe go-librespot[2017]: time="2026-02-26T22:13:01+01:00" level=debug msg="app state loaded" Feb 26 22:13:01 loe go-librespot[2017]: time="2026-02-26T22:13:01+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:13:02 loe volumio[1251]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Feb 26 22:13:02 loe volumio[1251]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Feb 26 22:13:02 loe volumio[1251]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Feb 26 22:13:02 loe volumio[1251]: No state is present for card vc4hdmi Feb 26 22:13:02 loe volumio[1251]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Feb 26 22:13:02 loe volumio[1251]: Found hardware: "vc4-hdmi" "" "" "" "" Feb 26 22:13:02 loe volumio[1251]: Hardware is initialized using a generic method Feb 26 22:13:02 loe volumio[1251]: No state is present for card vc4hdmi Feb 26 22:13:02 loe volumio[1251]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2 Feb 26 22:13:02 loe volumio[1251]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:Max Overclock PLL:0' : Device or resource busy Feb 26 22:13:02 loe volumio[1251]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:Max Overclock DSP:0' : Device or resource busy Feb 26 22:13:02 loe volumio[1251]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:Max Overclock DAC:0' : Device or resource busy Feb 26 22:13:02 loe volumio[1251]: info: Output device has changed, restarting MPD Feb 26 22:13:02 loe volumio[1251]: info: Output device has changed, restarting Shairport Sync Feb 26 22:13:02 loe sudo[2025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 26 22:13:02 loe sudo[2025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:02 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:02 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:13:02 loe go-librespot[2017]: time="2026-02-26T22:13:02+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:13:02 loe go-librespot[2017]: time="2026-02-26T22:13:02+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:13:02 loe go-librespot[2017]: time="2026-02-26T22:13:02+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:13:02 loe sudo[2025]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:02 loe go-librespot[2017]: time="2026-02-26T22:13:02+01:00" level=info msg="zeroconf server listening on port 44633" Feb 26 22:13:02 loe go-librespot[2017]: time="2026-02-26T22:13:02+01:00" level=debug msg="obtained new client token: AACRjWkF2LRZvxT3ZFpnIRaBQVElzRG1b6BxsB5TzYgz4yCwwmznrcsPmEs6sJ5MKKFmHLehXzWwZYkEUKI9d3JeiC/W44GimikY6t+2Uxh5I2ZfLgh0XEQHtRzi85amBFW13DLR3BVPmF/8y4ims1TPEzD3l61Rbxh2GFD/pH9bLN45DwcQJuEjiffkCbANiaj/P6TXQPw6lnMLQJEuSnG4/VMrWYQQWrIsV2n5cmNbq0nQHr/00Bmt3A==" Feb 26 22:13:02 loe sudo[2028]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 26 22:13:02 loe sudo[2028]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:02 loe go-librespot[2017]: time="2026-02-26T22:13:02+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:13:02 loe volumio[1251]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 26 22:13:02 loe go-librespot[2017]: time="2026-02-26T22:13:02+01:00" level=debug msg="completed keyexchange" Feb 26 22:13:02 loe go-librespot[2017]: time="2026-02-26T22:13:02+01:00" level=debug msg="completed challenge" Feb 26 22:13:02 loe volumio[1251]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Feb 26 22:13:02 loe go-librespot[2017]: time="2026-02-26T22:13:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:13:02 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:13:02 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:13:02 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:02 loe systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 26 22:13:02 loe upmpdcli[1389]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Feb 26 22:13:03 loe volumio[1251]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Feb 26 22:13:03 loe volumio[1251]: ------------------------------------ BT MESSAGE: [FUNC] onStart Feb 26 22:13:03 loe volumio[1251]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Feb 26 22:13:03 loe volumio[1251]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Feb 26 22:13:03 loe volumio[1251]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/ Feb 26 22:13:03 loe volumio[1251]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Feb 26 22:13:03 loe volumio[1251]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Feb 26 22:13:03 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Feb 26 22:13:03 loe volumio[1251]: info: MRS: Pushing multiroomSync output for this device Feb 26 22:13:03 loe volumio[1251]: info: MRS: Pushing multiroomSync output Feb 26 22:13:03 loe volumio[1251]: info: Adding audio output: Feb 26 22:13:03 loe volumio[1251]: info: Adding audio output: Feb 26 22:13:03 loe volumio[1251]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Feb 26 22:13:03 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:03 loe bluetoothd[946]: Path / reserved for Adv Monitor app :1.23 Feb 26 22:13:03 loe systemd[1]: mpd.service: Deactivated successfully. Feb 26 22:13:03 loe volumio[1251]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Feb 26 22:13:03 loe systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 26 22:13:03 loe systemd[1]: mpd.service: Consumed 10.380s CPU time. Feb 26 22:13:03 loe systemd[1]: mpd.socket: Deactivated successfully. Feb 26 22:13:03 loe systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 26 22:13:03 loe systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 26 22:13:03 loe volumio[1251]: info: Adding METAVOLUMIO REST API Endpoints Feb 26 22:13:03 loe volumio[1251]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Feb 26 22:13:03 loe volumio[1251]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Feb 26 22:13:03 loe volumio[1251]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Feb 26 22:13:03 loe volumio[1251]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Feb 26 22:13:03 loe volumio[1251]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Feb 26 22:13:03 loe bluetoothd[946]: Adv Monitor app :1.23 disconnected from D-Bus Feb 26 22:13:03 loe volumio[1251]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Feb 26 22:13:03 loe volumio[1251]: info: Preparing CD Folders Feb 26 22:13:03 loe volumio[1251]: info: Adding CD REST API Endpoints Feb 26 22:13:03 loe volumio[1251]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Feb 26 22:13:03 loe volumio[1251]: info: Starting UDEV Watcher for CD Feb 26 22:13:03 loe volumio[1251]: info: Detecting CD presence with UDEV Feb 26 22:13:03 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Feb 26 22:13:03 loe systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 26 22:13:03 loe systemd[1]: Starting mpd.service - Music Player Daemon... Feb 26 22:13:04 loe sudo[2042]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 26 22:13:04 loe sudo[2042]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 26 22:13:04 loe sudo[2042]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:05 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 26 22:13:06 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:06 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:06 loe go-librespot[2048]: go-librespot daemon starting... Feb 26 22:13:06 loe go-librespot[2049]: time="2026-02-26T22:13:06+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:13:06 loe go-librespot[2049]: time="2026-02-26T22:13:06+01:00" level=debug msg="app state loaded" Feb 26 22:13:06 loe go-librespot[2049]: time="2026-02-26T22:13:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:13:06 loe go-librespot[2049]: time="2026-02-26T22:13:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:13:06 loe go-librespot[2049]: time="2026-02-26T22:13:06+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:13:06 loe go-librespot[2049]: time="2026-02-26T22:13:06+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:13:06 loe go-librespot[2049]: time="2026-02-26T22:13:06+01:00" level=info msg="zeroconf server listening on port 41139" Feb 26 22:13:07 loe go-librespot[2049]: time="2026-02-26T22:13:07+01:00" level=debug msg="obtained new client token: AAC4SRT4AGA87+2lX0L/MYwC5N+mSc1aMO5o/8+SFkEoERGrY/a9PThp50K+VDJ8vvdQwl9nhQbFA3J+/jv2me/nak1+/y09jZcZzjtnIBZ6yLq9sYm7jwSIvFlPVIIMyBbvlmNcy1rVI/rsaUarSfGYTZ52ruMo+7EnRi7iyYlRJ/oUp3w2nw7ZU9bzRmC+O9JUzPpE2Wv1j42foWXPctxkDI3x2WkioDRVYrxROdgKpaxSbtgliWg=" Feb 26 22:13:07 loe go-librespot[2049]: time="2026-02-26T22:13:07+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:13:07 loe go-librespot[2049]: time="2026-02-26T22:13:07+01:00" level=debug msg="completed keyexchange" Feb 26 22:13:07 loe go-librespot[2049]: time="2026-02-26T22:13:07+01:00" level=debug msg="completed challenge" Feb 26 22:13:07 loe go-librespot[2049]: time="2026-02-26T22:13:07+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:13:07 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:13:07 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:13:09 loe upmpdcli[1389]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Feb 26 22:13:09 loe upmpdcli[1389]: :2:../src/mpdcli.cxx:396::MPDCli::updStatus: connection failed Feb 26 22:13:09 loe upmpdcli[1389]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Feb 26 22:13:09 loe volumio[1251]: warn: [cd-plugin] cdspeedctl: device or media not ready Feb 26 22:13:09 loe volumio[1251]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Feb 26 22:13:09 loe volumio[1251]: info: Adding inputs REST Endpoints Feb 26 22:13:09 loe volumio[1251]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Feb 26 22:13:09 loe volumio[1251]: info: Scanning Audio Inputs Feb 26 22:13:09 loe mpd[2046]: 2026-02-26T22:13:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 26 22:13:09 loe systemd[1]: Started mpd.service - Music Player Daemon. Feb 26 22:13:09 loe sudo[2028]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:09 loe volumio[1251]: info: Checking against Known Cards name Feb 26 22:13:09 loe volumio[1251]: info: Adding Server instance for streaming Feb 26 22:13:09 loe volumio[1251]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Feb 26 22:13:10 loe volumio[1251]: info: Adding HIGHRESAUDIO REST API Endpoints Feb 26 22:13:10 loe volumio[1251]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Feb 26 22:13:10 loe volumio[1251]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Feb 26 22:13:10 loe volumio[1251]: info: Refreshing TIDAL token Feb 26 22:13:10 loe volumio[1251]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Feb 26 22:13:10 loe volumio[1251]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Feb 26 22:13:10 loe volumio[1251]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Feb 26 22:13:10 loe volumio[1251]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Feb 26 22:13:10 loe volumio[1251]: info: QobuzConnect: Starting Qobuz Connect socket and service Feb 26 22:13:10 loe sudo[2079]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Feb 26 22:13:10 loe sudo[2079]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:10 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 26 22:13:10 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:10 loe volumio[1251]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Feb 26 22:13:10 loe sudo[2086]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Feb 26 22:13:10 loe sudo[2086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:10 loe volumio[1251]: info: Stopping AccessToken refresher cron for QOBUZ Feb 26 22:13:10 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:10 loe go-librespot[2087]: go-librespot daemon starting... Feb 26 22:13:10 loe go-librespot[2089]: time="2026-02-26T22:13:10+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:13:10 loe go-librespot[2089]: time="2026-02-26T22:13:10+01:00" level=debug msg="app state loaded" Feb 26 22:13:10 loe go-librespot[2089]: time="2026-02-26T22:13:10+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:13:10 loe sudo[2079]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:10 loe sudo[2086]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:11 loe upmpdcli[1389]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Feb 26 22:13:11 loe sudo[2096]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Feb 26 22:13:11 loe sudo[2096]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:11 loe go-librespot[2089]: time="2026-02-26T22:13:11+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:13:11 loe go-librespot[2089]: time="2026-02-26T22:13:11+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:13:11 loe go-librespot[2089]: time="2026-02-26T22:13:11+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:13:11 loe volumio[1251]: info: AccessToken refresher cron started for QOBUZ Feb 26 22:13:11 loe volumio[1251]: info: Adding QOBUZ REST API Endpoints Feb 26 22:13:11 loe go-librespot[2089]: time="2026-02-26T22:13:11+01:00" level=info msg="zeroconf server listening on port 39321" Feb 26 22:13:11 loe go-librespot[2089]: time="2026-02-26T22:13:11+01:00" level=debug msg="obtained new client token: AADymUO3q6yGN05wK+KgqJ1qjvNJh/OpgnVC95RJ/PAC0D79OIjVDg7xlsHq1QS+riyq+9uO26Jl4cCaAd7uonmJkAKUgF2TTidhXdvqmLXqiRebpFOngN7HQful/Wpi5xmAPC9X1W/Ww+c3XjRgSIuNArijye2yCkg186iO5FRcWPAFPxfWRcrRJQT/Akf5VLWw504V9wxxDfvJEAQsil+TTDTuIgAV92OgiqICX/ab/cDYnRSq+ddjEg==" Feb 26 22:13:11 loe systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Feb 26 22:13:11 loe sudo[2096]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:11 loe go-librespot[2089]: time="2026-02-26T22:13:11+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Feb 26 22:13:11 loe go-librespot[2089]: time="2026-02-26T22:13:11+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 26 22:13:11 loe go-librespot[2089]: time="2026-02-26T22:13:11+01:00" level=debug msg="completed keyexchange" Feb 26 22:13:11 loe go-librespot[2089]: time="2026-02-26T22:13:11+01:00" level=debug msg="completed challenge" Feb 26 22:13:11 loe go-librespot[2089]: time="2026-02-26T22:13:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:13:11 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:13:11 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:13:12 loe volumio[1251]: info: MRS: Getting audio outputs on start Feb 26 22:13:12 loe volumio[1251]: info: MRS: Requesting all other devices output Feb 26 22:13:12 loe volumio[1251]: info: Initializing connection to go-librespot Websocket Feb 26 22:13:12 loe volumio[1251]: info: BOOT COMPLETED Feb 26 22:13:13 loe volumio[1251]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Feb 26 22:13:13 loe volumio[1251]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Feb 26 22:13:13 loe volumio[1251]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Feb 26 22:13:13 loe volumio[1251]: info: MPD Permissions set Feb 26 22:13:13 loe sudo[2102]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Feb 26 22:13:13 loe sudo[2102]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:13 loe volumio[1251]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 22:13:14 loe systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Feb 26 22:13:14 loe sudo[2102]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:14 loe volumiobt[2106]: INFO [BTSTART] Ensuring Bluetooth directory exists... Feb 26 22:13:14 loe sudo[2107]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Feb 26 22:13:14 loe sudo[2107]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:14 loe sudo[2107]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:14 loe sudo[2109]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Feb 26 22:13:14 loe sudo[2109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:14 loe sudo[2109]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:14 loe volumiobt[2111]: INFO [BTSTART] Powering on Bluetooth if needed... Feb 26 22:13:14 loe bluetoothd[946]: Adv Monitor app :1.25 disconnected from D-Bus Feb 26 22:13:14 loe volumiobt[2114]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Feb 26 22:13:14 loe volumio[1251]: info: Executing endpoint qc_getconfig Feb 26 22:13:14 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Feb 26 22:13:14 loe volumiobt[2115]: [176B blob data] Feb 26 22:13:14 loe volumiobt[2115]: [157B blob data] Feb 26 22:13:14 loe volumiobt[2115]: [157B blob data] Feb 26 22:13:14 loe volumiobt[2115]: [157B blob data] Feb 26 22:13:14 loe volumiobt[2115]: [113B blob data] Feb 26 22:13:14 loe volumiobt[2115]: [bluetoothctl]> discoverable on Feb 26 22:13:14 loe volumiobt[2115]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended Feb 26 22:13:14 loe volumiobt[2115]: [bluetoothctl]> pairable on Feb 26 22:13:14 loe bluetoothd[946]: Path / reserved for Adv Monitor app :1.26 Feb 26 22:13:14 loe bluetoothd[946]: Adv Monitor app :1.26 disconnected from D-Bus Feb 26 22:13:14 loe volumiobt[2115]: [bluetoothctl]> Feb 26 22:13:14 loe volumiobt[2118]: INFO [BTSTART] Registering Bluetooth agent... Feb 26 22:13:14 loe volumiobt[2120]: [NEW] Media /org/bluez/hci0 Feb 26 22:13:14 loe volumiobt[2120]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Feb 26 22:13:14 loe volumiobt[2120]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Feb 26 22:13:14 loe volumiobt[2120]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Feb 26 22:13:14 loe bluetoothd[946]: Adv Monitor app :1.27 disconnected from D-Bus Feb 26 22:13:14 loe volumiobt[2122]: No agent is registered Feb 26 22:13:14 loe volumiobt[2122]: [NEW] Media /org/bluez/hci0 Feb 26 22:13:14 loe volumiobt[2122]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Feb 26 22:13:14 loe volumiobt[2122]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Feb 26 22:13:14 loe volumiobt[2122]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Feb 26 22:13:14 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 26 22:13:15 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:15 loe qobuz-connect[2100]: 20260226 22:13:15.023 [2100.2100] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Feb 26 22:13:15 loe bluetoothd[946]: Adv Monitor app :1.28 disconnected from D-Bus Feb 26 22:13:15 loe volumiobt[2124]: INFO [BTSTART] Agent registered successfully. Feb 26 22:13:15 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:15 loe go-librespot[2123]: go-librespot daemon starting... Feb 26 22:13:15 loe volumiobt[2126]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Feb 26 22:13:15 loe go-librespot[2125]: time="2026-02-26T22:13:15+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:13:15 loe go-librespot[2125]: time="2026-02-26T22:13:15+01:00" level=debug msg="app state loaded" Feb 26 22:13:15 loe go-librespot[2125]: time="2026-02-26T22:13:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:13:15 loe qobuz-connect[2100]: 20260226 22:13:15.263 [2100.2100] INFO VolumeManager: [0x1476408]: Setting new playback volume: 75 Feb 26 22:13:15 loe qobuz-connect[2100]: 20260226 22:13:15.263 [2100.2100] INFO VolumeManager: [0x1476408]: Setting new mute state: 0 Feb 26 22:13:15 loe qobuz-connect[2100]: 20260226 22:13:15.263 [2100.2100] INFO QobuzConnect: [0x1476dd8]: Client initialized! Feb 26 22:13:15 loe qobuz-connect[2100]: 20260226 22:13:15.263 [2100.2100] INFO SampleApp: Starting Avahi advertising, name: Loe, service name: _qobuz-connect._tcp Feb 26 22:13:15 loe qobuz-connect[2100]: 20260226 22:13:15.345 [2100.2100] INFO LocalConfigManager: [0x1475ce8]: Starting Local Configuration server Feb 26 22:13:15 loe qobuz-connect[2100]: 20260226 22:13:15.345 [2100.2100] INFO SampleApp: Starting Local configuration server Feb 26 22:13:15 loe qobuz-connect[2100]: 20260226 22:13:15.346 [2100.2100] INFO SampleApp: Playback volume changed: 75 Feb 26 22:13:15 loe qobuz-connect[2100]: 20260226 22:13:15.346 [2100.2100] INFO SampleApp: Connected to UNIX socket client 0x1460818 Feb 26 22:13:15 loe go-librespot[2125]: time="2026-02-26T22:13:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:13:15 loe go-librespot[2125]: time="2026-02-26T22:13:15+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:13:15 loe go-librespot[2125]: time="2026-02-26T22:13:15+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:13:15 loe go-librespot[2125]: time="2026-02-26T22:13:15+01:00" level=info msg="zeroconf server listening on port 32903" Feb 26 22:13:15 loe go-librespot[2125]: time="2026-02-26T22:13:15+01:00" level=debug msg="obtained new client token: AABBDOOFlqgqlaI4RIqJI+10k0LMrNnTjHd92sLqQCaanrLGvDcie8kiK6lxBcXbb92gwuNHHOlUcFHNuoFh+oT5LCKYc3hqBwsu/RA4XmP66oNETGlxuohTxY8Ohb40Yi/HPU2izHHX5fJSsHHQcsDyPlbwSJOyME/BJhNf0l5rWGQYN1BBkHBHzaERQjwBrm+c1+OBsRm47zLFkbn2mcgZXfe8K/pafsIe7pOGYq9G6gQQ3HYVnGsHnA==" Feb 26 22:13:16 loe go-librespot[2125]: time="2026-02-26T22:13:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:13:16 loe go-librespot[2125]: time="2026-02-26T22:13:16+01:00" level=debug msg="completed keyexchange" Feb 26 22:13:16 loe go-librespot[2125]: time="2026-02-26T22:13:16+01:00" level=debug msg="completed challenge" Feb 26 22:13:16 loe go-librespot[2125]: time="2026-02-26T22:13:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:13:16 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:13:16 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:13:16 loe volumio[1251]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Feb 26 22:13:16 loe volumio[1251]: info: QobuzConnect: QOBUZ Connect daemon connected Feb 26 22:13:16 loe volumio[1251]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Feb 26 22:13:16 loe volumio[1251]: info: CoreCommandRouter::volumioStop Feb 26 22:13:16 loe volumio[1251]: info: CoreStateMachine::stop Feb 26 22:13:16 loe volumio[1251]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:13:16 loe volumio[1251]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Feb 26 22:13:16 loe volumio[1251]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:13:16 loe volumio[1251]: info: TidalConnect service stoped! Feb 26 22:13:16 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:16 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:16 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:16 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:16 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:16 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:16 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:16 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:16 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:13:16 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:17 loe volumio[1251]: error: Hi Res Audio Failed Login: [object Object] Feb 26 22:13:17 loe volumio[1251]: info: Access Token successfully retrieved Feb 26 22:13:17 loe volumiobt[2132]: INFO:a2dp-agent:Connecting to system bus. Feb 26 22:13:17 loe volumio[1251]: error: updateQueue error: null Feb 26 22:13:17 loe volumiobt[2132]: INFO:a2dp-agent:Found Bluetooth adapter at: /org/bluez/hci0 Feb 26 22:13:17 loe volumiobt[2132]: INFO:a2dp-agent:Enabling infinite discovery on adapter. Feb 26 22:13:17 loe volumiobt[2132]: INFO:a2dp-agent:Registering agent. Feb 26 22:13:17 loe volumiobt[2132]: INFO:a2dp-agent:Searching for MediaPlayer1 interface... Feb 26 22:13:17 loe volumiobt[2132]: WARNING:a2dp-agent:No active MediaPlayer1 found. Metadata updates won't work. Feb 26 22:13:17 loe volumio[1251]: info: CoreCommandRouter::volumioGetState Feb 26 22:13:17 loe volumio[1251]: info: Initializing connection to go-librespot Websocket Feb 26 22:13:18 loe volumio[1251]: info: MRS: Found cast device: Chromecast-6441b8a26badb65de853f21771bb04b1 Feb 26 22:13:18 loe volumio[1251]: info: Adding audio output: Feb 26 22:13:18 loe volumio[1251]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 22:13:18 loe volumio[1251]: info: Starting Shairport Sync Feb 26 22:13:18 loe volumio[1251]: info: MRS: Found cast device: Chromecast-84d0dcfc86c31e08fb7722859cd1fe00 Feb 26 22:13:18 loe volumio[1251]: info: Adding audio output: Feb 26 22:13:19 loe sudo[2166]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 26 22:13:19 loe sudo[2166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:19 loe volumio[1251]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Feb 26 22:13:19 loe volumio[1251]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Feb 26 22:13:19 loe volumio[1251]: info: Preparing to generate the ALSA configuration file Feb 26 22:13:19 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 26 22:13:19 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:19 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:19 loe go-librespot[2168]: go-librespot daemon starting... Feb 26 22:13:19 loe systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 26 22:13:19 loe systemd[1]: shairport-sync.service: Deactivated successfully. Feb 26 22:13:19 loe systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 26 22:13:19 loe systemd[1]: shairport-sync.service: Consumed 2.514s CPU time. Feb 26 22:13:19 loe systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 26 22:13:19 loe sudo[2166]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:19 loe go-librespot[2169]: time="2026-02-26T22:13:19+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:13:19 loe go-librespot[2169]: time="2026-02-26T22:13:19+01:00" level=debug msg="app state loaded" Feb 26 22:13:19 loe go-librespot[2169]: time="2026-02-26T22:13:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:13:20 loe go-librespot[2169]: time="2026-02-26T22:13:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:13:20 loe go-librespot[2169]: time="2026-02-26T22:13:20+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:13:20 loe go-librespot[2169]: time="2026-02-26T22:13:20+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:13:20 loe go-librespot[2169]: time="2026-02-26T22:13:20+01:00" level=info msg="zeroconf server listening on port 34441" Feb 26 22:13:20 loe go-librespot[2169]: time="2026-02-26T22:13:20+01:00" level=debug msg="obtained new client token: AACJuDYRSk+qf9lS20H61O8YD+UvyIs+ca5uJeRAq9MvSC1PAqYvT4qpiej99rwbDvA4RCHnzC4/sCj96EyIZSQNijptvrLBMtHRQQooIU/naa4E7abUXH04BRw2vTxXFHPz5FK4eYF4eZhrvvIbB3JWa0BLY1tbRNtQ/Nht5xTpHyWSHxzNkV3KunBf3+B94J+BFCMRI3Oj6pcSqTYM7GVe2M5duu6F3zoPPvkRT8j1VxEaapT9XztdZg==" Feb 26 22:13:20 loe volumio[1251]: info: CoreCommandRouter::volumioGetState Feb 26 22:13:20 loe go-librespot[2169]: time="2026-02-26T22:13:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:13:20 loe go-librespot[2169]: time="2026-02-26T22:13:20+01:00" level=debug msg="completed keyexchange" Feb 26 22:13:20 loe go-librespot[2169]: time="2026-02-26T22:13:20+01:00" level=debug msg="completed challenge" Feb 26 22:13:20 loe go-librespot[2169]: time="2026-02-26T22:13:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:13:20 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:13:20 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:13:20 loe volumio[1251]: info: Successfully retrieved User Session From TIDAL Feb 26 22:13:20 loe volumio[1251]: info: Shairport-Sync Started Feb 26 22:13:21 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 26 22:13:21 loe volumio[1251]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.mjORZRjMx8YIlyGajvB2CXSYA5r2.a53384b16fd4d7a180fdac1b5068092c.state.status' Feb 26 22:13:21 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 26 22:13:21 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 26 22:13:21 loe volumio[1251]: info: Successfully retrieved User Subscription From TIDAL Feb 26 22:13:21 loe volumio[1251]: info: Adding TIDAL to Browse Sources Feb 26 22:13:21 loe sudo[2193]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Feb 26 22:13:21 loe sudo[2193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:21 loe volumio[1251]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 26 22:13:21 loe volumio[1251]: info: [1772140401324] CoreMusicLibrary::Adding element TIDAL Feb 26 22:13:21 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 22:13:21 loe volumio[1251]: Cannot find translation for source TIDAL Feb 26 22:13:21 loe volumio[1251]: info: Adding TIDAL REST API Endpoints Feb 26 22:13:21 loe volumio[1251]: info: Asound.conf file written Feb 26 22:13:21 loe systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Feb 26 22:13:21 loe sudo[2193]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:21 loe sudo[2198]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Feb 26 22:13:21 loe sudo[2198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:21 loe sudo[2198]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:22 loe volumio[1251]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Feb 26 22:13:22 loe volumio[1251]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Feb 26 22:13:22 loe volumio[1251]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Feb 26 22:13:22 loe volumio[1251]: No state is present for card vc4hdmi Feb 26 22:13:22 loe volumio[1251]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Feb 26 22:13:22 loe volumio[1251]: Found hardware: "vc4-hdmi" "" "" "" "" Feb 26 22:13:22 loe volumio[1251]: Hardware is initialized using a generic method Feb 26 22:13:22 loe volumio[1251]: No state is present for card vc4hdmi Feb 26 22:13:22 loe volumio[1251]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2 Feb 26 22:13:22 loe volumio[1251]: info: Output device has changed, restarting MPD Feb 26 22:13:22 loe volumio[1251]: info: Output device has changed, restarting Shairport Sync Feb 26 22:13:22 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:22 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:13:22 loe sudo[2206]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 26 22:13:22 loe sudo[2206]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:22 loe sudo[2208]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 26 22:13:22 loe sudo[2208]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:22 loe sudo[2206]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:22 loe volumio[1251]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 26 22:13:22 loe volumio[1251]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Feb 26 22:13:22 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:22 loe volumio[1251]: info: QobuzConnect: setDeactiveState invoked Feb 26 22:13:22 loe systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 26 22:13:23 loe upmpdcli[1389]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Feb 26 22:13:23 loe volumio[1251]: info: CoreCommandRouter::volumioGetState Feb 26 22:13:23 loe systemd[1]: mpd.service: Deactivated successfully. Feb 26 22:13:23 loe systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 26 22:13:23 loe systemd[1]: mpd.service: Consumed 5.541s CPU time. Feb 26 22:13:23 loe systemd[1]: mpd.socket: Deactivated successfully. Feb 26 22:13:23 loe systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 26 22:13:23 loe systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 26 22:13:23 loe volumio[1251]: info: Preparing to generate the ALSA configuration file Feb 26 22:13:23 loe systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 26 22:13:23 loe systemd[1]: Starting mpd.service - Music Player Daemon... Feb 26 22:13:23 loe sudo[2219]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Feb 26 22:13:23 loe sudo[2219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:23 loe sudo[2220]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 26 22:13:23 loe sudo[2220]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 26 22:13:23 loe sudo[2220]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:23 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 26 22:13:23 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:23 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:23 loe go-librespot[2232]: go-librespot daemon starting... Feb 26 22:13:23 loe systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Feb 26 22:13:23 loe systemd[1]: vtcs.service: Deactivated successfully. Feb 26 22:13:23 loe systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Feb 26 22:13:24 loe volumio[1251]: info: Initializing connection to go-librespot Websocket Feb 26 22:13:24 loe sudo[2219]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:24 loe sudo[2225]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Feb 26 22:13:24 loe sudo[2225]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:24 loe go-librespot[2233]: time="2026-02-26T22:13:24+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:13:24 loe go-librespot[2233]: time="2026-02-26T22:13:24+01:00" level=debug msg="app state loaded" Feb 26 22:13:24 loe go-librespot[2233]: time="2026-02-26T22:13:24+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:13:24 loe sudo[2225]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:24 loe sudo[2231]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Feb 26 22:13:24 loe sudo[2231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:24 loe volumio[1251]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Feb 26 22:13:24 loe volumio[1251]: info: Reading ALSA contributions from plugins. Feb 26 22:13:24 loe sudo[2231]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:24 loe volumio[1251]: info: MPD Permissions set Feb 26 22:13:24 loe go-librespot[2233]: time="2026-02-26T22:13:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:13:24 loe go-librespot[2233]: time="2026-02-26T22:13:24+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:13:24 loe go-librespot[2233]: time="2026-02-26T22:13:24+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:13:24 loe sudo[2246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Feb 26 22:13:24 loe sudo[2246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:24 loe go-librespot[2233]: time="2026-02-26T22:13:24+01:00" level=info msg="zeroconf server listening on port 35991" Feb 26 22:13:24 loe volumio[1251]: info: Executing endpoint tc_getconfig Feb 26 22:13:24 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Feb 26 22:13:25 loe go-librespot[2233]: time="2026-02-26T22:13:25+01:00" level=debug msg="new websocket client" Feb 26 22:13:25 loe systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Feb 26 22:13:25 loe go-librespot[2233]: time="2026-02-26T22:13:25+01:00" level=debug msg="obtained new client token: AADgBkH6EUgjvkey4j89uoU+aYE+eX/eb8DfM0LHwxtYnCuBhHQXjHJwABPGftGF37P1n+zn6TqHl1rZtqRpA4f8amQHQvbefWQ3OkqZDXxXeRbC6JzYocNBMM09VLvb/rvzeN5of4qJVIT0iwANC9RBNUhlUeyWhYSteg7npvqpw8OVv80/hJq+eLZujtMv+XNMmhX+VpEEup1P3TFjn7Vpj5ZRDLhsPy2ZdfNvwkyXSCTBf93OTRw=" Feb 26 22:13:25 loe qobuz-connect[2100]: 20260226 22:13:25.158 [2100.2100] INFO SampleApp: Stopping Local configuration server Feb 26 22:13:25 loe volumio[1251]: info: TidalConnect service started! Feb 26 22:13:25 loe go-librespot[2233]: time="2026-02-26T22:13:25+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:13:25 loe go-librespot[2233]: time="2026-02-26T22:13:25+01:00" level=debug msg="completed keyexchange" Feb 26 22:13:25 loe go-librespot[2233]: time="2026-02-26T22:13:25+01:00" level=debug msg="completed challenge" Feb 26 22:13:25 loe qobuz-connect[2100]: 20260226 22:13:25.382 [2100.2100] INFO SampleApp: shat down connection on UNIX socket Feb 26 22:13:25 loe systemd[1]: qobuz-connect.service: Deactivated successfully. Feb 26 22:13:25 loe systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Feb 26 22:13:25 loe go-librespot[2233]: time="2026-02-26T22:13:25+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:13:25 loe volumio[1251]: info: Connection to go-librespot Websocket established Feb 26 22:13:25 loe systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Feb 26 22:13:25 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:13:25 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:13:25 loe sudo[2246]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:25 loe volumio5-onboarding[1951]: failed to bootstrap state: failed to get available plugins: could not get available plugins: context deadline exceeded Feb 26 22:13:25 loe systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:13:25 loe systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Feb 26 22:13:25 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:25 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:25 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:26 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:26 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:26 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:26 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:26 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:26 loe systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 5. Feb 26 22:13:26 loe systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 26 22:13:26 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 22:13:26 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 26 22:13:26 loe systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 26 22:13:26 loe volumio5-onboarding[2254]: time=2026-02-26T22:13:26.455+01:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Feb 26 22:13:26 loe volumio[1251]: info: Connection to go-librespot Websocket closed Feb 26 22:13:26 loe volumio[1251]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Feb 26 22:13:26 loe volumio[1251]: info: QobuzConnect: setDeactiveState invoked Feb 26 22:13:26 loe volumio[1251]: info: CoreCommandRouter::volumioGetState Feb 26 22:13:26 loe volumio[1251]: info: Executing endpoint qc_getconfig Feb 26 22:13:26 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Feb 26 22:13:27 loe qobuz-connect[2248]: 20260226 22:13:27.166 [2248.2248] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Feb 26 22:13:27 loe qobuz-connect[2248]: 20260226 22:13:27.198 [2248.2248] INFO VolumeManager: [0x78a408]: Setting new playback volume: 75 Feb 26 22:13:27 loe qobuz-connect[2248]: 20260226 22:13:27.198 [2248.2248] INFO VolumeManager: [0x78a408]: Setting new mute state: 0 Feb 26 22:13:27 loe qobuz-connect[2248]: 20260226 22:13:27.198 [2248.2248] INFO QobuzConnect: [0x78add8]: Client initialized! Feb 26 22:13:27 loe qobuz-connect[2248]: 20260226 22:13:27.198 [2248.2248] INFO SampleApp: Starting Avahi advertising, name: Loe, service name: _qobuz-connect._tcp Feb 26 22:13:27 loe qobuz-connect[2248]: 20260226 22:13:27.252 [2248.2248] INFO LocalConfigManager: [0x789ce8]: Starting Local Configuration server Feb 26 22:13:27 loe qobuz-connect[2248]: 20260226 22:13:27.252 [2248.2248] INFO SampleApp: Starting Local configuration server Feb 26 22:13:27 loe qobuz-connect[2248]: 20260226 22:13:27.253 [2248.2248] INFO SampleApp: Connected to UNIX socket client 0x774818 Feb 26 22:13:27 loe volumio[1251]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Feb 26 22:13:27 loe volumio[1251]: info: QobuzConnect: QOBUZ Connect daemon connected Feb 26 22:13:27 loe qobuz-connect[2248]: 20260226 22:13:27.316 [2248.2248] INFO SampleApp: Playback volume changed: 75 Feb 26 22:13:27 loe volumio[1251]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Feb 26 22:13:27 loe volumio[1251]: info: Starting Shairport Sync Feb 26 22:13:27 loe volumio[1251]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Feb 26 22:13:27 loe volumio[1251]: info: Received Get System Info Feb 26 22:13:27 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 22:13:27 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 22:13:27 loe volumio[1251]: info: Discovery: Getting this device information Feb 26 22:13:27 loe volumio[1251]: info: CoreCommandRouter::volumioGetState Feb 26 22:13:27 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 22:13:27 loe volumio5-onboarding[2254]: time=2026-02-26T22:13:27.883+01:00 level=INFO msg="system info for a53384b16fd4d7a180fdac1b5068092c" deviceName=Loe deviceVariant=volumio deviceModel= softwareVersion=4.096 Feb 26 22:13:28 loe sudo[2270]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 26 22:13:28 loe volumio[1251]: info: CoreCommandRouter::volumioGetState Feb 26 22:13:28 loe sudo[2270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:28 loe volumio[1251]: info: TidalConnect service stoped! Feb 26 22:13:28 loe volumio[1251]: info: TidalConnect service stoped! Feb 26 22:13:28 loe volumio[1251]: info: Received Get System Info Feb 26 22:13:28 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Feb 26 22:13:28 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:28 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 22:13:28 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 22:13:28 loe volumio[1251]: info: Discovery: Getting this device information Feb 26 22:13:28 loe volumio[1251]: info: CoreCommandRouter::volumioGetState Feb 26 22:13:28 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 22:13:28 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:28 loe go-librespot[2289]: go-librespot daemon starting... Feb 26 22:13:28 loe systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 26 22:13:28 loe systemd[1]: shairport-sync.service: Deactivated successfully. Feb 26 22:13:28 loe systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 26 22:13:28 loe systemd[1]: shairport-sync.service: Consumed 1.522s CPU time. Feb 26 22:13:28 loe systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 26 22:13:28 loe sudo[2270]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:28 loe go-librespot[2290]: time="2026-02-26T22:13:28+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:13:28 loe go-librespot[2290]: time="2026-02-26T22:13:28+01:00" level=debug msg="app state loaded" Feb 26 22:13:28 loe go-librespot[2290]: time="2026-02-26T22:13:28+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:13:29 loe upmpdcli[1389]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Feb 26 22:13:29 loe upmpdcli[1389]: :2:../src/mpdcli.cxx:396::MPDCli::updStatus: connection failed Feb 26 22:13:29 loe upmpdcli[1389]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Feb 26 22:13:29 loe volumio[1251]: info: Getting Spotify volume Feb 26 22:13:29 loe go-librespot[2290]: time="2026-02-26T22:13:29+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:13:29 loe go-librespot[2290]: time="2026-02-26T22:13:29+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:13:29 loe go-librespot[2290]: time="2026-02-26T22:13:29+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:13:29 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 26 22:13:29 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 26 22:13:29 loe volumio5-onboarding[2254]: time=2026-02-26T22:13:29.607+01:00 level=INFO msg="enabling local network discovery" Feb 26 22:13:29 loe go-librespot[2290]: time="2026-02-26T22:13:29+01:00" level=info msg="zeroconf server listening on port 41767" Feb 26 22:13:29 loe volumio5-onboarding[2254]: time=2026-02-26T22:13:29.711+01:00 level=INFO msg="bootstrapping state" hasInternet=true Feb 26 22:13:29 loe go-librespot[2290]: time="2026-02-26T22:13:29+01:00" level=debug msg="obtained new client token: AAATQZS16B5fqG0z3trdlipgAC/k2muXy24JiuaESpnJV4eMYQKRrUfopJEQnujo5hxIdhNTX0Kiys/+xWpgfb+EkylsDI/yXK8EETntVyyzaLdhGhWQmAoEvli3CquwxrSsaNVqgn2yjkil/6wJtgzvn8dWZYsDYF+RiCOWQONg4Cn9jleE46GveVBVuy1jFFACDzqSZ1uKnkG868SSXV1IHdZbdiW/YhRvVEVCp7kp/mOHXqsWd78cTw==" Feb 26 22:13:29 loe volumio[1251]: info: Shairport-Sync Started Feb 26 22:13:29 loe go-librespot[2290]: time="2026-02-26T22:13:29+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Feb 26 22:13:29 loe go-librespot[2290]: time="2026-02-26T22:13:29+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 26 22:13:30 loe volumio[1251]: info: Initializing connection to go-librespot Websocket Feb 26 22:13:30 loe go-librespot[2290]: time="2026-02-26T22:13:30+01:00" level=debug msg="completed keyexchange" Feb 26 22:13:30 loe go-librespot[2290]: time="2026-02-26T22:13:30+01:00" level=debug msg="completed challenge" Feb 26 22:13:30 loe go-librespot[2290]: time="2026-02-26T22:13:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:13:30 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:13:30 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:13:30 loe mpd[2229]: 2026-02-26T22:13:30 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 26 22:13:30 loe systemd[1]: Started mpd.service - Music Player Daemon. Feb 26 22:13:30 loe volumio[1251]: info: Received Get System Info Feb 26 22:13:30 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 22:13:30 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 22:13:30 loe volumio[1251]: info: Discovery: Getting this device information Feb 26 22:13:30 loe volumio[1251]: info: CoreCommandRouter::volumioGetState Feb 26 22:13:30 loe volumio[1251]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 22:13:30 loe sudo[2208]: pam_unix(sudo:session): session closed for user root Feb 26 22:13:30 loe volumio-remote-updater[708]: Test mode disabled Feb 26 22:13:30 loe volumio-remote-updater[708]: Alpha mode disabled Feb 26 22:13:30 loe volumio-remote-updater[708]: Alpha legacy test mode disabled Feb 26 22:13:30 loe volumio[1251]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 22:13:30 loe volumio[1251]: Error: socket hang up Feb 26 22:13:30 loe volumio[1251]: at connResetException (node:internal/errors:720:14) Feb 26 22:13:30 loe volumio[1251]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 26 22:13:30 loe volumio[1251]: at Socket.emit (node:events:526:35) Feb 26 22:13:30 loe volumio[1251]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 26 22:13:30 loe volumio[1251]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 26 22:13:30 loe volumio[1251]: code: 'ECONNRESET', Feb 26 22:13:30 loe volumio[1251]: response: undefined Feb 26 22:13:30 loe volumio[1251]: } Feb 26 22:13:30 loe volumio[1251]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 22:13:31 loe upmpdcli[1389]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Feb 26 22:13:33 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Feb 26 22:13:33 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:33 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:33 loe go-librespot[2335]: go-librespot daemon starting... Feb 26 22:13:33 loe go-librespot[2336]: time="2026-02-26T22:13:33+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:13:33 loe go-librespot[2336]: time="2026-02-26T22:13:33+01:00" level=debug msg="app state loaded" Feb 26 22:13:33 loe go-librespot[2336]: time="2026-02-26T22:13:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:13:34 loe go-librespot[2336]: time="2026-02-26T22:13:34+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:13:34 loe go-librespot[2336]: time="2026-02-26T22:13:34+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:13:34 loe go-librespot[2336]: time="2026-02-26T22:13:34+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:13:34 loe go-librespot[2336]: time="2026-02-26T22:13:34+01:00" level=info msg="zeroconf server listening on port 34233" Feb 26 22:13:34 loe go-librespot[2336]: time="2026-02-26T22:13:34+01:00" level=debug msg="obtained new client token: AAAVEbAXYJ7BuVRTCXZCn4mWR9fXfcuBQqe4vmju0WsU5+XjYqCqB3V8zWV8A6ecQ9ljVLkcpCszv+vFrAWTmo+CBOINelAF2tZkCD6FKCPfJ2WaEsm5mlhsYFPZrfTUXY9k83/aYQURsuMBdbM96+WjiFfveGgE2zBREMyqdK8D2F9fqJLmeosf3mgv3MjZDEXG/zoy/7tgL8K6p5WS7MLSkGyZYnk0O64GH3d0v7/qfhpF5uYG5v8=" Feb 26 22:13:34 loe go-librespot[2336]: time="2026-02-26T22:13:34+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:13:34 loe go-librespot[2336]: time="2026-02-26T22:13:34+01:00" level=debug msg="completed keyexchange" Feb 26 22:13:34 loe go-librespot[2336]: time="2026-02-26T22:13:34+01:00" level=debug msg="completed challenge" Feb 26 22:13:34 loe go-librespot[2336]: time="2026-02-26T22:13:34+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:13:34 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:13:34 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:13:37 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Feb 26 22:13:37 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:37 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:37 loe go-librespot[2345]: go-librespot daemon starting... Feb 26 22:13:37 loe go-librespot[2346]: time="2026-02-26T22:13:37+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:13:37 loe go-librespot[2346]: time="2026-02-26T22:13:37+01:00" level=debug msg="app state loaded" Feb 26 22:13:37 loe go-librespot[2346]: time="2026-02-26T22:13:37+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:13:38 loe go-librespot[2346]: time="2026-02-26T22:13:38+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:13:38 loe go-librespot[2346]: time="2026-02-26T22:13:38+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:13:38 loe go-librespot[2346]: time="2026-02-26T22:13:38+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:13:38 loe go-librespot[2346]: time="2026-02-26T22:13:38+01:00" level=info msg="zeroconf server listening on port 34255" Feb 26 22:13:38 loe go-librespot[2346]: time="2026-02-26T22:13:38+01:00" level=debug msg="obtained new client token: AADmxpTEICcSE7AjLeoH6II5GZR6I85a8rL+YmqhuDexk7hOZ0w8hyMZI0D4vlzasaR1FeO9Ju3AO3W922lFFVD1Tsd4XFcFFPtE0wZl8Ulem3KpHpAi+bmOAc7QPHX1hT8HVruAEF5R47Xc12ndezIjml9WBSujt/9PsiYUySHz9VmtctY58DWqBhWSADMf46ygdYL7JJazpuGMUuYrvwW3b+MfHRhiMf8FZno3vw9a+2QRoyNrXsIJCw==" Feb 26 22:13:38 loe go-librespot[2346]: time="2026-02-26T22:13:38+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:13:38 loe go-librespot[2346]: time="2026-02-26T22:13:38+01:00" level=debug msg="completed keyexchange" Feb 26 22:13:38 loe go-librespot[2346]: time="2026-02-26T22:13:38+01:00" level=debug msg="completed challenge" Feb 26 22:13:38 loe go-librespot[2346]: time="2026-02-26T22:13:38+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:13:38 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:13:38 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 22:13:41 loe sudo[2371]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-26 22:12' Feb 26 22:13:41 loe sudo[2371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 22:13:41 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Feb 26 22:13:41 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:42 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 22:13:42 loe go-librespot[2373]: go-librespot daemon starting... Feb 26 22:13:42 loe go-librespot[2374]: time="2026-02-26T22:13:42+01:00" level=info msg="running go-librespot 0.4.0" Feb 26 22:13:42 loe go-librespot[2374]: time="2026-02-26T22:13:42+01:00" level=debug msg="app state loaded" Feb 26 22:13:42 loe go-librespot[2374]: time="2026-02-26T22:13:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 22:13:42 loe go-librespot[2374]: time="2026-02-26T22:13:42+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 22:13:42 loe go-librespot[2374]: time="2026-02-26T22:13:42+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 22:13:42 loe go-librespot[2374]: time="2026-02-26T22:13:42+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 22:13:42 loe go-librespot[2374]: time="2026-02-26T22:13:42+01:00" level=info msg="zeroconf server listening on port 44175" Feb 26 22:13:42 loe go-librespot[2374]: time="2026-02-26T22:13:42+01:00" level=debug msg="obtained new client token: AABWJtBcb1vNCK1wBZx2b8jUbq0tVhwakQ3R62sBve4lzD7PxBtWkB1muDI4Ktl/OFKC48haOO9q2pz4blSSEB7mdYWPSGCillLAkKBztsbXFo4NJMzt9q1iX1Muc5I8a1CwGywOjLClPy8x2uKRNb5pexwvS7HKiUh8LwxYtms1fdLryxjsXdAxnbiiYc8txKMVYkQcare423fkWLyUnRsOnU9RhMEmkfnHJe1oLc4asJZVa0gn2lXKgg==" Feb 26 22:13:42 loe go-librespot[2374]: time="2026-02-26T22:13:42+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 22:13:42 loe go-librespot[2374]: time="2026-02-26T22:13:42+01:00" level=debug msg="completed keyexchange" Feb 26 22:13:42 loe go-librespot[2374]: time="2026-02-26T22:13:42+01:00" level=debug msg="completed challenge" Feb 26 22:13:42 loe go-librespot[2374]: time="2026-02-26T22:13:42+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 26 22:13:42 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 22:13:42 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"