-- Logs begin at Thu 2019-02-14 19:11:58 KST, end at Sat 2025-07-05 15:15:59 KST. -- Jul 05 15:14:02 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:14:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:14:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 94. Jul 05 15:14:02 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:14:02 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:02 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:02 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:14:02 volumio go-librespot[3200]: go-librespot daemon starting... Jul 05 15:14:02 volumio go-librespot[3200]: time="2025-07-05T15:14:02+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:14:02 volumio go-librespot[3200]: time="2025-07-05T15:14:02+09:00" level=debug msg="app state loaded" Jul 05 15:14:02 volumio go-librespot[3200]: time="2025-07-05T15:14:02+09:00" level=debug msg="stored credentials not found" Jul 05 15:14:02 volumio go-librespot[3200]: time="2025-07-05T15:14:02+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:14:03 volumio go-librespot[3200]: time="2025-07-05T15:14:03+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:14:03 volumio go-librespot[3200]: time="2025-07-05T15:14:03+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:14:03 volumio go-librespot[3200]: time="2025-07-05T15:14:03+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:14:03 volumio go-librespot[3200]: time="2025-07-05T15:14:03+09:00" level=info msg="zeroconf server listening on port 40651" Jul 05 15:14:03 volumio go-librespot[3200]: time="2025-07-05T15:14:03+09:00" level=debug msg="obtained new client token: AACdR+OEXadjj0aGBOMSh0/T9VrGf9VTwCeraJBPR/b+Hq66j3lIi04W0OiOT2huCQjXPQld+hMfYElaTDEE8w7EmRsjvTA03ZebfCItcqOCOj46C/VWDEMvozw2ZPSfjQSoNjl8r1VqEMEkCUMpVdho2b88A6dq7mNlloDEHk32NoOpx6nrnPeM+j8cU+r3Zi7G0ccqcL5/qqV9Fpf2P1VgNipwDF8XD71E4RAp3RSU5G0RyuFw1FUl" Jul 05 15:14:03 volumio go-librespot[3200]: time="2025-07-05T15:14:03+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:14:03 volumio go-librespot[3200]: time="2025-07-05T15:14:03+09:00" level=debug msg="completed keyexchange" Jul 05 15:14:03 volumio go-librespot[3200]: time="2025-07-05T15:14:03+09:00" level=debug msg="completed challenge" Jul 05 15:14:03 volumio go-librespot[3200]: time="2025-07-05T15:14:03+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:14:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:14:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:14:05 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jul 05 15:14:05 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jul 05 15:14:05 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:05 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:06 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:14:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:14:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 95. Jul 05 15:14:06 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:14:06 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:14:06 volumio go-librespot[3210]: go-librespot daemon starting... Jul 05 15:14:06 volumio go-librespot[3210]: time="2025-07-05T15:14:06+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:14:06 volumio go-librespot[3210]: time="2025-07-05T15:14:06+09:00" level=debug msg="app state loaded" Jul 05 15:14:06 volumio go-librespot[3210]: time="2025-07-05T15:14:06+09:00" level=debug msg="stored credentials not found" Jul 05 15:14:06 volumio go-librespot[3210]: time="2025-07-05T15:14:06+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:14:06 volumio go-librespot[3210]: time="2025-07-05T15:14:06+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:14:06 volumio go-librespot[3210]: time="2025-07-05T15:14:06+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:14:06 volumio go-librespot[3210]: time="2025-07-05T15:14:06+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:14:06 volumio go-librespot[3210]: time="2025-07-05T15:14:06+09:00" level=info msg="zeroconf server listening on port 45881" Jul 05 15:14:06 volumio go-librespot[3210]: time="2025-07-05T15:14:06+09:00" level=debug msg="obtained new client token: AAAULBXatkeTVT/qITwFNhl8xo6gFPn6pywy+/yxexjsyn21G2N9ttaKFs0bH4EeL+Oft4kUNavxWSMGSR+t/4rV4o6d/TpsekeaJfy1yRhmLwaKhjhfYJUltBgHrEdEH15hYWo7+zmFcaPSFMiLJ2QF+8D3mhMdhuCKnBAfzwFsz6gylzrhRuWXVCzboG91XQB79TPJGhTHtMJIv7Ftxf9t0MqxgS9FtdviFMZiQLNu/BDV+qmVfAhwByA=" Jul 05 15:14:06 volumio go-librespot[3210]: time="2025-07-05T15:14:06+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:14:07 volumio go-librespot[3210]: time="2025-07-05T15:14:07+09:00" level=debug msg="completed keyexchange" Jul 05 15:14:07 volumio go-librespot[3210]: time="2025-07-05T15:14:07+09:00" level=debug msg="completed challenge" Jul 05 15:14:07 volumio go-librespot[3210]: time="2025-07-05T15:14:07+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:14:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:14:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:14:08 volumio ntpd[817]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jul 05 15:14:08 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:08 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:14:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 96. Jul 05 15:14:10 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:14:10 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:14:10 volumio go-librespot[3220]: go-librespot daemon starting... Jul 05 15:14:10 volumio go-librespot[3220]: time="2025-07-05T15:14:10+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:14:10 volumio go-librespot[3220]: time="2025-07-05T15:14:10+09:00" level=debug msg="app state loaded" Jul 05 15:14:10 volumio go-librespot[3220]: time="2025-07-05T15:14:10+09:00" level=debug msg="stored credentials not found" Jul 05 15:14:10 volumio go-librespot[3220]: time="2025-07-05T15:14:10+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:14:10 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:14:10 volumio go-librespot[3220]: time="2025-07-05T15:14:10+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:14:10 volumio go-librespot[3220]: time="2025-07-05T15:14:10+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:14:10 volumio go-librespot[3220]: time="2025-07-05T15:14:10+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:14:10 volumio go-librespot[3220]: time="2025-07-05T15:14:10+09:00" level=info msg="zeroconf server listening on port 44753" Jul 05 15:14:10 volumio go-librespot[3220]: time="2025-07-05T15:14:10+09:00" level=debug msg="obtained new client token: AACNxZ+yGrEYQH0kJSGjaP6x6urM/xrwYR0HNgc0d8siOJeS6zaBknLtH6q6GQIjv7f//tvYNJtmgcRChIBwhnFPUTc6GE8klZpIXiGD5ynErZZh1htLeRL2GUaBOJAvtfLqg2JcX+twa4j+Y7F4E2eCqH6w/Dj4qvEit1TMrxBn/7sdPt65Vc5MMS0Jb77/8RjWU6ZdZ73xzJZeqeHaQrbPVrMNkTxlgUt7L57NOU8stXtSJDq/1/Cvon8=" Jul 05 15:14:10 volumio go-librespot[3220]: time="2025-07-05T15:14:10+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:14:10 volumio go-librespot[3220]: time="2025-07-05T15:14:10+09:00" level=debug msg="completed keyexchange" Jul 05 15:14:10 volumio go-librespot[3220]: time="2025-07-05T15:14:10+09:00" level=debug msg="completed challenge" Jul 05 15:14:10 volumio go-librespot[3220]: time="2025-07-05T15:14:10+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:14:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:14:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:14:11 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:11 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:14:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 97. Jul 05 15:14:14 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:14:14 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:14:14 volumio go-librespot[3241]: go-librespot daemon starting... Jul 05 15:14:14 volumio go-librespot[3241]: time="2025-07-05T15:14:14+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:14:14 volumio go-librespot[3241]: time="2025-07-05T15:14:14+09:00" level=debug msg="app state loaded" Jul 05 15:14:14 volumio go-librespot[3241]: time="2025-07-05T15:14:14+09:00" level=debug msg="stored credentials not found" Jul 05 15:14:14 volumio go-librespot[3241]: time="2025-07-05T15:14:14+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:14:14 volumio go-librespot[3241]: time="2025-07-05T15:14:14+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:14:14 volumio go-librespot[3241]: time="2025-07-05T15:14:14+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:14:14 volumio go-librespot[3241]: time="2025-07-05T15:14:14+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:14:14 volumio go-librespot[3241]: time="2025-07-05T15:14:14+09:00" level=info msg="zeroconf server listening on port 42505" Jul 05 15:14:14 volumio go-librespot[3241]: time="2025-07-05T15:14:14+09:00" level=debug msg="obtained new client token: AAD5C8seSBHmGwyDCybIu4O0KSwvtSG6FkBtAJPPBGDc7Xlentf/eFIWdytOe4dGgzMhj89aeCkOo4/35AwUL5PQK/ZzVM6hmM8v5ySHu2DlhYUVXfjjMntzfyT3IAb3FvrTe1W1MNZRHWr8P6xDXWTQDNst49l1Vo5Os3jZaq/mAALxlr18hF5Aiww7Oxs7E/id6qhDIMrh5Fe428Gc6enresMT1b6JzFSlcdm1agSumZwc2iD9MQIc46w=" Jul 05 15:14:14 volumio go-librespot[3241]: time="2025-07-05T15:14:14+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:14:14 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:14:14 volumio go-librespot[3241]: time="2025-07-05T15:14:14+09:00" level=debug msg="completed keyexchange" Jul 05 15:14:14 volumio go-librespot[3241]: time="2025-07-05T15:14:14+09:00" level=debug msg="completed challenge" Jul 05 15:14:14 volumio go-librespot[3241]: time="2025-07-05T15:14:14+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:14:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:14:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:14:14 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:14 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:14:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 98. Jul 05 15:14:17 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:14:17 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:14:17 volumio go-librespot[3249]: go-librespot daemon starting... Jul 05 15:14:17 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:17 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:17 volumio go-librespot[3249]: time="2025-07-05T15:14:17+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:14:17 volumio go-librespot[3249]: time="2025-07-05T15:14:17+09:00" level=debug msg="app state loaded" Jul 05 15:14:17 volumio go-librespot[3249]: time="2025-07-05T15:14:17+09:00" level=debug msg="stored credentials not found" Jul 05 15:14:17 volumio go-librespot[3249]: time="2025-07-05T15:14:17+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:14:18 volumio go-librespot[3249]: time="2025-07-05T15:14:18+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:14:18 volumio go-librespot[3249]: time="2025-07-05T15:14:18+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:14:18 volumio go-librespot[3249]: time="2025-07-05T15:14:18+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:14:18 volumio go-librespot[3249]: time="2025-07-05T15:14:18+09:00" level=info msg="zeroconf server listening on port 44669" Jul 05 15:14:18 volumio go-librespot[3249]: time="2025-07-05T15:14:18+09:00" level=debug msg="obtained new client token: AADhX50lcb1WhoOHqW0Cq36NOUX0ITABtzQI+tYIIrlecqG3OpWuqYD7X02da0ms3+Q6ZMGT1ksNMmzceeHsrwsDdEBJ1jrUpMwDaDnz1WD7L1Ktmqry4n4GtjTNCcmZxc/VanZD7XikyxsaDVO+7AzfWrRLxOuoaKhtKzy6UWkB2zVZphAd8eo1YVQE38/hx+hgO4XTpepWeOolVA4JUx36YQsAIoF4Q/BjsRD5Ggn7ZSevL+Ol9+On" Jul 05 15:14:18 volumio go-librespot[3249]: time="2025-07-05T15:14:18+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:14:18 volumio go-librespot[3249]: time="2025-07-05T15:14:18+09:00" level=debug msg="completed keyexchange" Jul 05 15:14:18 volumio go-librespot[3249]: time="2025-07-05T15:14:18+09:00" level=debug msg="completed challenge" Jul 05 15:14:18 volumio go-librespot[3249]: time="2025-07-05T15:14:18+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:14:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:14:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:14:18 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 05 15:14:18 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 05 15:14:18 volumio volumio[856]: info: Discovery: Getting this device information Jul 05 15:14:18 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Jul 05 15:14:18 volumio volumio[856]: info: CorePlayQueue::getTrack 0 Jul 05 15:14:18 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 05 15:14:18 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:14:20 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:20 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:14:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99. Jul 05 15:14:21 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:14:21 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:14:21 volumio go-librespot[3271]: go-librespot daemon starting... Jul 05 15:14:21 volumio go-librespot[3271]: time="2025-07-05T15:14:21+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:14:21 volumio go-librespot[3271]: time="2025-07-05T15:14:21+09:00" level=debug msg="app state loaded" Jul 05 15:14:21 volumio go-librespot[3271]: time="2025-07-05T15:14:21+09:00" level=debug msg="stored credentials not found" Jul 05 15:14:21 volumio go-librespot[3271]: time="2025-07-05T15:14:21+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:14:21 volumio go-librespot[3271]: time="2025-07-05T15:14:21+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:14:21 volumio go-librespot[3271]: time="2025-07-05T15:14:21+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:14:21 volumio go-librespot[3271]: time="2025-07-05T15:14:21+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:14:21 volumio go-librespot[3271]: time="2025-07-05T15:14:21+09:00" level=info msg="zeroconf server listening on port 45011" Jul 05 15:14:21 volumio go-librespot[3271]: time="2025-07-05T15:14:21+09:00" level=debug msg="obtained new client token: AABcd4U39hn/2cHldOvlNPQCAdkWRqxhaMuSXF02A49sf5EpdA56/RfUz5R0V28HpeavRKpDfRfzxgQrMu6ZbYO8MOxIuDyiGXZPIOJpjSiLVSB1ThIkMxpdp4TVP8DpjW460fc3Ck4mtokKNSV6DR61yOPFPvwsRhzvk0CvkIWkuEPkBYcsHTIkLcXHasKmgLI3V81eDiDVSas0tFdjT/c9kNHbNEfxQTSfYe8MXM/1RyewDie/ro/RsBU=" Jul 05 15:14:21 volumio go-librespot[3271]: time="2025-07-05T15:14:21+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:14:22 volumio go-librespot[3271]: time="2025-07-05T15:14:22+09:00" level=debug msg="completed keyexchange" Jul 05 15:14:22 volumio go-librespot[3271]: time="2025-07-05T15:14:22+09:00" level=debug msg="completed challenge" Jul 05 15:14:22 volumio go-librespot[3271]: time="2025-07-05T15:14:22+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:14:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:14:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:14:22 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:14:23 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:23 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:14:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 100. Jul 05 15:14:25 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:14:25 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:14:25 volumio go-librespot[3279]: go-librespot daemon starting... Jul 05 15:14:25 volumio go-librespot[3279]: time="2025-07-05T15:14:25+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:14:25 volumio go-librespot[3279]: time="2025-07-05T15:14:25+09:00" level=debug msg="app state loaded" Jul 05 15:14:25 volumio go-librespot[3279]: time="2025-07-05T15:14:25+09:00" level=debug msg="stored credentials not found" Jul 05 15:14:25 volumio go-librespot[3279]: time="2025-07-05T15:14:25+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:14:25 volumio go-librespot[3279]: time="2025-07-05T15:14:25+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 05 15:14:25 volumio go-librespot[3279]: time="2025-07-05T15:14:25+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jul 05 15:14:25 volumio go-librespot[3279]: time="2025-07-05T15:14:25+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jul 05 15:14:25 volumio go-librespot[3279]: time="2025-07-05T15:14:25+09:00" level=info msg="zeroconf server listening on port 34755" Jul 05 15:14:25 volumio go-librespot[3279]: time="2025-07-05T15:14:25+09:00" level=debug msg="obtained new client token: AACVPJwK6J9HYmUf9WLsi6gHU2oBCGZBGFk3Ts+0q6envenznN8U8fD8oIYpnc8M02qeLwPUpt3argXboBQNJuXujtYFql8AyNWk4ZOVMaz8hoqkRjXp3mpyl5JyZA/gT9+6OWS0vSBzi2EVHC99QRt2M5BRUd7JtGPHOTdSXKIimCP//BeWFGl0q90S4iwiO94s2prYSaLsAbPRMMw23u4tVs5UTXi7MIIxyMwqsoQoF6CSBqjsv/4HaIs=" Jul 05 15:14:25 volumio go-librespot[3279]: time="2025-07-05T15:14:25+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:14:25 volumio go-librespot[3279]: time="2025-07-05T15:14:25+09:00" level=debug msg="completed keyexchange" Jul 05 15:14:25 volumio go-librespot[3279]: time="2025-07-05T15:14:25+09:00" level=debug msg="completed challenge" Jul 05 15:14:25 volumio go-librespot[3279]: time="2025-07-05T15:14:25+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:14:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:14:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:14:26 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:14:26 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:26 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:14:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 101. Jul 05 15:14:29 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:14:29 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:14:29 volumio go-librespot[3290]: go-librespot daemon starting... Jul 05 15:14:29 volumio go-librespot[3290]: time="2025-07-05T15:14:29+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:14:29 volumio go-librespot[3290]: time="2025-07-05T15:14:29+09:00" level=debug msg="app state loaded" Jul 05 15:14:29 volumio go-librespot[3290]: time="2025-07-05T15:14:29+09:00" level=debug msg="stored credentials not found" Jul 05 15:14:29 volumio go-librespot[3290]: time="2025-07-05T15:14:29+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:14:29 volumio go-librespot[3290]: time="2025-07-05T15:14:29+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:14:29 volumio go-librespot[3290]: time="2025-07-05T15:14:29+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:14:29 volumio go-librespot[3290]: time="2025-07-05T15:14:29+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:14:29 volumio go-librespot[3290]: time="2025-07-05T15:14:29+09:00" level=info msg="zeroconf server listening on port 39945" Jul 05 15:14:29 volumio go-librespot[3290]: time="2025-07-05T15:14:29+09:00" level=debug msg="obtained new client token: AAAei2YMavFHN/V/U8P9kpbL9fBEFpkbQFBSXxpACPgo1ilWsql88adpuj/BK0dCdG85CxbXadaMlnZg37KY/FueNQoa7VQQGX2sCYtL4IPpdgUQIkIqLG0bafRxtDJABThaXU6lYbJUSYBIhe48VSn33zvjSTiU+79WoXWNvrhUpN3y1QxExsEMAAHjv3CTqtI4RJmlZq8/48+7caK07i6IGvgPQlZzUe7h/J7hLscwDKjZfMcHK/ZOOFw=" Jul 05 15:14:29 volumio go-librespot[3290]: time="2025-07-05T15:14:29+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:14:29 volumio go-librespot[3290]: time="2025-07-05T15:14:29+09:00" level=debug msg="completed keyexchange" Jul 05 15:14:29 volumio go-librespot[3290]: time="2025-07-05T15:14:29+09:00" level=debug msg="completed challenge" Jul 05 15:14:29 volumio go-librespot[3290]: time="2025-07-05T15:14:29+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:14:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:14:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:14:29 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:29 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:30 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:14:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:14:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 102. Jul 05 15:14:32 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:14:32 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:14:32 volumio go-librespot[3312]: go-librespot daemon starting... Jul 05 15:14:32 volumio go-librespot[3312]: time="2025-07-05T15:14:32+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:14:32 volumio go-librespot[3312]: time="2025-07-05T15:14:32+09:00" level=debug msg="app state loaded" Jul 05 15:14:32 volumio go-librespot[3312]: time="2025-07-05T15:14:32+09:00" level=debug msg="stored credentials not found" Jul 05 15:14:32 volumio go-librespot[3312]: time="2025-07-05T15:14:32+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:14:32 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:32 volumio go-librespot[3312]: time="2025-07-05T15:14:32+09:00" level=debug msg="new websocket client" Jul 05 15:14:32 volumio volumio[856]: info: Connection to go-librespot Websocket established Jul 05 15:14:33 volumio go-librespot[3312]: time="2025-07-05T15:14:33+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:14:33 volumio go-librespot[3312]: time="2025-07-05T15:14:33+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:14:33 volumio go-librespot[3312]: time="2025-07-05T15:14:33+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:14:33 volumio go-librespot[3312]: time="2025-07-05T15:14:33+09:00" level=info msg="zeroconf server listening on port 40453" Jul 05 15:14:33 volumio go-librespot[3312]: time="2025-07-05T15:14:33+09:00" level=debug msg="obtained new client token: AADdM1tkg+R6Vyit0cyWx9KM9WhrkkwEDihlxCXwaf3bjMtgD06M3vTM8zhR2BDXisNEDvR9lremmUUxNkzdCMvFz+dCtd0b3wpLUVoDZGbhm8WUPqdr4ZkQ5+3w6R17uRyQ3cA1ra+lD/oniSwiHuk8RZ4o9M4Hb4Bbq6iBLo4qHUR4dIVFdfwYhgev7YmMFly+Xe6+KWqtad2lXv0Ef/lAfo5vJouGaYtLiCfzGoBcmSKSqBUsV6rz" Jul 05 15:14:33 volumio go-librespot[3312]: time="2025-07-05T15:14:33+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:14:33 volumio go-librespot[3312]: time="2025-07-05T15:14:33+09:00" level=debug msg="completed keyexchange" Jul 05 15:14:33 volumio go-librespot[3312]: time="2025-07-05T15:14:33+09:00" level=debug msg="completed challenge" Jul 05 15:14:33 volumio go-librespot[3312]: time="2025-07-05T15:14:33+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:14:33 volumio volumio[856]: info: Connection to go-librespot Websocket closed Jul 05 15:14:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:14:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:14:34 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:14:35 volumio volumio[856]: info: Getting Spotify volume Jul 05 15:14:35 volumio volumio[856]: (node:856) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:35 volumio volumio[856]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jul 05 15:14:35 volumio volumio[856]: (node:856) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 6) Jul 05 15:14:35 volumio volumio[856]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jul 05 15:14:35 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Jul 05 15:14:35 volumio volumio[856]: info: CorePlayQueue::getTrack 0 Jul 05 15:14:36 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:36 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:14:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 103. Jul 05 15:14:36 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:14:36 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:14:36 volumio go-librespot[3320]: go-librespot daemon starting... Jul 05 15:14:36 volumio go-librespot[3320]: time="2025-07-05T15:14:36+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:14:36 volumio go-librespot[3320]: time="2025-07-05T15:14:36+09:00" level=debug msg="app state loaded" Jul 05 15:14:36 volumio go-librespot[3320]: time="2025-07-05T15:14:36+09:00" level=debug msg="stored credentials not found" Jul 05 15:14:36 volumio go-librespot[3320]: time="2025-07-05T15:14:36+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:14:36 volumio go-librespot[3320]: time="2025-07-05T15:14:36+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:14:36 volumio go-librespot[3320]: time="2025-07-05T15:14:36+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:14:36 volumio go-librespot[3320]: time="2025-07-05T15:14:36+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:14:36 volumio go-librespot[3320]: time="2025-07-05T15:14:36+09:00" level=info msg="zeroconf server listening on port 46263" Jul 05 15:14:36 volumio go-librespot[3320]: time="2025-07-05T15:14:36+09:00" level=debug msg="obtained new client token: AAA1FBDk2SNIb0sTi0LF0HglJvuahNJ/cf1EHiE6Sb6L4TFOdQtStDcLCI70SUuZzj5MPe/QTDeyiQ1E5+kXyoVxkORf1Fzk5IeC4bbZL7Qkgp9K5zN+phOQqaCdSI18BMv9ud5Jf1Rv+tIghXpKBJoU+zYVTMTfQ0T6IOu36/1Xp0IGUYKq5zOUEY5moEX/rkk9aN3DSxpXeBczRDV2ZyAYbB9gmx3sXL0uFi2nIrO0aG1Q3FqZy69FoWI=" Jul 05 15:14:36 volumio go-librespot[3320]: time="2025-07-05T15:14:36+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:14:37 volumio go-librespot[3320]: time="2025-07-05T15:14:37+09:00" level=debug msg="completed keyexchange" Jul 05 15:14:37 volumio go-librespot[3320]: time="2025-07-05T15:14:37+09:00" level=debug msg="completed challenge" Jul 05 15:14:37 volumio go-librespot[3320]: time="2025-07-05T15:14:37+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:14:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:14:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:14:38 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:14:39 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:39 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:14:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 104. Jul 05 15:14:40 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:14:40 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:14:40 volumio go-librespot[3327]: go-librespot daemon starting... Jul 05 15:14:40 volumio go-librespot[3327]: time="2025-07-05T15:14:40+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:14:40 volumio go-librespot[3327]: time="2025-07-05T15:14:40+09:00" level=debug msg="app state loaded" Jul 05 15:14:40 volumio go-librespot[3327]: time="2025-07-05T15:14:40+09:00" level=debug msg="stored credentials not found" Jul 05 15:14:40 volumio go-librespot[3327]: time="2025-07-05T15:14:40+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:14:40 volumio go-librespot[3327]: time="2025-07-05T15:14:40+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:14:40 volumio go-librespot[3327]: time="2025-07-05T15:14:40+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:14:40 volumio go-librespot[3327]: time="2025-07-05T15:14:40+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:14:40 volumio go-librespot[3327]: time="2025-07-05T15:14:40+09:00" level=info msg="zeroconf server listening on port 38081" Jul 05 15:14:40 volumio go-librespot[3327]: time="2025-07-05T15:14:40+09:00" level=debug msg="obtained new client token: AADAVZGmQuStjt4dOSMex04gS5McdTGpdhlf0BBVAXwQmbA14d8O7OhAAldCK4sHjGx3KJXifTvnQEwtqwyZ3aFnxqCvCGCBL86NxU6vaD9K8slBQQY6SV8eYV1yL1qzgsqbosvFdnnVyDc564af7anvyZz1tjOq9C3NhGHb8oqcuuGS7Pc9vtnC10sJXlDaFFcQ0DiCqOuMpgra1FXOxkk2ii5Zk0Exq/DjKjfMlf+pNF55zb6QkmS3H38=" Jul 05 15:14:40 volumio go-librespot[3327]: time="2025-07-05T15:14:40+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:14:40 volumio go-librespot[3327]: time="2025-07-05T15:14:40+09:00" level=debug msg="completed keyexchange" Jul 05 15:14:40 volumio go-librespot[3327]: time="2025-07-05T15:14:40+09:00" level=debug msg="completed challenge" Jul 05 15:14:40 volumio go-librespot[3327]: time="2025-07-05T15:14:40+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:14:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:14:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:14:42 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:42 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:42 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:14:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:14:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 105. Jul 05 15:14:44 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:14:44 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:14:44 volumio go-librespot[3389]: go-librespot daemon starting... Jul 05 15:14:44 volumio go-librespot[3389]: time="2025-07-05T15:14:44+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:14:44 volumio go-librespot[3389]: time="2025-07-05T15:14:44+09:00" level=debug msg="app state loaded" Jul 05 15:14:44 volumio go-librespot[3389]: time="2025-07-05T15:14:44+09:00" level=debug msg="stored credentials not found" Jul 05 15:14:44 volumio go-librespot[3389]: time="2025-07-05T15:14:44+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:14:44 volumio go-librespot[3389]: time="2025-07-05T15:14:44+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 05 15:14:44 volumio go-librespot[3389]: time="2025-07-05T15:14:44+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jul 05 15:14:44 volumio go-librespot[3389]: time="2025-07-05T15:14:44+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jul 05 15:14:44 volumio go-librespot[3389]: time="2025-07-05T15:14:44+09:00" level=info msg="zeroconf server listening on port 43089" Jul 05 15:14:44 volumio go-librespot[3389]: time="2025-07-05T15:14:44+09:00" level=debug msg="obtained new client token: AABEV1s4Q9Ci/oV28ncvdV7eenYVyk2kR9Ss0nawsoIZUJ336bjTIBonCTUldVdnnHfcrmTvjBBbwUnev5uf7zy4pOD32ZNm7Q3bVX2rdPucsQtO+eyAhnK7pu8O3HuXmNhv3KY0jGh5bNCAHMkVFn4K3lw3+Aqcq26Stx/cQj0czUwAHXo1XmLfVVNGBMmWiFX25H6ka1s+f4KJFDP0zuRYOdnYQKEZss0uCR3lfc0BrdFOO2vr6m1gtX4=" Jul 05 15:14:44 volumio go-librespot[3389]: time="2025-07-05T15:14:44+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:14:44 volumio go-librespot[3389]: time="2025-07-05T15:14:44+09:00" level=debug msg="completed keyexchange" Jul 05 15:14:44 volumio go-librespot[3389]: time="2025-07-05T15:14:44+09:00" level=debug msg="completed challenge" Jul 05 15:14:44 volumio go-librespot[3389]: time="2025-07-05T15:14:44+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:14:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:14:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:14:45 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:45 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:46 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:14:47 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:14:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 106. Jul 05 15:14:47 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:14:47 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:14:47 volumio go-librespot[3401]: go-librespot daemon starting... Jul 05 15:14:47 volumio go-librespot[3401]: time="2025-07-05T15:14:47+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:14:47 volumio go-librespot[3401]: time="2025-07-05T15:14:47+09:00" level=debug msg="app state loaded" Jul 05 15:14:47 volumio go-librespot[3401]: time="2025-07-05T15:14:47+09:00" level=debug msg="stored credentials not found" Jul 05 15:14:47 volumio go-librespot[3401]: time="2025-07-05T15:14:47+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:14:48 volumio go-librespot[3401]: time="2025-07-05T15:14:48+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:14:48 volumio go-librespot[3401]: time="2025-07-05T15:14:48+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:14:48 volumio go-librespot[3401]: time="2025-07-05T15:14:48+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:14:48 volumio go-librespot[3401]: time="2025-07-05T15:14:48+09:00" level=info msg="zeroconf server listening on port 41993" Jul 05 15:14:48 volumio go-librespot[3401]: time="2025-07-05T15:14:48+09:00" level=debug msg="obtained new client token: AAB/BnRyJIIgqCH1s2wFDOvIFX5vA9eQEgAxGtE0GUmU1ASSVM+Ncq5199R7gXvtod4WaaycLtqZRhpXhr5kQc3WhZ+nXQXZzWvxFPuOoIqVOgc6W5EnLm7V4e/liQys+2El+2JtKOBoeUaq2ViElhAWz8lxKzGEaDxkGRzKOYTnjJ7EUIi9uy/COWpZoLN8y0QytCbxczjUkExSXisRa7lm4UeN2w03QDfMNsdSuccZwO8lkbtRH8ih" Jul 05 15:14:48 volumio go-librespot[3401]: time="2025-07-05T15:14:48+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:14:48 volumio go-librespot[3401]: time="2025-07-05T15:14:48+09:00" level=debug msg="completed keyexchange" Jul 05 15:14:48 volumio go-librespot[3401]: time="2025-07-05T15:14:48+09:00" level=debug msg="completed challenge" Jul 05 15:14:48 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:48 volumio go-librespot[3401]: time="2025-07-05T15:14:48+09:00" level=debug msg="new websocket client" Jul 05 15:14:48 volumio volumio[856]: info: Connection to go-librespot Websocket established Jul 05 15:14:48 volumio go-librespot[3401]: time="2025-07-05T15:14:48+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:14:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:14:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:14:48 volumio volumio[856]: info: Connection to go-librespot Websocket closed Jul 05 15:14:48 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 05 15:14:48 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 05 15:14:48 volumio volumio[856]: info: Discovery: Getting this device information Jul 05 15:14:48 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Jul 05 15:14:48 volumio volumio[856]: info: CorePlayQueue::getTrack 0 Jul 05 15:14:48 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 05 15:14:50 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:14:51 volumio volumio[856]: info: Getting Spotify volume Jul 05 15:14:51 volumio volumio[856]: (node:856) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:51 volumio volumio[856]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jul 05 15:14:51 volumio volumio[856]: (node:856) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 7) Jul 05 15:14:51 volumio volumio[856]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jul 05 15:14:51 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:51 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:51 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Jul 05 15:14:51 volumio volumio[856]: info: CorePlayQueue::getTrack 0 Jul 05 15:14:51 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:14:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 107. Jul 05 15:14:51 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:14:51 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:14:51 volumio go-librespot[3424]: go-librespot daemon starting... Jul 05 15:14:51 volumio go-librespot[3424]: time="2025-07-05T15:14:51+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:14:51 volumio go-librespot[3424]: time="2025-07-05T15:14:51+09:00" level=debug msg="app state loaded" Jul 05 15:14:51 volumio go-librespot[3424]: time="2025-07-05T15:14:51+09:00" level=debug msg="stored credentials not found" Jul 05 15:14:51 volumio go-librespot[3424]: time="2025-07-05T15:14:51+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:14:51 volumio go-librespot[3424]: time="2025-07-05T15:14:51+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:14:51 volumio go-librespot[3424]: time="2025-07-05T15:14:51+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:14:51 volumio go-librespot[3424]: time="2025-07-05T15:14:51+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:14:51 volumio go-librespot[3424]: time="2025-07-05T15:14:51+09:00" level=info msg="zeroconf server listening on port 45435" Jul 05 15:14:51 volumio go-librespot[3424]: time="2025-07-05T15:14:51+09:00" level=debug msg="obtained new client token: AACeFbsqv4OcNbIQtdcbLxr2BJDlMwHnRpgIbBZWv+w8ybk7QLiN4jwYRHTmdqTEKDt9eYTihEERtOAMvnPTFlY3fL+uOQYh5kVjNXbSS/tTus4zBsCWwn5jp1gTUxNd2qAv57RbDPDNfKhJ/YBHfmopVMJVS/NwH7t0ZCpM8H39BPY9rE1w5AjBSoqwrX8EpTT/aBU58NyVQSVver0mRD0zuNg3Ol+7IHmCVUAVeE+B9SsjmGaWPp2IA50=" Jul 05 15:14:51 volumio go-librespot[3424]: time="2025-07-05T15:14:51+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:14:52 volumio go-librespot[3424]: time="2025-07-05T15:14:52+09:00" level=debug msg="completed keyexchange" Jul 05 15:14:52 volumio go-librespot[3424]: time="2025-07-05T15:14:52+09:00" level=debug msg="completed challenge" Jul 05 15:14:52 volumio go-librespot[3424]: time="2025-07-05T15:14:52+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:14:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:14:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:14:54 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:54 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:54 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:14:55 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:14:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 108. Jul 05 15:14:55 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:14:55 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:14:55 volumio go-librespot[3431]: go-librespot daemon starting... Jul 05 15:14:55 volumio go-librespot[3431]: time="2025-07-05T15:14:55+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:14:55 volumio go-librespot[3431]: time="2025-07-05T15:14:55+09:00" level=debug msg="app state loaded" Jul 05 15:14:55 volumio go-librespot[3431]: time="2025-07-05T15:14:55+09:00" level=debug msg="stored credentials not found" Jul 05 15:14:55 volumio go-librespot[3431]: time="2025-07-05T15:14:55+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:14:55 volumio go-librespot[3431]: time="2025-07-05T15:14:55+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:14:55 volumio go-librespot[3431]: time="2025-07-05T15:14:55+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:14:55 volumio go-librespot[3431]: time="2025-07-05T15:14:55+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:14:55 volumio go-librespot[3431]: time="2025-07-05T15:14:55+09:00" level=info msg="zeroconf server listening on port 43351" Jul 05 15:14:55 volumio go-librespot[3431]: time="2025-07-05T15:14:55+09:00" level=debug msg="obtained new client token: AAAiZOYMw9B0qxDr4R2/UQ3hnXDDV8AQpZAYkzXgYJxX9KsOvGXMUoj75l5gmArCokuXlAvHtqGD1fDt55nhzpFvLwyDPOJWBRagGIml4rvfDfSfTbcJX9douDxXYTfrUECFlLNgIhtTuOizrdojCntprKgQEhwDXFCIdoIpBHVKAm3BP2pjefabC300wAfXDK620O/WQkuY0QYIS+3uQh8I57ylhShr6W/R5tLOJIo4IdLJkFuKYCmsq6M=" Jul 05 15:14:55 volumio go-librespot[3431]: time="2025-07-05T15:14:55+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:14:55 volumio go-librespot[3431]: time="2025-07-05T15:14:55+09:00" level=debug msg="completed keyexchange" Jul 05 15:14:55 volumio go-librespot[3431]: time="2025-07-05T15:14:55+09:00" level=debug msg="completed challenge" Jul 05 15:14:55 volumio go-librespot[3431]: time="2025-07-05T15:14:55+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:14:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:14:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:14:57 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:14:57 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:14:58 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:14:59 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:14:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 109. Jul 05 15:14:59 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:14:59 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:14:59 volumio go-librespot[3439]: go-librespot daemon starting... Jul 05 15:14:59 volumio go-librespot[3439]: time="2025-07-05T15:14:59+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:14:59 volumio go-librespot[3439]: time="2025-07-05T15:14:59+09:00" level=debug msg="app state loaded" Jul 05 15:14:59 volumio go-librespot[3439]: time="2025-07-05T15:14:59+09:00" level=debug msg="stored credentials not found" Jul 05 15:14:59 volumio go-librespot[3439]: time="2025-07-05T15:14:59+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:14:59 volumio go-librespot[3439]: time="2025-07-05T15:14:59+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 05 15:14:59 volumio go-librespot[3439]: time="2025-07-05T15:14:59+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jul 05 15:14:59 volumio go-librespot[3439]: time="2025-07-05T15:14:59+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jul 05 15:14:59 volumio go-librespot[3439]: time="2025-07-05T15:14:59+09:00" level=info msg="zeroconf server listening on port 42227" Jul 05 15:14:59 volumio go-librespot[3439]: time="2025-07-05T15:14:59+09:00" level=debug msg="obtained new client token: AAByh/Xi19yj2ANbZZ6UqcU/Ep8rTbQJef37XsZ2eKsHRMM07eFqSIQLPt22gWr4/IjWL+CR1BLSdLG2JRzwkSEDtYbOmmsm5lP0v31EvgqT66CE4ML0+cjhyzwPqbxpaXbvpFdTkOcsuSTkCgaeCEWeW9KzTTBaNnH4Nzbul+GuCSXumClODGfKwGv5nVxCaLZGFbHNq95LTVRMqpYV/Uzfl2y0XnuDZLOex/bJT9NyGrjUZH4kKun2j/o=" Jul 05 15:14:59 volumio go-librespot[3439]: time="2025-07-05T15:14:59+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jul 05 15:14:59 volumio go-librespot[3439]: time="2025-07-05T15:14:59+09:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jul 05 15:14:59 volumio go-librespot[3439]: time="2025-07-05T15:14:59+09:00" level=debug msg="completed keyexchange" Jul 05 15:14:59 volumio go-librespot[3439]: time="2025-07-05T15:14:59+09:00" level=debug msg="completed challenge" Jul 05 15:14:59 volumio go-librespot[3439]: time="2025-07-05T15:14:59+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:14:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:14:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:15:00 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:00 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:02 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:15:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:15:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 110. Jul 05 15:15:02 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:15:02 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:15:02 volumio go-librespot[3461]: go-librespot daemon starting... Jul 05 15:15:02 volumio go-librespot[3461]: time="2025-07-05T15:15:02+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:15:02 volumio go-librespot[3461]: time="2025-07-05T15:15:02+09:00" level=debug msg="app state loaded" Jul 05 15:15:02 volumio go-librespot[3461]: time="2025-07-05T15:15:02+09:00" level=debug msg="stored credentials not found" Jul 05 15:15:02 volumio go-librespot[3461]: time="2025-07-05T15:15:02+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:15:03 volumio go-librespot[3461]: time="2025-07-05T15:15:03+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:15:03 volumio go-librespot[3461]: time="2025-07-05T15:15:03+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:15:03 volumio go-librespot[3461]: time="2025-07-05T15:15:03+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:15:03 volumio go-librespot[3461]: time="2025-07-05T15:15:03+09:00" level=info msg="zeroconf server listening on port 43547" Jul 05 15:15:03 volumio go-librespot[3461]: time="2025-07-05T15:15:03+09:00" level=debug msg="obtained new client token: AAB5XhJ+hiYW8Ndww2uFru2abkU4FBLs8avI5bZCh5+HKJN+pq7cEs8z+uMzXEeDIBvIPq9ogb1ij0N2F6s769mevmX9Lg3YraEGCq+W3FXgFCasnjqakhjg+gxOmEyAXwWhiHTOFKkVU6uRwizTr8+iavjsxBGq//4hyIGVDSyViyNUOf9eSSNdibK0hTJE5/X5MBKkamsFVoq+d6FQkitA9Uigaw6O+bmubd4+awkEObXe/ZELtbwZ" Jul 05 15:15:03 volumio go-librespot[3461]: time="2025-07-05T15:15:03+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:15:03 volumio go-librespot[3461]: time="2025-07-05T15:15:03+09:00" level=debug msg="completed keyexchange" Jul 05 15:15:03 volumio go-librespot[3461]: time="2025-07-05T15:15:03+09:00" level=debug msg="completed challenge" Jul 05 15:15:03 volumio go-librespot[3461]: time="2025-07-05T15:15:03+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:15:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:15:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:15:03 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:03 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:06 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:06 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:06 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:15:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:15:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 111. Jul 05 15:15:06 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:15:06 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:15:06 volumio go-librespot[3469]: go-librespot daemon starting... Jul 05 15:15:06 volumio go-librespot[3469]: time="2025-07-05T15:15:06+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:15:06 volumio go-librespot[3469]: time="2025-07-05T15:15:06+09:00" level=debug msg="app state loaded" Jul 05 15:15:06 volumio go-librespot[3469]: time="2025-07-05T15:15:06+09:00" level=debug msg="stored credentials not found" Jul 05 15:15:06 volumio go-librespot[3469]: time="2025-07-05T15:15:06+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:15:06 volumio go-librespot[3469]: time="2025-07-05T15:15:06+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 05 15:15:06 volumio go-librespot[3469]: time="2025-07-05T15:15:06+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jul 05 15:15:06 volumio go-librespot[3469]: time="2025-07-05T15:15:06+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jul 05 15:15:06 volumio go-librespot[3469]: time="2025-07-05T15:15:06+09:00" level=info msg="zeroconf server listening on port 38109" Jul 05 15:15:06 volumio go-librespot[3469]: time="2025-07-05T15:15:06+09:00" level=debug msg="obtained new client token: AADJ/UPg+ZMquKSrrdjZGtxE0jRphlxP/+XL5cYSWNCaB9SNvPHdMpSJS/5I0gkSQotLLoYkGITrV3IOJO87Sz8c46TeCImRou2uEpYRHsbwMbS6DCc8l/8VI+b4xcxKpaohOEY+o0Chq4PxGwrnEkFaEhjO+2ESx/2XRM6ywz7KJb373zr5GC4k532Qp0WGVEgAPJn+1iX9Z356PCTet0tT6cVbIJ/sGjljO1CrmDOOCMWp5AuxS/sW2fg=" Jul 05 15:15:06 volumio go-librespot[3469]: time="2025-07-05T15:15:06+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jul 05 15:15:07 volumio go-librespot[3469]: time="2025-07-05T15:15:07+09:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jul 05 15:15:07 volumio go-librespot[3469]: time="2025-07-05T15:15:07+09:00" level=debug msg="completed keyexchange" Jul 05 15:15:07 volumio go-librespot[3469]: time="2025-07-05T15:15:07+09:00" level=debug msg="completed challenge" Jul 05 15:15:07 volumio go-librespot[3469]: time="2025-07-05T15:15:07+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:15:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:15:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:15:09 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:09 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:15:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 112. Jul 05 15:15:10 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:15:10 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:15:10 volumio go-librespot[3481]: go-librespot daemon starting... Jul 05 15:15:10 volumio go-librespot[3481]: time="2025-07-05T15:15:10+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:15:10 volumio go-librespot[3481]: time="2025-07-05T15:15:10+09:00" level=debug msg="app state loaded" Jul 05 15:15:10 volumio go-librespot[3481]: time="2025-07-05T15:15:10+09:00" level=debug msg="stored credentials not found" Jul 05 15:15:10 volumio go-librespot[3481]: time="2025-07-05T15:15:10+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:15:10 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:15:10 volumio go-librespot[3481]: time="2025-07-05T15:15:10+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:15:10 volumio go-librespot[3481]: time="2025-07-05T15:15:10+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:15:10 volumio go-librespot[3481]: time="2025-07-05T15:15:10+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:15:10 volumio go-librespot[3481]: time="2025-07-05T15:15:10+09:00" level=info msg="zeroconf server listening on port 37595" Jul 05 15:15:10 volumio go-librespot[3481]: time="2025-07-05T15:15:10+09:00" level=debug msg="obtained new client token: AABu6K65pPObzsimHr3ZBdaodwdUl9vpSAGx04Wo81XgKgF77aRclSP9Pe0HeZCEdUeaG1SxGabsW+/BWzTJXyQ8kweed0ruNoX9TWvnVrq2VydYqlJQLh1J3VCq/w9BkB/G4HL5dCnECOKgReuySMa5eUqyKCLigAFjKtwRjQtnHyGLdM2eHkUBPvmfKMKuq17HPfT05EeyIVSMrBGpC/Eya5KU/oLfijCpakPqt6W+ghrKmsenCDsy/8s=" Jul 05 15:15:10 volumio go-librespot[3481]: time="2025-07-05T15:15:10+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:15:10 volumio go-librespot[3481]: time="2025-07-05T15:15:10+09:00" level=debug msg="completed keyexchange" Jul 05 15:15:10 volumio go-librespot[3481]: time="2025-07-05T15:15:10+09:00" level=debug msg="completed challenge" Jul 05 15:15:10 volumio go-librespot[3481]: time="2025-07-05T15:15:10+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:15:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:15:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:15:12 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:12 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:15:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 113. Jul 05 15:15:14 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:15:14 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:15:14 volumio go-librespot[3504]: go-librespot daemon starting... Jul 05 15:15:14 volumio go-librespot[3504]: time="2025-07-05T15:15:14+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:15:14 volumio go-librespot[3504]: time="2025-07-05T15:15:14+09:00" level=debug msg="app state loaded" Jul 05 15:15:14 volumio go-librespot[3504]: time="2025-07-05T15:15:14+09:00" level=debug msg="stored credentials not found" Jul 05 15:15:14 volumio go-librespot[3504]: time="2025-07-05T15:15:14+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:15:14 volumio go-librespot[3504]: time="2025-07-05T15:15:14+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 05 15:15:14 volumio go-librespot[3504]: time="2025-07-05T15:15:14+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jul 05 15:15:14 volumio go-librespot[3504]: time="2025-07-05T15:15:14+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jul 05 15:15:14 volumio go-librespot[3504]: time="2025-07-05T15:15:14+09:00" level=info msg="zeroconf server listening on port 38063" Jul 05 15:15:14 volumio go-librespot[3504]: time="2025-07-05T15:15:14+09:00" level=debug msg="obtained new client token: AAAbwRhCB8DybqXgvMPQe2yXRnEGV+jvXDi6aZK0djgBVzgVwFx8akB7Lo+Sa3Y0SnVRTHuXVKzpJkaBcWUbglOTjkm2yaaZ096gsYZLj76VQGYeTqJtdJ2MFKDsKxd6ewufr388VEoX4XPBnmNGlwIKUQudNi8pX3DCe7B+lcVQV4fX8lMa7lp2uHNvlXOi1lfMegWJ1QHkeVstkAOnm+RuQuX35D338qOWL7cQFGRt1e3XfNAn3mLOvBs=" Jul 05 15:15:14 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:15:14 volumio go-librespot[3504]: time="2025-07-05T15:15:14+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:15:14 volumio go-librespot[3504]: time="2025-07-05T15:15:14+09:00" level=debug msg="completed keyexchange" Jul 05 15:15:14 volumio go-librespot[3504]: time="2025-07-05T15:15:14+09:00" level=debug msg="completed challenge" Jul 05 15:15:14 volumio go-librespot[3504]: time="2025-07-05T15:15:14+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:15:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:15:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:15:15 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:15 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:15:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 114. Jul 05 15:15:17 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:15:17 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:15:17 volumio go-librespot[3511]: go-librespot daemon starting... Jul 05 15:15:17 volumio go-librespot[3511]: time="2025-07-05T15:15:17+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:15:17 volumio go-librespot[3511]: time="2025-07-05T15:15:17+09:00" level=debug msg="app state loaded" Jul 05 15:15:17 volumio go-librespot[3511]: time="2025-07-05T15:15:17+09:00" level=debug msg="stored credentials not found" Jul 05 15:15:17 volumio go-librespot[3511]: time="2025-07-05T15:15:17+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:15:18 volumio go-librespot[3511]: time="2025-07-05T15:15:18+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:15:18 volumio go-librespot[3511]: time="2025-07-05T15:15:18+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:15:18 volumio go-librespot[3511]: time="2025-07-05T15:15:18+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:15:18 volumio go-librespot[3511]: time="2025-07-05T15:15:18+09:00" level=info msg="zeroconf server listening on port 44163" Jul 05 15:15:18 volumio go-librespot[3511]: time="2025-07-05T15:15:18+09:00" level=debug msg="obtained new client token: AABX2U1FkPu+tUjjI/Z6s88cqGezWtRNcsJWeuvWdF6T5t2X9Fba5yRIu8abpIywy5VzbKiC96a1ncidwlJz1W2xW6yTA81QekA9j3Qk2b1Rq10nVFYwu6rBEivfFd88uUSDdFbGTmDfkfY+uT2u68CIMAdxPRgmjEVVopqaE+Won1BP8cjhqeKR3WH51d4gG06wgWfmOOWzwWAaAiJwYMm7fsAwI2gcADbNq4CzxU65pzBsiwKjS8mJ" Jul 05 15:15:18 volumio go-librespot[3511]: time="2025-07-05T15:15:18+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:15:18 volumio go-librespot[3511]: time="2025-07-05T15:15:18+09:00" level=debug msg="completed keyexchange" Jul 05 15:15:18 volumio go-librespot[3511]: time="2025-07-05T15:15:18+09:00" level=debug msg="completed challenge" Jul 05 15:15:18 volumio go-librespot[3511]: time="2025-07-05T15:15:18+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:15:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:15:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:15:18 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:18 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:18 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 05 15:15:18 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 05 15:15:18 volumio volumio[856]: info: Discovery: Getting this device information Jul 05 15:15:18 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Jul 05 15:15:18 volumio volumio[856]: info: CorePlayQueue::getTrack 0 Jul 05 15:15:18 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 05 15:15:18 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:15:21 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:21 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:15:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 115. Jul 05 15:15:21 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:15:21 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:15:21 volumio go-librespot[3533]: go-librespot daemon starting... Jul 05 15:15:21 volumio go-librespot[3533]: time="2025-07-05T15:15:21+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:15:21 volumio go-librespot[3533]: time="2025-07-05T15:15:21+09:00" level=debug msg="app state loaded" Jul 05 15:15:21 volumio go-librespot[3533]: time="2025-07-05T15:15:21+09:00" level=debug msg="stored credentials not found" Jul 05 15:15:21 volumio go-librespot[3533]: time="2025-07-05T15:15:21+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:15:21 volumio go-librespot[3533]: time="2025-07-05T15:15:21+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:15:21 volumio go-librespot[3533]: time="2025-07-05T15:15:21+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:15:21 volumio go-librespot[3533]: time="2025-07-05T15:15:21+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:15:21 volumio go-librespot[3533]: time="2025-07-05T15:15:21+09:00" level=info msg="zeroconf server listening on port 42023" Jul 05 15:15:21 volumio go-librespot[3533]: time="2025-07-05T15:15:21+09:00" level=debug msg="obtained new client token: AAAqnPo6f/phQOYhM94SZfBsvztKCoiiW5j4iYJrq1gb/OwaMle6c7NWR9LsFye8GBecuWQwKdUIBsbGL4oh3MybaKaH9T8zkqNwV/zI4SYHpkXBIViBVWI8RRIIOw2xfVWTdiR4dZcedstFMeBGfgKbnLKRFYxuvtAlz3X7stKd+EkKh6SnTgLL9mDVhWKdg3ZHNFfS9B/kotK/QYVnkX0EHN2Q634e5QD1KiP7snGLBE2Mw33eZSwpCcs=" Jul 05 15:15:22 volumio go-librespot[3533]: time="2025-07-05T15:15:22+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jul 05 15:15:22 volumio go-librespot[3533]: time="2025-07-05T15:15:22+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Jul 05 15:15:22 volumio go-librespot[3533]: time="2025-07-05T15:15:22+09:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jul 05 15:15:22 volumio go-librespot[3533]: time="2025-07-05T15:15:22+09:00" level=debug msg="completed keyexchange" Jul 05 15:15:22 volumio go-librespot[3533]: time="2025-07-05T15:15:22+09:00" level=debug msg="completed challenge" Jul 05 15:15:22 volumio go-librespot[3533]: time="2025-07-05T15:15:22+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:15:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:15:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:15:22 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:15:24 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:24 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:15:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 116. Jul 05 15:15:25 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:15:25 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:15:25 volumio go-librespot[3541]: go-librespot daemon starting... Jul 05 15:15:25 volumio go-librespot[3541]: time="2025-07-05T15:15:25+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:15:25 volumio go-librespot[3541]: time="2025-07-05T15:15:25+09:00" level=debug msg="app state loaded" Jul 05 15:15:25 volumio go-librespot[3541]: time="2025-07-05T15:15:25+09:00" level=debug msg="stored credentials not found" Jul 05 15:15:25 volumio go-librespot[3541]: time="2025-07-05T15:15:25+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:15:25 volumio go-librespot[3541]: time="2025-07-05T15:15:25+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:15:25 volumio go-librespot[3541]: time="2025-07-05T15:15:25+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:15:25 volumio go-librespot[3541]: time="2025-07-05T15:15:25+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:15:25 volumio go-librespot[3541]: time="2025-07-05T15:15:25+09:00" level=info msg="zeroconf server listening on port 35639" Jul 05 15:15:25 volumio go-librespot[3541]: time="2025-07-05T15:15:25+09:00" level=debug msg="obtained new client token: AAB4vKXw0EKpjfxrvvbLKVTKPK5tcu3dKB6FgBlNzJPV6qQf8IZpooQoR2ria8BDHM0sjHGeieYz09zHjjXySX/Dp+FbUDvFDUkolKFacnAZoJNultEWPlzW964BWPWUBmhe2eJDxYBkTKDW2oenOBNhFCj0B+meP3Mit2/LFrF3P9FKAtqs+inMq30VBRNb52v2pE1HlhIBLhGMKA7ijAAaZ3B1L9M0PxkhJWtt/yX8Bhq3HYCo36i5IQ0=" Jul 05 15:15:25 volumio go-librespot[3541]: time="2025-07-05T15:15:25+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:15:26 volumio go-librespot[3541]: time="2025-07-05T15:15:26+09:00" level=debug msg="completed keyexchange" Jul 05 15:15:26 volumio go-librespot[3541]: time="2025-07-05T15:15:26+09:00" level=debug msg="completed challenge" Jul 05 15:15:26 volumio go-librespot[3541]: time="2025-07-05T15:15:26+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:15:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:15:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:15:26 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:15:27 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:27 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:15:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 117. Jul 05 15:15:29 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:15:29 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:15:29 volumio go-librespot[3552]: go-librespot daemon starting... Jul 05 15:15:29 volumio go-librespot[3552]: time="2025-07-05T15:15:29+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:15:29 volumio go-librespot[3552]: time="2025-07-05T15:15:29+09:00" level=debug msg="app state loaded" Jul 05 15:15:29 volumio go-librespot[3552]: time="2025-07-05T15:15:29+09:00" level=debug msg="stored credentials not found" Jul 05 15:15:29 volumio go-librespot[3552]: time="2025-07-05T15:15:29+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:15:29 volumio go-librespot[3552]: time="2025-07-05T15:15:29+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:15:29 volumio go-librespot[3552]: time="2025-07-05T15:15:29+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:15:29 volumio go-librespot[3552]: time="2025-07-05T15:15:29+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:15:29 volumio go-librespot[3552]: time="2025-07-05T15:15:29+09:00" level=info msg="zeroconf server listening on port 44371" Jul 05 15:15:29 volumio go-librespot[3552]: time="2025-07-05T15:15:29+09:00" level=debug msg="obtained new client token: AABgpr0G4vHJpPuDELc1leupCeZiobPZWKc8AuP2C6cp+zamk40WrrQv9B+2a2ip3RK0j9hgCJXKhVORe7oMML2FXWMk/qKXY0i+X3FOs2Cy0/vYI+yyFZCgZhs6sO+v+aHXCCusm2hvVnTkDPgdphqmWJutWiQWb4c0SXQxB1F8X+wuZTRlzMV5OCbVxT/bWH+P+SfgbCVr/hpADBcpPCdFGbMs4BUqPliOqlPH25PUrNH6E/ladO92esI=" Jul 05 15:15:29 volumio go-librespot[3552]: time="2025-07-05T15:15:29+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:15:29 volumio go-librespot[3552]: time="2025-07-05T15:15:29+09:00" level=debug msg="completed keyexchange" Jul 05 15:15:29 volumio go-librespot[3552]: time="2025-07-05T15:15:29+09:00" level=debug msg="completed challenge" Jul 05 15:15:29 volumio go-librespot[3552]: time="2025-07-05T15:15:29+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:15:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:15:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:15:30 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Jul 05 15:15:30 volumio volumio[856]: info: CorePlayQueue::getTrack 0 Jul 05 15:15:30 volumio sudo[3562]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 05 15:15:30 volumio sudo[3562]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 15:15:30 volumio sudo[3562]: pam_unix(sudo:session): session closed for user root Jul 05 15:15:30 volumio sudo[3565]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 05 15:15:30 volumio sudo[3565]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 15:15:30 volumio sudo[3565]: pam_unix(sudo:session): session closed for user root Jul 05 15:15:30 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:30 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:30 volumio volumio[856]: verbose: New Socket.io Connection to 192.168.219.200 from 192.168.219.100 UA: Mozilla/5.0 (Linux; Android 14; SM-A528N Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/137.0.7151.115 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Jul 05 15:15:30 volumio volumio[856]: info: CoreCommandRouter::volumioGetVisibleSources Jul 05 15:15:30 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 05 15:15:30 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Jul 05 15:15:30 volumio volumio[856]: info: CorePlayQueue::getTrack 0 Jul 05 15:15:30 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jul 05 15:15:30 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 05 15:15:30 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 05 15:15:30 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 05 15:15:30 volumio sudo[3568]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 05 15:15:30 volumio sudo[3568]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 15:15:30 volumio sudo[3568]: pam_unix(sudo:session): session closed for user root Jul 05 15:15:30 volumio sudo[3571]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 05 15:15:30 volumio sudo[3571]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 15:15:30 volumio sudo[3571]: pam_unix(sudo:session): session closed for user root Jul 05 15:15:30 volumio volumio[856]: verbose: New Socket.io Connection to 192.168.219.200 from 192.168.219.100 UA: Mozilla/5.0 (Linux; Android 14; SM-A528N Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/137.0.7151.115 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Jul 05 15:15:30 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Jul 05 15:15:30 volumio volumio[856]: info: CorePlayQueue::getTrack 0 Jul 05 15:15:30 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 05 15:15:30 volumio volumio[856]: info: Listing playlists Jul 05 15:15:30 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jul 05 15:15:30 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 05 15:15:30 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 05 15:15:30 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 05 15:15:31 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:15:32 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 05 15:15:32 volumio volumio[856]: info: Received Get System Info Jul 05 15:15:32 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 05 15:15:32 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 05 15:15:32 volumio volumio[856]: info: Discovery: Getting this device information Jul 05 15:15:32 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Jul 05 15:15:32 volumio volumio[856]: info: CorePlayQueue::getTrack 0 Jul 05 15:15:32 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 05 15:15:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:15:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 118. Jul 05 15:15:33 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:15:33 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:15:33 volumio go-librespot[3587]: go-librespot daemon starting... Jul 05 15:15:33 volumio go-librespot[3587]: time="2025-07-05T15:15:33+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:15:33 volumio go-librespot[3587]: time="2025-07-05T15:15:33+09:00" level=debug msg="app state loaded" Jul 05 15:15:33 volumio go-librespot[3587]: time="2025-07-05T15:15:33+09:00" level=debug msg="stored credentials not found" Jul 05 15:15:33 volumio go-librespot[3587]: time="2025-07-05T15:15:33+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:15:33 volumio go-librespot[3587]: time="2025-07-05T15:15:33+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:15:33 volumio go-librespot[3587]: time="2025-07-05T15:15:33+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:15:33 volumio go-librespot[3587]: time="2025-07-05T15:15:33+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:15:33 volumio go-librespot[3587]: time="2025-07-05T15:15:33+09:00" level=info msg="zeroconf server listening on port 41821" Jul 05 15:15:33 volumio go-librespot[3587]: time="2025-07-05T15:15:33+09:00" level=debug msg="obtained new client token: AADbJLJJQNs09wnxNe3b8zniBn0WCEwY6EsfPsCWcsIbmDk4e3o/4BA2758n2T4qRf5/Babsx10hMJTX0F0GcqeSRiK7rIIIavF9WSBaR33wKs7s0SIYWetcElrXJxxdmnHVj4uvi5gdNQSh7R59v2rUtJLSSMWI1PqMxA5Y1qG96gRJEq9gRFmp+OfIoptGgR7Ukt3rBS4J9njY54DvQDehsCtLgNJXl7Q6PsFISFIOCvLEmTNeP6obv9Y=" Jul 05 15:15:33 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:33 volumio go-librespot[3587]: time="2025-07-05T15:15:33+09:00" level=debug msg="new websocket client" Jul 05 15:15:33 volumio volumio[856]: info: Connection to go-librespot Websocket established Jul 05 15:15:33 volumio go-librespot[3587]: time="2025-07-05T15:15:33+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:15:33 volumio go-librespot[3587]: time="2025-07-05T15:15:33+09:00" level=debug msg="completed keyexchange" Jul 05 15:15:33 volumio go-librespot[3587]: time="2025-07-05T15:15:33+09:00" level=debug msg="completed challenge" Jul 05 15:15:33 volumio go-librespot[3587]: time="2025-07-05T15:15:33+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:15:33 volumio volumio[856]: info: Connection to go-librespot Websocket closed Jul 05 15:15:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:15:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:15:35 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:15:35 volumio volumio[856]: info: CoreCommandRouter::volumioGetVisibleSources Jul 05 15:15:35 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 05 15:15:35 volumio volumio[856]: info: CoreCommandRouter::volumioGetQueue Jul 05 15:15:35 volumio volumio[856]: info: CoreStateMachine::getQueue Jul 05 15:15:35 volumio volumio[856]: info: CorePlayQueue::getQueue Jul 05 15:15:36 volumio volumio[856]: info: Getting Spotify volume Jul 05 15:15:36 volumio volumio[856]: (node:856) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:36 volumio volumio[856]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jul 05 15:15:36 volumio volumio[856]: (node:856) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 8) Jul 05 15:15:36 volumio volumio[856]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Jul 05 15:15:36 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Jul 05 15:15:36 volumio volumio[856]: info: CorePlayQueue::getTrack 0 Jul 05 15:15:36 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:36 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:15:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 119. Jul 05 15:15:36 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:15:36 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:15:36 volumio go-librespot[3595]: go-librespot daemon starting... Jul 05 15:15:36 volumio go-librespot[3595]: time="2025-07-05T15:15:36+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:15:36 volumio go-librespot[3595]: time="2025-07-05T15:15:36+09:00" level=debug msg="app state loaded" Jul 05 15:15:36 volumio go-librespot[3595]: time="2025-07-05T15:15:36+09:00" level=debug msg="stored credentials not found" Jul 05 15:15:36 volumio go-librespot[3595]: time="2025-07-05T15:15:36+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:15:37 volumio go-librespot[3595]: time="2025-07-05T15:15:37+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:15:37 volumio go-librespot[3595]: time="2025-07-05T15:15:37+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:15:37 volumio go-librespot[3595]: time="2025-07-05T15:15:37+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:15:37 volumio go-librespot[3595]: time="2025-07-05T15:15:37+09:00" level=info msg="zeroconf server listening on port 32823" Jul 05 15:15:37 volumio go-librespot[3595]: time="2025-07-05T15:15:37+09:00" level=debug msg="obtained new client token: AAD36Z4IuxH4s5iwM1NCpAUIljTsWuVgQoHmgZKoglXsZiHAv+UaF/Qxi+uFnREbropcz4dGhFnrrcLzRMKIeDBUp/w55QXFPJ/J0CkBKKIftDgWsinlk7Gx/nLLSgrG1AEhBJkaPNpctoxWYJS6JgINeFehpxPwCT6gUX/oT3CITu59dNCK0C0J643oUswKpCFHvEMU1MPbyb3D1ENxJrl2KCMxWJbkB20hCEiNp9I/TRJvkXn5lJYg" Jul 05 15:15:37 volumio go-librespot[3595]: time="2025-07-05T15:15:37+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:15:37 volumio go-librespot[3595]: time="2025-07-05T15:15:37+09:00" level=debug msg="completed keyexchange" Jul 05 15:15:37 volumio go-librespot[3595]: time="2025-07-05T15:15:37+09:00" level=debug msg="completed challenge" Jul 05 15:15:37 volumio go-librespot[3595]: time="2025-07-05T15:15:37+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:15:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:15:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:15:37 volumio volumio[856]: info: Preload queue cleared Jul 05 15:15:39 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 15:15:39 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:39 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:15:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 120. Jul 05 15:15:40 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:15:40 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Jul 05 15:15:40 volumio volumio[856]: info: CorePlayQueue::getTrack 0 Jul 05 15:15:40 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:15:40 volumio go-librespot[3603]: go-librespot daemon starting... Jul 05 15:15:40 volumio go-librespot[3603]: time="2025-07-05T15:15:40+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:15:40 volumio go-librespot[3603]: time="2025-07-05T15:15:40+09:00" level=debug msg="app state loaded" Jul 05 15:15:40 volumio go-librespot[3603]: time="2025-07-05T15:15:40+09:00" level=debug msg="stored credentials not found" Jul 05 15:15:40 volumio go-librespot[3603]: time="2025-07-05T15:15:40+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:15:40 volumio go-librespot[3603]: time="2025-07-05T15:15:40+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:15:40 volumio go-librespot[3603]: time="2025-07-05T15:15:40+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:15:40 volumio go-librespot[3603]: time="2025-07-05T15:15:40+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:15:40 volumio go-librespot[3603]: time="2025-07-05T15:15:40+09:00" level=info msg="zeroconf server listening on port 40687" Jul 05 15:15:40 volumio go-librespot[3603]: time="2025-07-05T15:15:40+09:00" level=debug msg="obtained new client token: AAAX0sodxjnETjuFTciWYuEzItE8dL+aY1Zo7dCV0kdz74bCPIni4BdmLleowMbzH7CRtZJBkh/7j3Qz24yHaea3aexpSTSDxfBCaJqx9ZuVYcHnJg3Giz1c7onzOjyrYeGsS4mxVYYtMZJIBKKV2C0JR3v3GlFjKshXwWx0+YeTUpBFSv9nFFowd6K50zkeBOvnys924Qo8r5CNvDi5qtYqYYCsgak4agywOTW3qHMSWw2IegBPtCKZj90=" Jul 05 15:15:40 volumio sudo[3625]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 05 15:15:40 volumio sudo[3625]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 15:15:40 volumio sudo[3625]: pam_unix(sudo:session): session closed for user root Jul 05 15:15:40 volumio sudo[3628]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 05 15:15:40 volumio sudo[3628]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 15:15:40 volumio sudo[3628]: pam_unix(sudo:session): session closed for user root Jul 05 15:15:40 volumio go-librespot[3603]: time="2025-07-05T15:15:40+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:15:41 volumio volumio[856]: verbose: New Socket.io Connection to 192.168.219.200 from 192.168.219.100 UA: Mozilla/5.0 (Linux; Android 14; SM-A528N Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/137.0.7151.115 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Jul 05 15:15:41 volumio go-librespot[3603]: time="2025-07-05T15:15:41+09:00" level=debug msg="completed keyexchange" Jul 05 15:15:41 volumio go-librespot[3603]: time="2025-07-05T15:15:41+09:00" level=debug msg="completed challenge" Jul 05 15:15:41 volumio volumio[856]: info: CoreCommandRouter::volumioGetVisibleSources Jul 05 15:15:41 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 05 15:15:41 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Jul 05 15:15:41 volumio volumio[856]: info: CorePlayQueue::getTrack 0 Jul 05 15:15:41 volumio go-librespot[3603]: time="2025-07-05T15:15:41+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:15:41 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jul 05 15:15:41 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 05 15:15:41 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 05 15:15:41 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 05 15:15:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:15:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:15:41 volumio sudo[3631]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 05 15:15:41 volumio sudo[3631]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 15:15:41 volumio sudo[3631]: pam_unix(sudo:session): session closed for user root Jul 05 15:15:41 volumio sudo[3634]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 05 15:15:41 volumio sudo[3634]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 15:15:41 volumio sudo[3634]: pam_unix(sudo:session): session closed for user root Jul 05 15:15:41 volumio volumio[856]: verbose: New Socket.io Connection to 192.168.219.200 from 192.168.219.100 UA: Mozilla/5.0 (Linux; Android 14; SM-A528N Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/137.0.7151.115 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Jul 05 15:15:41 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Jul 05 15:15:41 volumio volumio[856]: info: CorePlayQueue::getTrack 0 Jul 05 15:15:41 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 05 15:15:41 volumio volumio[856]: info: Listing playlists Jul 05 15:15:41 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jul 05 15:15:41 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 05 15:15:41 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 05 15:15:41 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 05 15:15:42 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:42 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:42 volumio volumio[856]: info: CoreCommandRouter::volumioGetVisibleSources Jul 05 15:15:42 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 05 15:15:42 volumio volumio[856]: info: CoreCommandRouter::volumioGetQueue Jul 05 15:15:42 volumio volumio[856]: info: CoreStateMachine::getQueue Jul 05 15:15:42 volumio volumio[856]: info: CorePlayQueue::getQueue Jul 05 15:15:43 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 05 15:15:43 volumio volumio[856]: info: Received Get System Info Jul 05 15:15:43 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 05 15:15:43 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 05 15:15:43 volumio volumio[856]: info: Discovery: Getting this device information Jul 05 15:15:43 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Jul 05 15:15:43 volumio volumio[856]: info: CorePlayQueue::getTrack 0 Jul 05 15:15:43 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 05 15:15:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:15:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 121. Jul 05 15:15:44 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jul 05 15:15:44 volumio volumio[856]: info: CURURI: playlists Jul 05 15:15:44 volumio volumio[856]: info: Listing playlists Jul 05 15:15:44 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:15:44 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:15:44 volumio go-librespot[3677]: go-librespot daemon starting... Jul 05 15:15:44 volumio go-librespot[3677]: time="2025-07-05T15:15:44+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:15:44 volumio go-librespot[3677]: time="2025-07-05T15:15:44+09:00" level=debug msg="app state loaded" Jul 05 15:15:44 volumio go-librespot[3677]: time="2025-07-05T15:15:44+09:00" level=debug msg="stored credentials not found" Jul 05 15:15:44 volumio go-librespot[3677]: time="2025-07-05T15:15:44+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:15:44 volumio volumio[856]: info: Preload queue cleared Jul 05 15:15:44 volumio go-librespot[3677]: time="2025-07-05T15:15:44+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 05 15:15:44 volumio go-librespot[3677]: time="2025-07-05T15:15:44+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jul 05 15:15:44 volumio go-librespot[3677]: time="2025-07-05T15:15:44+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jul 05 15:15:44 volumio go-librespot[3677]: time="2025-07-05T15:15:44+09:00" level=info msg="zeroconf server listening on port 33979" Jul 05 15:15:44 volumio go-librespot[3677]: time="2025-07-05T15:15:44+09:00" level=debug msg="obtained new client token: AAA7pn/hs1tOMKOHVJ9+HP21Ok9abtJPYZ/m16I7WnX8kZwvwDxJQj9AMlo+YDUK/sJSuHkhC9zL0szw3UCxF4cni7UDP8LMRprvn5cuN7TNxyo6ZJvCrBSDftJXLmSe+abtJ0DsfSyyqi5LTjrRv8eZbyQXW/EUHvb4XXMGrp9TjJ/iD5jVv8tls9bwZNAx8kwJkbUGrZUJ4hwiw3u6MOoAtV3GT/w0v223OSxBrO2WL1GGnS5hcP/5XIk=" Jul 05 15:15:44 volumio go-librespot[3677]: time="2025-07-05T15:15:44+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:15:44 volumio go-librespot[3677]: time="2025-07-05T15:15:44+09:00" level=debug msg="completed keyexchange" Jul 05 15:15:44 volumio go-librespot[3677]: time="2025-07-05T15:15:44+09:00" level=debug msg="completed challenge" Jul 05 15:15:44 volumio go-librespot[3677]: time="2025-07-05T15:15:44+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:15:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:15:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:15:45 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:45 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:46 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jul 05 15:15:46 volumio volumio[856]: info: CURURI: music-library Jul 05 15:15:46 volumio volumio[856]: error: Failed LSINFO: null Jul 05 15:15:46 volumio volumio[856]: info: Preload queue cleared Jul 05 15:15:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:15:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 122. Jul 05 15:15:48 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:15:48 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:15:48 volumio go-librespot[3689]: go-librespot daemon starting... Jul 05 15:15:48 volumio go-librespot[3689]: time="2025-07-05T15:15:48+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:15:48 volumio go-librespot[3689]: time="2025-07-05T15:15:48+09:00" level=debug msg="app state loaded" Jul 05 15:15:48 volumio go-librespot[3689]: time="2025-07-05T15:15:48+09:00" level=debug msg="stored credentials not found" Jul 05 15:15:48 volumio go-librespot[3689]: time="2025-07-05T15:15:48+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:15:48 volumio go-librespot[3689]: time="2025-07-05T15:15:48+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:15:48 volumio go-librespot[3689]: time="2025-07-05T15:15:48+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:15:48 volumio go-librespot[3689]: time="2025-07-05T15:15:48+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:15:48 volumio go-librespot[3689]: time="2025-07-05T15:15:48+09:00" level=info msg="zeroconf server listening on port 35991" Jul 05 15:15:48 volumio go-librespot[3689]: time="2025-07-05T15:15:48+09:00" level=debug msg="obtained new client token: AABP6tufLRk6e6Yxq20Mjk8yW1FXo3wOU8DIZlOm6/J/j/v7s7/C/YfEpNclo6ahUz0eEVH7juycvWoQpql7Y79L9dq/yiOd/Mu2+Ufd8H9mLoyX9SYDQGC4y8JfyxyhH9iJUSaK0l/TgpVmqx2bQHb4StUjrLvMML/ufNoBwB4OQ9AR3kc0rYoUuLmG3vCEjh/LQhDxC5onqPj221BCNS+R9SFh1GOcnv8akB9ZybzjpoEJiT+uCf7Bs/o=" Jul 05 15:15:48 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 05 15:15:48 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 05 15:15:48 volumio volumio[856]: info: Discovery: Getting this device information Jul 05 15:15:48 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Jul 05 15:15:48 volumio volumio[856]: info: CorePlayQueue::getTrack 0 Jul 05 15:15:48 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 05 15:15:48 volumio go-librespot[3689]: time="2025-07-05T15:15:48+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:15:48 volumio go-librespot[3689]: time="2025-07-05T15:15:48+09:00" level=debug msg="completed keyexchange" Jul 05 15:15:48 volumio go-librespot[3689]: time="2025-07-05T15:15:48+09:00" level=debug msg="completed challenge" Jul 05 15:15:48 volumio go-librespot[3689]: time="2025-07-05T15:15:48+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:15:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:15:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:15:48 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:48 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:51 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:51 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:51 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 05 15:15:51 volumio volumio[856]: info: Preload queue cleared Jul 05 15:15:51 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:15:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 123. Jul 05 15:15:51 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:15:51 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:15:51 volumio go-librespot[3712]: go-librespot daemon starting... Jul 05 15:15:51 volumio go-librespot[3712]: time="2025-07-05T15:15:51+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:15:51 volumio go-librespot[3712]: time="2025-07-05T15:15:51+09:00" level=debug msg="app state loaded" Jul 05 15:15:51 volumio go-librespot[3712]: time="2025-07-05T15:15:51+09:00" level=debug msg="stored credentials not found" Jul 05 15:15:51 volumio go-librespot[3712]: time="2025-07-05T15:15:51+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:15:52 volumio go-librespot[3712]: time="2025-07-05T15:15:52+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:15:52 volumio go-librespot[3712]: time="2025-07-05T15:15:52+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:15:52 volumio go-librespot[3712]: time="2025-07-05T15:15:52+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:15:52 volumio go-librespot[3712]: time="2025-07-05T15:15:52+09:00" level=info msg="zeroconf server listening on port 35899" Jul 05 15:15:52 volumio go-librespot[3712]: time="2025-07-05T15:15:52+09:00" level=debug msg="obtained new client token: AAARVoLvxzRmP+6iFzfTXQWIQsZtiK/dCeQhbLP1NVnzau0jIaAK2rKba2bc2d/9zlkkW5KYwwsOd6qXOxsoiGKkIBs1ddn47H20LvCWL1aDwoBQQytPpBVKXvc9SV/LnS/KUe/dEdW12m/8a6qekFkC6/vu89sTB6TG/IZHH5gYmSY3pwrftDJ9zp0P09sKxZnb2ejrp2bwM35I/+ub55Co2Sf4XwtOHqcKICctstb9uJdz0t8Z2L+f" Jul 05 15:15:52 volumio go-librespot[3712]: time="2025-07-05T15:15:52+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:15:52 volumio go-librespot[3712]: time="2025-07-05T15:15:52+09:00" level=debug msg="completed keyexchange" Jul 05 15:15:52 volumio go-librespot[3712]: time="2025-07-05T15:15:52+09:00" level=debug msg="completed challenge" Jul 05 15:15:52 volumio go-librespot[3712]: time="2025-07-05T15:15:52+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:15:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:15:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:15:52 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 05 15:15:53 volumio volumio[856]: info: Preload queue cleared Jul 05 15:15:54 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:54 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:55 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:15:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124. Jul 05 15:15:55 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:15:55 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:15:55 volumio go-librespot[3720]: go-librespot daemon starting... Jul 05 15:15:55 volumio go-librespot[3720]: time="2025-07-05T15:15:55+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:15:55 volumio go-librespot[3720]: time="2025-07-05T15:15:55+09:00" level=debug msg="app state loaded" Jul 05 15:15:55 volumio go-librespot[3720]: time="2025-07-05T15:15:55+09:00" level=debug msg="stored credentials not found" Jul 05 15:15:55 volumio go-librespot[3720]: time="2025-07-05T15:15:55+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:15:55 volumio go-librespot[3720]: time="2025-07-05T15:15:55+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 05 15:15:55 volumio go-librespot[3720]: time="2025-07-05T15:15:55+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jul 05 15:15:55 volumio go-librespot[3720]: time="2025-07-05T15:15:55+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jul 05 15:15:55 volumio go-librespot[3720]: time="2025-07-05T15:15:55+09:00" level=info msg="zeroconf server listening on port 37307" Jul 05 15:15:55 volumio go-librespot[3720]: time="2025-07-05T15:15:55+09:00" level=debug msg="obtained new client token: AADeDismbr74k/nEnn9Bxr3Np5t1VRVBD2GPOciOAVOKNcUYAmVXD+X5c+ITvR7DUx2HjZcxBrm9dx2gyeS1BOecZwFxNn8w5xAf8lKoGNoa2U8/c87IxC1h02kzCaLLnWACVgZ74U+/7kGKixi6T2PMXpd6viXFgFcF2bxYQs7YVLBkgxxmu5C60vTOkQe72ORQH+h9NRdZw8ler6IZq4eCQHK283sDQ2ZOsYtzRAmll9QCw4DXuNipB1w=" Jul 05 15:15:55 volumio go-librespot[3720]: time="2025-07-05T15:15:55+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:15:56 volumio go-librespot[3720]: time="2025-07-05T15:15:56+09:00" level=debug msg="completed keyexchange" Jul 05 15:15:56 volumio go-librespot[3720]: time="2025-07-05T15:15:56+09:00" level=debug msg="completed challenge" Jul 05 15:15:56 volumio go-librespot[3720]: time="2025-07-05T15:15:56+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:15:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:15:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 15:15:56 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 05 15:15:56 volumio volumio[856]: info: Preload queue cleared Jul 05 15:15:57 volumio volumio[856]: info: Initializing connection to go-librespot Websocket Jul 05 15:15:57 volumio volumio[856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 15:15:59 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 15:15:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 125. Jul 05 15:15:59 volumio systemd[1]: Stopped go-librespot Daemon. Jul 05 15:15:59 volumio systemd[1]: Started go-librespot Daemon. Jul 05 15:15:59 volumio go-librespot[3728]: go-librespot daemon starting... Jul 05 15:15:59 volumio go-librespot[3728]: time="2025-07-05T15:15:59+09:00" level=info msg="running go-librespot 0.2.0" Jul 05 15:15:59 volumio go-librespot[3728]: time="2025-07-05T15:15:59+09:00" level=debug msg="app state loaded" Jul 05 15:15:59 volumio go-librespot[3728]: time="2025-07-05T15:15:59+09:00" level=debug msg="stored credentials not found" Jul 05 15:15:59 volumio go-librespot[3728]: time="2025-07-05T15:15:59+09:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 15:15:59 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 05 15:15:59 volumio volumio[856]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 05 15:15:59 volumio volumio[856]: TypeError: Cannot read property 'length' of undefined Jul 05 15:15:59 volumio volumio[856]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jul 05 15:15:59 volumio volumio[856]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jul 05 15:15:59 volumio volumio[856]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jul 05 15:15:59 volumio volumio[856]: at Parser.emit (events.js:315:20) Jul 05 15:15:59 volumio volumio[856]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jul 05 15:15:59 volumio volumio[856]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jul 05 15:15:59 volumio volumio[856]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jul 05 15:15:59 volumio volumio[856]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jul 05 15:15:59 volumio volumio[856]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jul 05 15:15:59 volumio volumio[856]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jul 05 15:15:59 volumio volumio[856]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jul 05 15:15:59 volumio volumio[856]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jul 05 15:15:59 volumio volumio[856]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jul 05 15:15:59 volumio volumio[856]: at IncomingMessage.emit (events.js:327:22) Jul 05 15:15:59 volumio volumio[856]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 05 15:15:59 volumio volumio[856]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 05 15:15:59 volumio volumio[856]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 05 15:15:59 volumio go-librespot[3728]: time="2025-07-05T15:15:59+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 15:15:59 volumio go-librespot[3728]: time="2025-07-05T15:15:59+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 05 15:15:59 volumio go-librespot[3728]: time="2025-07-05T15:15:59+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 05 15:15:59 volumio go-librespot[3728]: time="2025-07-05T15:15:59+09:00" level=info msg="zeroconf server listening on port 36427" Jul 05 15:15:59 volumio go-librespot[3728]: time="2025-07-05T15:15:59+09:00" level=debug msg="obtained new client token: AAB1vMRIkxuYNb0mmDbhpVQSn7h0Gzq3h4U7dESxQCL2vuv2a3Efh11nLv0v4G/Xo62K/ixgFpV7wEfZJpiB1OUYxRmoQttKZERw12lr+y2hU9/p0EFnAagOPUtN71TCoNNnBj3O3UligWOHjib+cb4UejIHzBv3YmBeZfgpu8gk5TZVMR8AIXlLkzqVNfjhzLe2MFBB8Vu9KZb6FCasioLm+gZOzKIVxU/7kncO8cyOarvQxo11qrEB2eo=" Jul 05 15:15:59 volumio go-librespot[3728]: time="2025-07-05T15:15:59+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jul 05 15:15:59 volumio go-librespot[3728]: time="2025-07-05T15:15:59+09:00" level=debug msg="completed keyexchange" Jul 05 15:15:59 volumio go-librespot[3728]: time="2025-07-05T15:15:59+09:00" level=debug msg="completed challenge" Jul 05 15:15:59 volumio sudo[3744]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-05 15:14 Jul 05 15:15:59 volumio sudo[3744]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 15:15:59 volumio go-librespot[3728]: time="2025-07-05T15:15:59+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 05 15:15:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 15:15:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 09:33:57 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="354f95cf0a6c2cbcd57b1aca3179c81c"