-- Logs begin at Thu 2019-02-14 19:11:58 JST, end at Fri 2026-02-13 11:06:30 JST. --
Feb 13 11:05:01 volumiohome volumio[1337]: info: Get:1 https://apt2.volumio.org/raspbian buster InRelease [15.0 kB]
Feb 13 11:05:01 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:01.201+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:01 volumiohome volumio[1337]: info: Get:2 https://archive2.volumio.org/debian buster InRelease [54.2 kB]
Feb 13 11:05:01 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:01.244+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:01 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:01 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:02 volumiohome volumio[1337]: info: Get:3 https://apt2.volumio.org/raspbian buster/main armhf Packages [13.0 MB]
Feb 13 11:05:02 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:02.067+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:02 volumiohome volumio[1337]: info: Get:4 https://archive2.volumio.org/debian buster/main armhf Packages [400 kB]
Feb 13 11:05:02 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:02.215+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:02 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:05:02 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 81.
Feb 13 11:05:02 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:05:02 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:05:02 volumiohome go-librespot[3675]: go-librespot daemon starting...
Feb 13 11:05:02 volumiohome go-librespot[3675]: time="2026-02-13T11:05:02+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:05:02 volumiohome go-librespot[3675]: time="2026-02-13T11:05:02+09:00" level=debug msg="app state loaded"
Feb 13 11:05:02 volumiohome go-librespot[3675]: time="2026-02-13T11:05:02+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:05:02 volumiohome go-librespot[3675]: time="2026-02-13T11:05:02+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]"
Feb 13 11:05:02 volumiohome go-librespot[3675]: time="2026-02-13T11:05:02+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]"
Feb 13 11:05:02 volumiohome go-librespot[3675]: time="2026-02-13T11:05:02+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]"
Feb 13 11:05:02 volumiohome go-librespot[3675]: time="2026-02-13T11:05:02+09:00" level=info msg="zeroconf server listening on port 39585"
Feb 13 11:05:02 volumiohome go-librespot[3675]: time="2026-02-13T11:05:02+09:00" level=debug msg="obtained new client token: AAB6a+/ektE0RE9hTC9l66pV2KXrzDWI/5fyLXxin7v1AVtyOFWfzhL2gcBcjASbxpnPszEwNAvVyKEWUOHxpRITqyCjGIGyxdp1hjh5rCcwP9Z7dr5E300KRLsSFC9PCUDyAUm+bH3BsrHkad40KKNWcylDLk9eddBOd0aUz1E/CuTc5S6Acrg749F7nOuK7ydc3q/zyfBIdXI4mpMLWsk0pdbgRYwIrUVame/yCeqbIyJu8iNq1guiTGk="
Feb 13 11:05:02 volumiohome go-librespot[3675]: time="2026-02-13T11:05:02+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:05:02 volumiohome go-librespot[3675]: time="2026-02-13T11:05:02+09:00" level=debug msg="completed keyexchange"
Feb 13 11:05:02 volumiohome go-librespot[3675]: time="2026-02-13T11:05:02+09:00" level=debug msg="completed challenge"
Feb 13 11:05:02 volumiohome go-librespot[3675]: time="2026-02-13T11:05:02+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:05:02 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:05:02 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:05:04 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:04 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:05 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:05:05 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 82.
Feb 13 11:05:05 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:05:06 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:05:06 volumiohome go-librespot[3699]: go-librespot daemon starting...
Feb 13 11:05:06 volumiohome go-librespot[3699]: time="2026-02-13T11:05:06+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:05:06 volumiohome go-librespot[3699]: time="2026-02-13T11:05:06+09:00" level=debug msg="app state loaded"
Feb 13 11:05:06 volumiohome go-librespot[3699]: time="2026-02-13T11:05:06+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:05:06 volumiohome go-librespot[3699]: time="2026-02-13T11:05: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-gew4.spotify.com:80]"
Feb 13 11:05:06 volumiohome go-librespot[3699]: time="2026-02-13T11:05:06+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]"
Feb 13 11:05:06 volumiohome go-librespot[3699]: time="2026-02-13T11:05:06+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]"
Feb 13 11:05:06 volumiohome go-librespot[3699]: time="2026-02-13T11:05:06+09:00" level=info msg="zeroconf server listening on port 34173"
Feb 13 11:05:06 volumiohome go-librespot[3699]: time="2026-02-13T11:05:06+09:00" level=debug msg="obtained new client token: AADXsHjqNEsppwWkS8lV85pQ6H3dJsHL04vZPnEMzaJWexVMlB8AfZqkM2B3OSHxa05bq/Pbk/6z473DXrKSoAKc1zeKXwMnKcbe5zziwltTuR2zvnwspKdE3l1zf9MYyCc4r2FytxgYMc3v2l/34iqUU7Zf9Pe2ij1QpGJH54s8Tuy+HSGn534FjCH7pxZBqjfPiVo/h67fDc2SD36dnagylU+m1G/dzOS/Wq1+oclFASws0qAFV+h/"
Feb 13 11:05:06 volumiohome go-librespot[3699]: time="2026-02-13T11:05:06+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:05:06 volumiohome go-librespot[3699]: time="2026-02-13T11:05:06+09:00" level=debug msg="completed keyexchange"
Feb 13 11:05:06 volumiohome go-librespot[3699]: time="2026-02-13T11:05:06+09:00" level=debug msg="completed challenge"
Feb 13 11:05:06 volumiohome go-librespot[3699]: time="2026-02-13T11:05:06+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:05:06 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:05:06 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:05:07 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:07 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:08 volumiohome volumio[1337]: info: Get:5 https://apt2.volumio.org/raspbian buster/contrib armhf Packages [58.8 kB]
Feb 13 11:05:08 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:08.049+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:08 volumiohome volumio[1337]: info: Get:6 https://apt2.volumio.org/raspbian buster/non-free armhf Packages [110 kB]
Feb 13 11:05:08 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:08.079+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:08 volumiohome volumio[1337]: info: Get:7 https://apt2.volumio.org/raspbian buster/rpi armhf Packages [1360 B]
Feb 13 11:05:08 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:08.281+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:09 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:05:09 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 83.
Feb 13 11:05:09 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:05:09 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:05:09 volumiohome go-librespot[3707]: go-librespot daemon starting...
Feb 13 11:05:09 volumiohome go-librespot[3707]: time="2026-02-13T11:05:09+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:05:09 volumiohome go-librespot[3707]: time="2026-02-13T11:05:09+09:00" level=debug msg="app state loaded"
Feb 13 11:05:09 volumiohome go-librespot[3707]: time="2026-02-13T11:05:09+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:05:09 volumiohome go-librespot[3707]: time="2026-02-13T11:05:09+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]"
Feb 13 11:05:09 volumiohome go-librespot[3707]: time="2026-02-13T11:05:09+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]"
Feb 13 11:05:09 volumiohome go-librespot[3707]: time="2026-02-13T11:05:09+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]"
Feb 13 11:05:09 volumiohome go-librespot[3707]: time="2026-02-13T11:05:09+09:00" level=info msg="zeroconf server listening on port 41765"
Feb 13 11:05:10 volumiohome go-librespot[3707]: time="2026-02-13T11:05:10+09:00" level=debug msg="obtained new client token: AACumcOS23PaaoVyQehCN986iN14WTDABIxW828tLESGDA3MF2vBbs76NR3RiRLEpx14/z1yDuFV3peMOeg+57+m9VJSS9/sz2umFs175Hmx4Oui5N8HE1gazuYM7S/hyx9OOcXYp1wRvZEDmArfanWvT6WVKlp3bWPTqsSGQgIGJNRbBIxuXrS88J73cAihPr0HD3hIsuWq8+QzdeMSw1B9q/vHiHwryDn7y01uW+XXbK2vbYuznx1J"
Feb 13 11:05:10 volumiohome go-librespot[3707]: time="2026-02-13T11:05:10+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:05:10 volumiohome go-librespot[3707]: time="2026-02-13T11:05:10+09:00" level=debug msg="completed keyexchange"
Feb 13 11:05:10 volumiohome go-librespot[3707]: time="2026-02-13T11:05:10+09:00" level=debug msg="completed challenge"
Feb 13 11:05:10 volumiohome go-librespot[3707]: time="2026-02-13T11:05:10+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:05:10 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:05:10 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:05:10 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:10 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:13 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:05:13 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 84.
Feb 13 11:05:13 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:05:13 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:05:13 volumiohome go-librespot[3733]: go-librespot daemon starting...
Feb 13 11:05:13 volumiohome go-librespot[3733]: time="2026-02-13T11:05:13+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:05:13 volumiohome go-librespot[3733]: time="2026-02-13T11:05:13+09:00" level=debug msg="app state loaded"
Feb 13 11:05:13 volumiohome go-librespot[3733]: time="2026-02-13T11:05:13+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:05:13 volumiohome go-librespot[3733]: time="2026-02-13T11:05:13+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]"
Feb 13 11:05:13 volumiohome go-librespot[3733]: time="2026-02-13T11:05:13+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]"
Feb 13 11:05:13 volumiohome go-librespot[3733]: time="2026-02-13T11:05:13+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]"
Feb 13 11:05:13 volumiohome go-librespot[3733]: time="2026-02-13T11:05:13+09:00" level=info msg="zeroconf server listening on port 45783"
Feb 13 11:05:13 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:13 volumiohome go-librespot[3733]: time="2026-02-13T11:05:13+09:00" level=debug msg="new websocket client"
Feb 13 11:05:13 volumiohome volumio[1337]: info: Connection to go-librespot Websocket established
Feb 13 11:05:14 volumiohome go-librespot[3733]: time="2026-02-13T11:05:14+09:00" level=debug msg="obtained new client token: AAAdu9Sksjy03DvdXIVuwngZD5FQVIEPx8XKGiUktVhpWGr2XhbcBbJ4feZ4ld/QAc4czHJoD3rWNX6xO1+VhK1SHNP2q/r/v16xj4Wsi//u+9VLNUVx0lfl3nK2+btIwtOsvJPLeC1il4q6Bqgm6KWTN+9BpEgBPB+tU94oecxgqWbdUaYbEyDVNNCGLL1UlGY9RAZVsFrinuYGQtFyz+Oz2/kDDiVnRm6riC+8Jw9pSTqsG7EksdQcXu4="
Feb 13 11:05:14 volumiohome go-librespot[3733]: time="2026-02-13T11:05:14+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:05:14 volumiohome go-librespot[3733]: time="2026-02-13T11:05:14+09:00" level=debug msg="completed keyexchange"
Feb 13 11:05:14 volumiohome go-librespot[3733]: time="2026-02-13T11:05:14+09:00" level=debug msg="completed challenge"
Feb 13 11:05:14 volumiohome go-librespot[3733]: time="2026-02-13T11:05:14+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:05:14 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:05:14 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:05:14 volumiohome volumio[1337]: info: Connection to go-librespot Websocket closed
Feb 13 11:05:17 volumiohome volumio[1337]: info: Getting Spotify volume
Feb 13 11:05:17 volumiohome volumio[1337]: (node:1337) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:17 volumiohome volumio[1337]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Feb 13 11:05:17 volumiohome volumio[1337]: (node:1337) 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: 9)
Feb 13 11:05:17 volumiohome volumio[1337]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8
Feb 13 11:05:17 volumiohome volumio[1337]: info: CoreCommandRouter::volumioGetState
Feb 13 11:05:17 volumiohome volumio[1337]: info: CorePlayQueue::getTrack 0
Feb 13 11:05:17 volumiohome volumio[1337]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 13 11:05:17 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:17 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:17 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:05:17 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 85.
Feb 13 11:05:17 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:05:17 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:05:17 volumiohome go-librespot[3789]: go-librespot daemon starting...
Feb 13 11:05:17 volumiohome go-librespot[3789]: time="2026-02-13T11:05:17+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:05:17 volumiohome go-librespot[3789]: time="2026-02-13T11:05:17+09:00" level=debug msg="app state loaded"
Feb 13 11:05:17 volumiohome go-librespot[3789]: time="2026-02-13T11:05:17+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:05:17 volumiohome go-librespot[3789]: time="2026-02-13T11:05:17+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]"
Feb 13 11:05:17 volumiohome go-librespot[3789]: time="2026-02-13T11:05:17+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]"
Feb 13 11:05:17 volumiohome go-librespot[3789]: time="2026-02-13T11:05:17+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]"
Feb 13 11:05:17 volumiohome go-librespot[3789]: time="2026-02-13T11:05:17+09:00" level=info msg="zeroconf server listening on port 36883"
Feb 13 11:05:17 volumiohome go-librespot[3789]: time="2026-02-13T11:05:17+09:00" level=debug msg="obtained new client token: AAAfQ1rzaT+hG6Va38EVHI8uTX2IzmezWlqgMdGvNsMVzynOVmFbgUGo30Y/Q25KT7etUpCNYL63OHvC2Bd9KUprAMX0XTP1//2KfWfkE+HOOWVf15eDcVXEU/suFWAMj27G4mMdbUIaGCqLErFKJ/AhrmqGcFyxseSMdnndwj4KNYCEWAg7soiKcraZ/DlGxMAqDWJOaiLXWYZNLYc3HjbwkQ5+80/H3pZJa6rbtyRN+ic0th/L8wUX5H8="
Feb 13 11:05:17 volumiohome go-librespot[3789]: time="2026-02-13T11:05:17+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:05:17 volumiohome go-librespot[3789]: time="2026-02-13T11:05:17+09:00" level=debug msg="completed keyexchange"
Feb 13 11:05:17 volumiohome go-librespot[3789]: time="2026-02-13T11:05:17+09:00" level=debug msg="completed challenge"
Feb 13 11:05:17 volumiohome go-librespot[3789]: time="2026-02-13T11:05:17+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:05:17 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:05:17 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:05:20 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:20 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:20 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:05:20 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 86.
Feb 13 11:05:20 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:05:20 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:05:20 volumiohome go-librespot[3801]: go-librespot daemon starting...
Feb 13 11:05:20 volumiohome go-librespot[3801]: time="2026-02-13T11:05:20+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:05:20 volumiohome go-librespot[3801]: time="2026-02-13T11:05:20+09:00" level=debug msg="app state loaded"
Feb 13 11:05:20 volumiohome go-librespot[3801]: time="2026-02-13T11:05:20+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:05:20 volumiohome go-librespot[3801]: time="2026-02-13T11:05:20+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]"
Feb 13 11:05:20 volumiohome go-librespot[3801]: time="2026-02-13T11:05:20+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]"
Feb 13 11:05:20 volumiohome go-librespot[3801]: time="2026-02-13T11:05:20+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]"
Feb 13 11:05:20 volumiohome go-librespot[3801]: time="2026-02-13T11:05:20+09:00" level=info msg="zeroconf server listening on port 44933"
Feb 13 11:05:21 volumiohome go-librespot[3801]: time="2026-02-13T11:05:21+09:00" level=debug msg="obtained new client token: AADA+sQggE0XShBHYSFbAMMj8v7q2ev3/ZxDOnzWGFNEgBiJn3+TT4dOo4LKRXW87ZdF1XXIT8RqPzufKoZxUIObpR2XGWs4Xxf0EytkP5T9j0pMc3z3qPdDVRACezrAoEKbXOJ6zAG8t3psu/Qyll1w3mJIHALHv86B0zibyfZExdfKC6qXxz0p/8AyhnP5aioOwq87wckd/NvbAPuMKTvjE9LzSF1GkQUQJT4qyV6M+wrlEZ1F98ID"
Feb 13 11:05:21 volumiohome go-librespot[3801]: time="2026-02-13T11:05:21+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:05:21 volumiohome go-librespot[3801]: time="2026-02-13T11:05:21+09:00" level=debug msg="completed keyexchange"
Feb 13 11:05:21 volumiohome go-librespot[3801]: time="2026-02-13T11:05:21+09:00" level=debug msg="completed challenge"
Feb 13 11:05:21 volumiohome go-librespot[3801]: time="2026-02-13T11:05:21+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:05:21 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:05:21 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:05:23 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:23 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:24 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:05:24 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87.
Feb 13 11:05:24 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:05:24 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:05:24 volumiohome go-librespot[3823]: go-librespot daemon starting...
Feb 13 11:05:24 volumiohome go-librespot[3823]: time="2026-02-13T11:05:24+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:05:24 volumiohome go-librespot[3823]: time="2026-02-13T11:05:24+09:00" level=debug msg="app state loaded"
Feb 13 11:05:24 volumiohome go-librespot[3823]: time="2026-02-13T11:05:24+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:05:24 volumiohome go-librespot[3823]: time="2026-02-13T11:05:24+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]"
Feb 13 11:05:24 volumiohome go-librespot[3823]: time="2026-02-13T11:05:24+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]"
Feb 13 11:05:24 volumiohome go-librespot[3823]: time="2026-02-13T11:05:24+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]"
Feb 13 11:05:24 volumiohome go-librespot[3823]: time="2026-02-13T11:05:24+09:00" level=info msg="zeroconf server listening on port 34651"
Feb 13 11:05:24 volumiohome go-librespot[3823]: time="2026-02-13T11:05:24+09:00" level=debug msg="obtained new client token: AACPDxj+8iAnbkGV+/ywMd4JBBIPaUsebrvQ9MWOdJF82KURNcUPztlCkgxYa6BOmufyEwxbB8JfwD5p8Bher2IP7MGECnTHsjFpTkVU0NFdAGh6m/kjFTgJoY2YCz1vk0G4peTsYCiPjhCG007CiOEaoZu6355fkay0SVAIJRbZZ8Vn5UzB5gVIg15PsZ5vsCnMBQiVRfz6IghCsupPGCsqCcQVfafEJlrIqZiWNTmEJsJf9cTVFCttrrw="
Feb 13 11:05:24 volumiohome go-librespot[3823]: time="2026-02-13T11:05:24+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"
Feb 13 11:05:24 volumiohome go-librespot[3823]: time="2026-02-13T11:05:24+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"
Feb 13 11:05:24 volumiohome go-librespot[3823]: time="2026-02-13T11:05:24+09:00" level=debug msg="connected to ap-gae2.spotify.com:80"
Feb 13 11:05:24 volumiohome go-librespot[3823]: time="2026-02-13T11:05:24+09:00" level=debug msg="completed keyexchange"
Feb 13 11:05:24 volumiohome go-librespot[3823]: time="2026-02-13T11:05:24+09:00" level=debug msg="completed challenge"
Feb 13 11:05:24 volumiohome go-librespot[3823]: time="2026-02-13T11:05:24+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:05:24 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:05:24 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:05:26 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:26 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:26 volumiohome volumio[1337]: info: Fetched 13.7 MB in 13s (1076 kB/s)
Feb 13 11:05:26 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:26.623+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:27 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:05:27 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 88.
Feb 13 11:05:27 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:05:28 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:05:28 volumiohome go-librespot[3833]: go-librespot daemon starting...
Feb 13 11:05:28 volumiohome go-librespot[3833]: time="2026-02-13T11:05:28+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:05:28 volumiohome go-librespot[3833]: time="2026-02-13T11:05:28+09:00" level=debug msg="app state loaded"
Feb 13 11:05:28 volumiohome go-librespot[3833]: time="2026-02-13T11:05:28+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:05:28 volumiohome go-librespot[3833]: time="2026-02-13T11:05:28+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]"
Feb 13 11:05:28 volumiohome go-librespot[3833]: time="2026-02-13T11:05:28+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]"
Feb 13 11:05:28 volumiohome go-librespot[3833]: time="2026-02-13T11:05:28+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]"
Feb 13 11:05:28 volumiohome go-librespot[3833]: time="2026-02-13T11:05:28+09:00" level=info msg="zeroconf server listening on port 46017"
Feb 13 11:05:28 volumiohome go-librespot[3833]: time="2026-02-13T11:05:28+09:00" level=debug msg="obtained new client token: AADxU2Lt84uOsGAiqHPNfNrGQP3lwygSDQ3orKSF+ELrGFJPfGerBGsjk3oY/dSxlL32ZZ66MEDqazNbCfIYwvus8bGb3agM75KxcASvhn/DaBcGo7IWeie81P8YZ7++K4s2gcJPGrXpy2wned7Y6DZVG6P4VwsA0wUfCLKazugtawTgEcupTEh6p6++2pSRZphXxnfI6xpWeFqsYGMu+cPGulhNFF55p+zTfVnEuR5sOiVJCaleVS5J140="
Feb 13 11:05:28 volumiohome go-librespot[3833]: time="2026-02-13T11:05:28+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:05:28 volumiohome go-librespot[3833]: time="2026-02-13T11:05:28+09:00" level=debug msg="completed keyexchange"
Feb 13 11:05:28 volumiohome go-librespot[3833]: time="2026-02-13T11:05:28+09:00" level=debug msg="completed challenge"
Feb 13 11:05:28 volumiohome go-librespot[3833]: time="2026-02-13T11:05:28+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:05:28 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:05:28 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:05:29 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:29 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:29 volumiohome volumio[1337]: info: Reading package lists...
Feb 13 11:05:29 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:29.409+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:29 volumiohome volumio[1337]: info: Building dependency tree...
Feb 13 11:05:29 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:29.969+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:29 volumiohome volumio[1337]: info: Reading state information...
Feb 13 11:05:29 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:29.982+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:30 volumiohome volumio[1337]: info: 218 packages can be upgraded. Run 'apt list --upgradable' to see them.
Feb 13 11:05:30 volumiohome sudo[3546]: pam_unix(sudo:session): session closed for user root
Feb 13 11:05:30 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:30.027+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:30 volumiohome sudo[3842]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/usr/bin/apt -y install python3-aiohttp python3-pip
Feb 13 11:05:30 volumiohome sudo[3842]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 13 11:05:30 volumiohome volumio[1337]: info: Reading package lists...
Feb 13 11:05:30 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:30.126+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:30 volumiohome volumio[1337]: info: Building dependency tree...
Feb 13 11:05:30 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:30.591+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:30 volumiohome volumio[1337]: info: Reading state information...
Feb 13 11:05:30 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:30.600+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:31 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:05:31 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 89.
Feb 13 11:05:31 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:05:31 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:05:31 volumiohome go-librespot[3846]: go-librespot daemon starting...
Feb 13 11:05:31 volumiohome go-librespot[3846]: time="2026-02-13T11:05:31+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:05:31 volumiohome go-librespot[3846]: time="2026-02-13T11:05:31+09:00" level=debug msg="app state loaded"
Feb 13 11:05:31 volumiohome go-librespot[3846]: time="2026-02-13T11:05:31+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:05:31 volumiohome go-librespot[3846]: time="2026-02-13T11:05:31+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]"
Feb 13 11:05:31 volumiohome go-librespot[3846]: time="2026-02-13T11:05:31+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]"
Feb 13 11:05:31 volumiohome go-librespot[3846]: time="2026-02-13T11:05:31+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]"
Feb 13 11:05:31 volumiohome go-librespot[3846]: time="2026-02-13T11:05:31+09:00" level=info msg="zeroconf server listening on port 39607"
Feb 13 11:05:32 volumiohome go-librespot[3846]: time="2026-02-13T11:05:32+09:00" level=debug msg="obtained new client token: AADZmRXWKEKZzw+tjEREYTYd0NmPstAMxRz//4na30tpwoxC8TBsO33mPP2X3QeQqXhOElxx/akUmtmHpwQFUFgPLCVjfQ8M7Q/BDvgCT4MN4IHJ7p3xiZiZTb9W3N6TUw9H9WqapZihlP7As3dJ+0971KWFqkVzPDPI70n7APMP97xo8mEi7PwPyMT46bg+xbtQ0j9qlXwB+of6WZFvCqgHLgqWR5jqXMsDenI2P2QcC9jFaImvXw=="
Feb 13 11:05:32 volumiohome go-librespot[3846]: time="2026-02-13T11:05:32+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:05:32 volumiohome go-librespot[3846]: time="2026-02-13T11:05:32+09:00" level=debug msg="completed keyexchange"
Feb 13 11:05:32 volumiohome go-librespot[3846]: time="2026-02-13T11:05:32+09:00" level=debug msg="completed challenge"
Feb 13 11:05:32 volumiohome go-librespot[3846]: time="2026-02-13T11:05:32+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:05:32 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:05:32 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:05:32 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:32 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:32 volumiohome volumio[1337]: info: python3-aiohttp is already the newest version (3.5.1-1+deb10u1).
Feb 13 11:05:32 volumiohome sudo[3842]: pam_unix(sudo:session): session closed for user root
Feb 13 11:05:32 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:32.642+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:32 volumiohome volumio[1337]: info: python3-pip is already the newest version (18.1-5+rpt1).
Feb 13 11:05:32 volumiohome volumio[1337]: info: 0 upgraded, 0 newly installed, 0 to remove and 218 not upgraded.
Feb 13 11:05:32 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:32.650+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:32 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:32.651+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:32 volumiohome sudo[3854]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/tar -xvf fusiondsp.service.tar -C /
Feb 13 11:05:32 volumiohome sudo[3854]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 13 11:05:32 volumiohome volumio[1337]: info: lib/systemd/system/fusiondsp.service
Feb 13 11:05:32 volumiohome sudo[3854]: pam_unix(sudo:session): session closed for user root
Feb 13 11:05:32 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:32.665+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio[1337]: info: MiniUnz 1.01b, demo of zLib + Unz package written by Gilles Vollant
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.595+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio[1337]: info: more info at http://www.winimage.com/zLibDll/unzip.html
Feb 13 11:05:34 volumiohome volumio[1337]: info:
Feb 13 11:05:34 volumiohome volumio[1337]: info: cgui-1.0.0.zip opened
Feb 13 11:05:34 volumiohome volumio[1337]: info: creating directory: cgui/
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/LICENSE.txt
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/README.md
Feb 13 11:05:34 volumiohome volumio[1337]: info: creating directory: cgui/build/
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/robots.txt
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/logo512.png
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/asset-manifest.json
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/index.html
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/.put_statics_here
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/favicon.ico
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/logo192.png
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/.xdp-css-variables-1.css-PvrWoX
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/manifest.json
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/css-variables.css
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/precache-manifest.76db5aad1647230454f47b1e22783b54.js
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/service-worker.js
Feb 13 11:05:34 volumiohome sudo[3872]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/chown -R volumio cgui
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/precache-manifest.5e6c675b70ef6a3fe73d0209febfe347.js
Feb 13 11:05:34 volumiohome volumio[1337]: info: creating directory: cgui/build/static/
Feb 13 11:05:34 volumiohome sudo[3872]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 13 11:05:34 volumiohome volumio[1337]: info: creating directory: cgui/build/static/css/
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/css/main.d51d005e.chunk.css
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/css/main.d51d005e.chunk.css.map
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/css/2.975d6916.chunk.css.map
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/css/main.56bdf14e.chunk.css
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/css/main.56bdf14e.chunk.css.map
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/css/main.1503f6cd.css.map
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/css/2.a4c7e7cf.chunk.css.map
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/css/main.1503f6cd.css
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/css/2.975d6916.chunk.css
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/css/2.a4c7e7cf.chunk.css
Feb 13 11:05:34 volumiohome volumio[1337]: info: creating directory: cgui/build/static/media/
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/media/camilladsp.95719842.svg
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/media/camilladsp.4767ea4ad3510467418b818dc677a87e.svg
Feb 13 11:05:34 volumiohome volumio[1337]: info: creating directory: cgui/build/static/js/
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/js/2.fd49ece5.chunk.js.map
Feb 13 11:05:34 volumiohome sudo[3872]: pam_unix(sudo:session): session closed for user root
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/js/main.71e11955.js
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/js/runtime-main.422581ec.js
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/js/2.fd49ece5.chunk.js
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/js/2.c1b9df8b.chunk.js.LICENSE.txt
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/js/main.61bb6809.chunk.js
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/js/main.61bb6809.chunk.js.map
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/js/2.c1b9df8b.chunk.js
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/js/main.1b3ac690.chunk.js.map
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/js/main.71e11955.js.LICENSE.txt
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/js/main.71e11955.js.map
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/js/runtime-main.422581ec.js.map
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/js/main.1b3ac690.chunk.js
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/js/2.c1b9df8b.chunk.js.map
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/build/static/js/2.fd49ece5.chunk.js.LICENSE.txt
Feb 13 11:05:34 volumiohome volumio[1337]: info: creating directory: cgui/config/
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/config/camillagui.yml
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/config/.xdp-css-variables-1.css-ppBDuX
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/config/gui-config.yml
Feb 13 11:05:34 volumiohome volumio[1337]: info: creating directory: cgui/backend/
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/backend/filters_test.py
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/backend/version.py
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/backend/filters.py
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/backend/settings.py
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/backend/views.py
Feb 13 11:05:34 volumiohome sudo[3874]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/chgrp -R volumio cgui
Feb 13 11:05:34 volumiohome sudo[3874]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/backend/filterdefaults.py
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/backend/__init__.py
Feb 13 11:05:34 volumiohome sudo[3874]: pam_unix(sudo:session): session closed for user root
Feb 13 11:05:34 volumiohome volumio[1337]: info: creating directory: cgui/backend/__pycache__/
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/backend/__pycache__/filterdefaults.cpython-37.pyc
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/backend/__pycache__/views.cpython-37.pyc
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/backend/__pycache__/settings.cpython-37.pyc
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/backend/__pycache__/__init__.cpython-37.pyc
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/backend/__pycache__/routes.cpython-37.pyc
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/backend/__pycache__/filemanagement.cpython-37.pyc
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/backend/__pycache__/filters.cpython-37.pyc
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/backend/__pycache__/version.cpython-37.pyc
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/backend/routes.py
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/backend/filemanagement.py
Feb 13 11:05:34 volumiohome volumio[1337]: info: extracting: cgui/main.py
Feb 13 11:05:34 volumiohome sudo[3876]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/rm cgui-1.0.0.zip
Feb 13 11:05:34 volumiohome sudo[3876]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 13 11:05:34 volumiohome sudo[3876]: pam_unix(sudo:session): session closed for user root
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.768+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.769+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.769+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.770+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.770+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.771+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.772+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.772+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.773+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.773+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.774+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.774+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.775+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.775+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.776+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.781+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.782+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.783+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.783+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.784+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.785+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.785+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.786+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.787+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.787+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.788+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.789+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.789+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.790+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.791+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.792+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.793+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.793+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.794+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.795+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.796+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.796+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.797+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.798+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.798+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.799+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.800+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.803+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.803+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.805+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.806+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.808+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.809+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.810+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.811+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.812+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.812+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.813+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.814+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.815+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.816+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.816+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.817+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.816+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.817+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.819+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.820+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.821+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:34 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:34.822+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:35 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:35 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:35 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:05:35 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 90.
Feb 13 11:05:35 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:05:35 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:05:35 volumiohome go-librespot[3879]: go-librespot daemon starting...
Feb 13 11:05:35 volumiohome go-librespot[3879]: time="2026-02-13T11:05:35+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:05:35 volumiohome go-librespot[3879]: time="2026-02-13T11:05:35+09:00" level=debug msg="app state loaded"
Feb 13 11:05:35 volumiohome go-librespot[3879]: time="2026-02-13T11:05:35+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:05:35 volumiohome go-librespot[3879]: time="2026-02-13T11:05:35+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]"
Feb 13 11:05:35 volumiohome go-librespot[3879]: time="2026-02-13T11:05:35+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]"
Feb 13 11:05:35 volumiohome go-librespot[3879]: time="2026-02-13T11:05:35+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]"
Feb 13 11:05:35 volumiohome go-librespot[3879]: time="2026-02-13T11:05:35+09:00" level=info msg="zeroconf server listening on port 36615"
Feb 13 11:05:35 volumiohome go-librespot[3879]: time="2026-02-13T11:05:35+09:00" level=debug msg="obtained new client token: AAAAv2+RAKX8MIibdlTMVB69ExdEZLqqlYE/qX8/pe0IDwzAwoseDY0+7ytCbxTePbwpwTLjL2dk5uCVlPseRbM/g9GO1I+qUpHcjZ8JnYe5txMc1lrvwJRRxe9sGEQj6ev1/vwMbPQQHCfNICP/36OzpEroDpLF7CslooNpu886dK2cPnpu3WbFzLSsLK+ZDn9ojcgkO8yyQTQYrpQpPqhSueNyUPBxn6SKktxs2/j1hl+FvZpurnghPEo="
Feb 13 11:05:35 volumiohome go-librespot[3879]: time="2026-02-13T11:05:35+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:05:35 volumiohome go-librespot[3879]: time="2026-02-13T11:05:35+09:00" level=debug msg="completed keyexchange"
Feb 13 11:05:35 volumiohome go-librespot[3879]: time="2026-02-13T11:05:35+09:00" level=debug msg="completed challenge"
Feb 13 11:05:35 volumiohome go-librespot[3879]: time="2026-02-13T11:05:35+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:05:35 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:05:35 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:05:38 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:38 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:38 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:05:38 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 91.
Feb 13 11:05:38 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:05:39 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:05:39 volumiohome go-librespot[3887]: go-librespot daemon starting...
Feb 13 11:05:39 volumiohome go-librespot[3887]: time="2026-02-13T11:05:39+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:05:39 volumiohome go-librespot[3887]: time="2026-02-13T11:05:39+09:00" level=debug msg="app state loaded"
Feb 13 11:05:39 volumiohome go-librespot[3887]: time="2026-02-13T11:05:39+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:05:39 volumiohome go-librespot[3887]: time="2026-02-13T11:05:39+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]"
Feb 13 11:05:39 volumiohome go-librespot[3887]: time="2026-02-13T11:05:39+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]"
Feb 13 11:05:39 volumiohome go-librespot[3887]: time="2026-02-13T11:05:39+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]"
Feb 13 11:05:39 volumiohome go-librespot[3887]: time="2026-02-13T11:05:39+09:00" level=info msg="zeroconf server listening on port 39415"
Feb 13 11:05:39 volumiohome go-librespot[3887]: time="2026-02-13T11:05:39+09:00" level=debug msg="obtained new client token: AABplvS6F2Huq7UZoGhfEOuB/IknJ0XNHWxSccWb94kNljAXvI/ovF7W2TRcvpcXujcgti4GXnh+KGdy1TR2pKdEew49Hee4DsWMQdJHUhaunERIPwsaahRuDL6Jc6hc4ah1fW4HKD0LzFbBxq28/1ZT/fRzPOcEZwRqVFm64cPi+LHWM89Lcl9bIfc6VzLl4KlOsa4hYxItf3dXH2hEQh8RWoFzIpc/MoXt/tiJtnq3Xg/TzpPWzkrrE8I="
Feb 13 11:05:39 volumiohome go-librespot[3887]: time="2026-02-13T11:05:39+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:05:39 volumiohome go-librespot[3887]: time="2026-02-13T11:05:39+09:00" level=debug msg="completed keyexchange"
Feb 13 11:05:39 volumiohome go-librespot[3887]: time="2026-02-13T11:05:39+09:00" level=debug msg="completed challenge"
Feb 13 11:05:39 volumiohome go-librespot[3887]: time="2026-02-13T11:05:39+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:05:39 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:05:39 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:05:39 volumiohome volumio[1337]: info: Looking in indexes: https://pypi.org/simple, https://www.piwheels.org/simple
Feb 13 11:05:39 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:39.692+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:39 volumiohome volumio[1337]: info: Collecting git+https://github.com/HEnquist/pycamilladsp.git@v1.0.0
Feb 13 11:05:39 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:39.700+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:39 volumiohome volumio[1337]: info: Cloning https://github.com/HEnquist/pycamilladsp.git (to revision v1.0.0) to /tmp/pip-req-build-g1zie_tc
Feb 13 11:05:39 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:39.706+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:41 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:41 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:41 volumiohome volumio[1337]: info: Requirement already satisfied (use --upgrade to upgrade): camilladsp==1.0.0 from git+https://github.com/HEnquist/pycamilladsp.git@v1.0.0 in /usr/local/lib/python3.7/dist-packages
Feb 13 11:05:41 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:41.661+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:41 volumiohome volumio[1337]: info: Requirement already satisfied: PyYAML in /usr/local/lib/python3.7/dist-packages (from camilladsp==1.0.0) (6.0)
Feb 13 11:05:41 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:41.673+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:41 volumiohome volumio[1337]: info: Requirement already satisfied: websocket_client in /usr/local/lib/python3.7/dist-packages (from camilladsp==1.0.0) (1.3.3)
Feb 13 11:05:41 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:41.682+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:41 volumiohome volumio[1337]: info: Building wheels for collected packages: camilladsp
Feb 13 11:05:41 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:41.705+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:41 volumiohome volumio[1337]: info: Running setup.py bdist_wheel for camilladsp: started
Feb 13 11:05:41 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:41.714+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:42 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:05:42 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 92.
Feb 13 11:05:42 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:05:42 volumiohome volumio[1337]: info: Running setup.py bdist_wheel for camilladsp: finished with status 'done'
Feb 13 11:05:42 volumiohome volumio[1337]: info: Stored in directory: /tmp/pip-ephem-wheel-cache-76pq8crl/wheels/ca/47/7d/ee36beb671f74869a8e2ecb2c3fd4a28c1b7488a9c78e442b6
Feb 13 11:05:42 volumiohome volumio[1337]: info: Successfully built camilladsp
Feb 13 11:05:42 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:05:42 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:42.553+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:42 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:42.563+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:42 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:42.577+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:42 volumiohome go-librespot[3919]: go-librespot daemon starting...
Feb 13 11:05:42 volumiohome go-librespot[3919]: time="2026-02-13T11:05:42+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:05:42 volumiohome go-librespot[3919]: time="2026-02-13T11:05:42+09:00" level=debug msg="app state loaded"
Feb 13 11:05:42 volumiohome go-librespot[3919]: time="2026-02-13T11:05:42+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:05:42 volumiohome go-librespot[3919]: time="2026-02-13T11:05:42+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]"
Feb 13 11:05:42 volumiohome go-librespot[3919]: time="2026-02-13T11:05:42+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]"
Feb 13 11:05:42 volumiohome go-librespot[3919]: time="2026-02-13T11:05:42+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]"
Feb 13 11:05:42 volumiohome go-librespot[3919]: time="2026-02-13T11:05:42+09:00" level=info msg="zeroconf server listening on port 42423"
Feb 13 11:05:42 volumiohome go-librespot[3919]: time="2026-02-13T11:05:42+09:00" level=debug msg="obtained new client token: AACXVKxiEYAUeHd+9AlkOSqbg4fq8YCaKF0ztGagwrx000YtTgfn5DWQcL/t1h1cQMsCiAgkv8Qt5QhxA8cQDrsaWtEglmMAgQCLDyfn+s9EkT3OXnA7LFr7HbX6Zh4svhoMknQFUB5TJ1k34Ib3Ww3FZd+AwgvlO5LYO67YgZXClEjsVyvaVmYY6aZpUfmmRbqB12rUuKR1UU5avN7FaKkxnElPRXwSaEihF9gru/EnXWOdR6NODEoXoQU="
Feb 13 11:05:42 volumiohome go-librespot[3919]: time="2026-02-13T11:05:42+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:05:42 volumiohome go-librespot[3919]: time="2026-02-13T11:05:42+09:00" level=debug msg="completed keyexchange"
Feb 13 11:05:42 volumiohome go-librespot[3919]: time="2026-02-13T11:05:42+09:00" level=debug msg="completed challenge"
Feb 13 11:05:43 volumiohome go-librespot[3919]: time="2026-02-13T11:05:43+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:05:43 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:05:43 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:05:44 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:44 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:46 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:05:46 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93.
Feb 13 11:05:46 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:05:46 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:05:46 volumiohome go-librespot[3942]: go-librespot daemon starting...
Feb 13 11:05:46 volumiohome go-librespot[3942]: time="2026-02-13T11:05:46+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:05:46 volumiohome go-librespot[3942]: time="2026-02-13T11:05:46+09:00" level=debug msg="app state loaded"
Feb 13 11:05:46 volumiohome go-librespot[3942]: time="2026-02-13T11:05:46+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:05:46 volumiohome volumio[1337]: info: Looking in indexes: https://pypi.org/simple, https://www.piwheels.org/simple
Feb 13 11:05:46 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:46.467+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:46 volumiohome volumio[1337]: info: Collecting git+https://github.com/HEnquist/pycamilladsp-plot.git@v1.0.2
Feb 13 11:05:46 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:46.476+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:46 volumiohome volumio[1337]: info: Cloning https://github.com/HEnquist/pycamilladsp-plot.git (to revision v1.0.2) to /tmp/pip-req-build-at67ev18
Feb 13 11:05:46 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:46.484+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:46 volumiohome go-librespot[3942]: time="2026-02-13T11:05:46+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]"
Feb 13 11:05:46 volumiohome go-librespot[3942]: time="2026-02-13T11:05:46+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]"
Feb 13 11:05:46 volumiohome go-librespot[3942]: time="2026-02-13T11:05:46+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]"
Feb 13 11:05:46 volumiohome go-librespot[3942]: time="2026-02-13T11:05:46+09:00" level=info msg="zeroconf server listening on port 39407"
Feb 13 11:05:46 volumiohome go-librespot[3942]: time="2026-02-13T11:05:46+09:00" level=debug msg="obtained new client token: AAA3k3EKy7C4/hVbOkecLxfDfvaUZb0MLuSSpD5yzfI3456XeTbiPJTxXixgKmoq4rL5RXUG4M4f6EioXu9uSWHwVqDVtrw/gMMBX+Z6UChje8ezlNO0mVchoUTjZpoZ77zSfYQH5LkFrTg1AZAKtD7KRPn1P3ehHQbGXTUjHQsLKkgG/BPlcw2+T4nV8lqYbW5yAMLc0sVSQWM0OxgveCA7EkGM46O/yHKHwRqBuflkd6c0p4uVFAJ5E18="
Feb 13 11:05:46 volumiohome go-librespot[3942]: time="2026-02-13T11:05:46+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:05:46 volumiohome go-librespot[3942]: time="2026-02-13T11:05:46+09:00" level=debug msg="completed keyexchange"
Feb 13 11:05:46 volumiohome go-librespot[3942]: time="2026-02-13T11:05:46+09:00" level=debug msg="completed challenge"
Feb 13 11:05:46 volumiohome go-librespot[3942]: time="2026-02-13T11:05:46+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:05:46 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:05:46 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:05:47 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:47 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:47 volumiohome volumio[1337]: info: Requirement already satisfied (use --upgrade to upgrade): camilladsp-plot==1.0.2 from git+https://github.com/HEnquist/pycamilladsp-plot.git@v1.0.2 in /usr/local/lib/python3.7/dist-packages
Feb 13 11:05:47 volumiohome volumio[1337]: info: Requirement already satisfied: PyYAML in /usr/local/lib/python3.7/dist-packages (from camilladsp-plot==1.0.2) (6.0)
Feb 13 11:05:47 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:47.947+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:47 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:47.955+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:47 volumiohome volumio[1337]: info: Requirement already satisfied: jsonschema in /usr/local/lib/python3.7/dist-packages (from camilladsp-plot==1.0.2) (4.7.2)
Feb 13 11:05:47 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:47.961+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:48 volumiohome volumio[1337]: info: Requirement already satisfied: typing-extensions; python_version < "3.8" in /usr/local/lib/python3.7/dist-packages (from jsonschema->camilladsp-plot==1.0.2) (4.3.0)
Feb 13 11:05:48 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:48.043+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:48 volumiohome volumio[1337]: info: Requirement already satisfied: pyrsistent!=0.17.0,!=0.17.1,!=0.17.2,>=0.14.0 in /usr/local/lib/python3.7/dist-packages (from jsonschema->camilladsp-plot==1.0.2) (0.18.1)
Feb 13 11:05:48 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:48.053+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:48 volumiohome volumio[1337]: info: Requirement already satisfied: importlib-resources>=1.4.0; python_version < "3.9" in /usr/local/lib/python3.7/dist-packages (from jsonschema->camilladsp-plot==1.0.2) (5.8.0)
Feb 13 11:05:48 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:48.066+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:48 volumiohome volumio[1337]: info: Requirement already satisfied: attrs>=17.4.0 in /usr/lib/python3/dist-packages (from jsonschema->camilladsp-plot==1.0.2) (18.2.0)
Feb 13 11:05:48 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:48.119+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:48 volumiohome volumio[1337]: info: Requirement already satisfied: importlib-metadata; python_version < "3.8" in /usr/local/lib/python3.7/dist-packages (from jsonschema->camilladsp-plot==1.0.2) (4.12.0)
Feb 13 11:05:48 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:48.145+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:48 volumiohome volumio[1337]: info: Requirement already satisfied: zipp>=3.1.0; python_version < "3.10" in /usr/local/lib/python3.7/dist-packages (from importlib-resources>=1.4.0; python_version < "3.9"->jsonschema->camilladsp-plot==1.0.2) (3.8.1)
Feb 13 11:05:48 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:48.224+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:48 volumiohome volumio[1337]: info: Building wheels for collected packages: camilladsp-plot
Feb 13 11:05:48 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:48.275+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:48 volumiohome volumio[1337]: info: Running setup.py bdist_wheel for camilladsp-plot: started
Feb 13 11:05:48 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:48.287+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:49 volumiohome volumio[1337]: info: Running setup.py bdist_wheel for camilladsp-plot: finished with status 'done'
Feb 13 11:05:49 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:49.146+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:49 volumiohome volumio[1337]: info: Stored in directory: /tmp/pip-ephem-wheel-cache-fx3_g_ub/wheels/11/e1/43/8275af2f537d569c7097d202b4955f9aec629859be39dab2e9
Feb 13 11:05:49 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:49.153+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:49 volumiohome volumio[1337]: info: Successfully built camilladsp-plot
Feb 13 11:05:49 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:49.170+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:49 volumiohome volumio[1337]: info: copying hw detection script
Feb 13 11:05:49 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:49.436+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:49 volumiohome volumio[1337]: info: Detected cpu architecture as armv7l
Feb 13 11:05:49 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:49.445+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:49 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:05:49 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 94.
Feb 13 11:05:49 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:05:50 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:05:50 volumiohome go-librespot[3977]: go-librespot daemon starting...
Feb 13 11:05:50 volumiohome go-librespot[3977]: time="2026-02-13T11:05:50+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:05:50 volumiohome go-librespot[3977]: time="2026-02-13T11:05:50+09:00" level=debug msg="app state loaded"
Feb 13 11:05:50 volumiohome go-librespot[3977]: time="2026-02-13T11:05:50+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:05:50 volumiohome go-librespot[3977]: time="2026-02-13T11:05:50+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]"
Feb 13 11:05:50 volumiohome go-librespot[3977]: time="2026-02-13T11:05:50+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]"
Feb 13 11:05:50 volumiohome go-librespot[3977]: time="2026-02-13T11:05:50+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]"
Feb 13 11:05:50 volumiohome go-librespot[3977]: time="2026-02-13T11:05:50+09:00" level=info msg="zeroconf server listening on port 35581"
Feb 13 11:05:50 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:50 volumiohome go-librespot[3977]: time="2026-02-13T11:05:50+09:00" level=debug msg="new websocket client"
Feb 13 11:05:50 volumiohome volumio[1337]: info: Connection to go-librespot Websocket established
Feb 13 11:05:50 volumiohome go-librespot[3977]: time="2026-02-13T11:05:50+09:00" level=debug msg="obtained new client token: AABTBdb9ujNVLevcSHa6qZ3L0o5AIuDp2dcPX4cJuaneSOHYwMUHPywFQO6IjuQ2ESRmXMa5mbZokt476rj2NG8Cdop5q3RsTLPt/ABG3Nv6lYxVYzBb+zazhMH5E9xUCOhdLejA2YNyj4To09KBtda1XEcibZTEY8DYnjJWgmuMTOiPe1WgzLATFZJm5VXh5+KMnB8znw3ZN2k5sRDvAhz5mv/598YmLVgNx8BCUiaXNqLyDy9NZqBO"
Feb 13 11:05:50 volumiohome go-librespot[3977]: time="2026-02-13T11:05:50+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:05:50 volumiohome go-librespot[3977]: time="2026-02-13T11:05:50+09:00" level=debug msg="completed keyexchange"
Feb 13 11:05:50 volumiohome go-librespot[3977]: time="2026-02-13T11:05:50+09:00" level=debug msg="completed challenge"
Feb 13 11:05:50 volumiohome go-librespot[3977]: time="2026-02-13T11:05:50+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:05:50 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:05:50 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:05:50 volumiohome volumio[1337]: info: Connection to go-librespot Websocket closed
Feb 13 11:05:51 volumiohome sudo[3992]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/bin/cp /data/plugins/audio_interface/fusiondsp/c/hw_params_arm /data/plugins/audio_interface/fusiondsp/hw_params
Feb 13 11:05:51 volumiohome sudo[3992]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 13 11:05:51 volumiohome sudo[3992]: pam_unix(sudo:session): session closed for user root
Feb 13 11:05:51 volumiohome sudo[3994]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/bin/chmod +x /data/plugins/audio_interface/fusiondsp/hw_params
Feb 13 11:05:51 volumiohome sudo[3994]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 13 11:05:51 volumiohome sudo[3994]: pam_unix(sudo:session): session closed for user root
Feb 13 11:05:51 volumiohome sudo[3996]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/usr/bin/apt-get -y install drc
Feb 13 11:05:51 volumiohome sudo[3996]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 13 11:05:51 volumiohome volumio[1337]: info: Reading package lists...
Feb 13 11:05:51 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:51.614+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:52 volumiohome volumio[1337]: info: Building dependency tree...
Feb 13 11:05:52 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:52.063+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:52 volumiohome volumio[1337]: info: Reading state information...
Feb 13 11:05:52 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:52.074+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:52 volumiohome volumio[1337]: info: drc is already the newest version (3.2.2~dfsg0-2).
Feb 13 11:05:52 volumiohome sudo[3996]: pam_unix(sudo:session): session closed for user root
Feb 13 11:05:52 volumiohome sudo[3512]: pam_unix(sudo:session): session closed for user root
Feb 13 11:05:52 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:52.926+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:52 volumiohome volumio[1337]: info: 0 upgraded, 0 newly installed, 0 to remove and 218 not upgraded.
Feb 13 11:05:52 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:52.933+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:52 volumiohome volumio[1337]: info: Install script completed
Feb 13 11:05:52 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:52.942+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:52 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:05:52.948+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:05:52 volumiohome volumio[1337]: info: Done installing plugin.
Feb 13 11:05:52 volumiohome volumio[1337]: info: Enabling plugin fusiondsp
Feb 13 11:05:52 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Feb 13 11:05:52 volumiohome volumio[1337]: info: [{"prettyName":"FusionDsp","name":"fusiondsp","category":"audio_interface","version":"1.0.62","icon":"fa-sliders fa-rotate-90","isManuallyInstalled":false,"enabled":true,"active":false},{"prettyName":"Calm Radio","name":"calmradio","category":"music_service","version":"1.2.4","icon":"fa-heartbeat","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.2.2","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"YouTube Cast Receiver","name":"ytcr","category":"music_service","version":"1.2.0","icon":"fa-youtube","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"YouTube Music","name":"ytmusic","category":"music_service","version":"1.3.1","icon":"fa-youtube-play","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"System information","name":"Systeminfo","category":"user_interface","version":"3.0.6","icon":"fa-info-circle","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Now Playing","name":"now_playing","category":"user_interface","version":"0.5.6","icon":"fa-play-circle","isManuallyInstalled":false,"enabled":true,"active":true}]
Feb 13 11:05:52 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Feb 13 11:05:52 volumiohome volumio[1337]: info: Folder /tmp/plugins removed
Feb 13 11:05:52 volumiohome volumio[1337]: info: Folder /tmp/downloaded_plugin.zip removed
Feb 13 11:05:52 volumiohome volumio[1337]: Plugin install end detected on script
Feb 13 11:05:52 volumiohome volumio[1337]: info: Folder /data/temp removed
Feb 13 11:05:53 volumiohome volumio[1337]: info: CoreCommandRouter::getUIConfigOnPlugin
Feb 13 11:05:53 volumiohome volumio[1337]: info: FusionDsp - no preset used
Feb 13 11:05:53 volumiohome volumio[1337]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json,home-20250604.json
Feb 13 11:05:53 volumiohome volumio[1337]: info: Getting Spotify volume
Feb 13 11:05:53 volumiohome volumio[1337]: (node:1337) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:53 volumiohome volumio[1337]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Feb 13 11:05:53 volumiohome volumio[1337]: (node:1337) 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: 10)
Feb 13 11:05:53 volumiohome volumio[1337]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8
Feb 13 11:05:53 volumiohome volumio[1337]: info: CoreCommandRouter::volumioGetState
Feb 13 11:05:53 volumiohome volumio[1337]: info: CorePlayQueue::getTrack 0
Feb 13 11:05:53 volumiohome volumio[1337]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 13 11:05:53 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:53 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:53 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:05:53 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 95.
Feb 13 11:05:53 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:05:53 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:05:53 volumiohome go-librespot[4014]: go-librespot daemon starting...
Feb 13 11:05:53 volumiohome go-librespot[4014]: time="2026-02-13T11:05:53+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:05:53 volumiohome go-librespot[4014]: time="2026-02-13T11:05:53+09:00" level=debug msg="app state loaded"
Feb 13 11:05:53 volumiohome go-librespot[4014]: time="2026-02-13T11:05:53+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:05:53 volumiohome go-librespot[4014]: time="2026-02-13T11:05:53+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]"
Feb 13 11:05:53 volumiohome go-librespot[4014]: time="2026-02-13T11:05:53+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]"
Feb 13 11:05:53 volumiohome go-librespot[4014]: time="2026-02-13T11:05:53+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]"
Feb 13 11:05:53 volumiohome go-librespot[4014]: time="2026-02-13T11:05:53+09:00" level=info msg="zeroconf server listening on port 45871"
Feb 13 11:05:53 volumiohome go-librespot[4014]: time="2026-02-13T11:05:53+09:00" level=debug msg="obtained new client token: AACpYBcoOCQM12z1yRJeQqJ0lqyGzcPInjTTJSRjmBeRL4fd9ttxMfIIjizJ1lMzDEYiu1zbnuNCydnqWZ+s7cfGUqQkkT5SAMBIVcuYRMw0YWTowaAovd2lTK6PXEHFPXpicZuQ9oWP5HvuKy9TF/myf3018T9LfkmFFWwjODuh5X5BeXMCUbDBrw5KCuP7rowifPd+27ms8VbGlP39Q5WwsF9L3rVcTB4YHqhxtT9Bvjf4WSxlQohbbUA="
Feb 13 11:05:53 volumiohome go-librespot[4014]: time="2026-02-13T11:05:53+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:05:53 volumiohome go-librespot[4014]: time="2026-02-13T11:05:53+09:00" level=debug msg="completed keyexchange"
Feb 13 11:05:53 volumiohome go-librespot[4014]: time="2026-02-13T11:05:53+09:00" level=debug msg="completed challenge"
Feb 13 11:05:53 volumiohome go-librespot[4014]: time="2026-02-13T11:05:53+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:05:53 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:05:53 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:05:56 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:56 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:05:57 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:05:57 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 96.
Feb 13 11:05:57 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:05:57 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:05:57 volumiohome go-librespot[4022]: go-librespot daemon starting...
Feb 13 11:05:57 volumiohome go-librespot[4022]: time="2026-02-13T11:05:57+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:05:57 volumiohome go-librespot[4022]: time="2026-02-13T11:05:57+09:00" level=debug msg="app state loaded"
Feb 13 11:05:57 volumiohome go-librespot[4022]: time="2026-02-13T11:05:57+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:05:57 volumiohome go-librespot[4022]: time="2026-02-13T11:05:57+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]"
Feb 13 11:05:57 volumiohome go-librespot[4022]: time="2026-02-13T11:05:57+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]"
Feb 13 11:05:57 volumiohome go-librespot[4022]: time="2026-02-13T11:05:57+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]"
Feb 13 11:05:57 volumiohome go-librespot[4022]: time="2026-02-13T11:05:57+09:00" level=info msg="zeroconf server listening on port 37649"
Feb 13 11:05:57 volumiohome go-librespot[4022]: time="2026-02-13T11:05:57+09:00" level=debug msg="obtained new client token: AAB7st/cs526Y48fA6xbg0YUNwuGYWIS/DCGX1Q9VYh0QX3RWMqapbSBU1oVb+EnyONYLLHK45rX7Ofc8fTvFL6CWOR01ck3+pZiB0w/8/y2gF55j3Gb1V9/pvlW0+93NW3kZgdeqzaydYvVakOQyzxV/FLpXk0FFX7d0vsYT7+QBOzdpKoRAMCCS9gOCMM7gGJwdExK3ImxconZky06dfzxYzVOiOELIsRo5EtbMjFHtmI/V0X75LMv/dk="
Feb 13 11:05:57 volumiohome go-librespot[4022]: time="2026-02-13T11:05:57+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:05:57 volumiohome go-librespot[4022]: time="2026-02-13T11:05:57+09:00" level=debug msg="completed keyexchange"
Feb 13 11:05:57 volumiohome go-librespot[4022]: time="2026-02-13T11:05:57+09:00" level=debug msg="completed challenge"
Feb 13 11:05:57 volumiohome go-librespot[4022]: time="2026-02-13T11:05:57+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:05:57 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:05:57 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:05:59 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:05:59 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:06:00 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:06:00 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 97.
Feb 13 11:06:00 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:06:00 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:06:00 volumiohome go-librespot[4032]: go-librespot daemon starting...
Feb 13 11:06:00 volumiohome go-librespot[4032]: time="2026-02-13T11:06:00+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:06:00 volumiohome go-librespot[4032]: time="2026-02-13T11:06:00+09:00" level=debug msg="app state loaded"
Feb 13 11:06:00 volumiohome go-librespot[4032]: time="2026-02-13T11:06:00+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:06:00 volumiohome go-librespot[4032]: time="2026-02-13T11:06:00+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]"
Feb 13 11:06:00 volumiohome go-librespot[4032]: time="2026-02-13T11:06:00+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]"
Feb 13 11:06:00 volumiohome go-librespot[4032]: time="2026-02-13T11:06:00+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]"
Feb 13 11:06:00 volumiohome go-librespot[4032]: time="2026-02-13T11:06:00+09:00" level=info msg="zeroconf server listening on port 43679"
Feb 13 11:06:01 volumiohome go-librespot[4032]: time="2026-02-13T11:06:01+09:00" level=debug msg="obtained new client token: AABIHnf0Xntbn5ZzxOTeG9rrdDpOWbJ+BsP9gsL+q1MMWqVYxeK2mDafgDHbee6sdGmF+RgY3JIiFZp42FCfwqg9dOBd956MBYEtMehe/uuMr55wSY4WUnOwZpL9/UkuuEbgWPZ16mGuMJirlVJZ8CY6n/laqEmjRKHQXK74wJlJF8OW79WjDv7UAghmRdKBDIJt+L2N3rjEq1K0nOS72xb1m86GwFgTn3J7rm1tn3vHE9hgFAbqNUv1zMA="
Feb 13 11:06:01 volumiohome go-librespot[4032]: time="2026-02-13T11:06:01+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"
Feb 13 11:06:01 volumiohome go-librespot[4032]: time="2026-02-13T11:06:01+09:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 13 11:06:01 volumiohome go-librespot[4032]: time="2026-02-13T11:06:01+09:00" level=debug msg="completed keyexchange"
Feb 13 11:06:01 volumiohome go-librespot[4032]: time="2026-02-13T11:06:01+09:00" level=debug msg="completed challenge"
Feb 13 11:06:01 volumiohome go-librespot[4032]: time="2026-02-13T11:06:01+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:06:01 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:06:01 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:06:02 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:06:02 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:06:04 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:06:04 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 98.
Feb 13 11:06:04 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:06:04 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:06:04 volumiohome go-librespot[4054]: go-librespot daemon starting...
Feb 13 11:06:04 volumiohome go-librespot[4054]: time="2026-02-13T11:06:04+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:06:04 volumiohome go-librespot[4054]: time="2026-02-13T11:06:04+09:00" level=debug msg="app state loaded"
Feb 13 11:06:04 volumiohome go-librespot[4054]: time="2026-02-13T11:06:04+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:06:04 volumiohome go-librespot[4054]: time="2026-02-13T11:06:04+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]"
Feb 13 11:06:04 volumiohome go-librespot[4054]: time="2026-02-13T11:06:04+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]"
Feb 13 11:06:04 volumiohome go-librespot[4054]: time="2026-02-13T11:06:04+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]"
Feb 13 11:06:04 volumiohome go-librespot[4054]: time="2026-02-13T11:06:04+09:00" level=info msg="zeroconf server listening on port 42599"
Feb 13 11:06:04 volumiohome go-librespot[4054]: time="2026-02-13T11:06:04+09:00" level=debug msg="obtained new client token: AAAnBnHxL5zyxMpulF5NLFDnD+0vdlsgw4gyheQ5vdooHfY/bhDUHaShRfSa397EqFiloCrufTpT9ahoRhQqyA4Qp1YYzB1S9AIqNswBzt1059GdChGYArre5mKGUcG/UfKIdFbojkGqC1bbaYSt+/GwDma4l6Ky2l51+HfPijajzUrOu3KwepWdOQ0ziZBADd1bkwRGouc8xNqI92E81OiqrRr7rt0OiChPX7u73DacPB21HgVdwcdWt1E="
Feb 13 11:06:04 volumiohome go-librespot[4054]: time="2026-02-13T11:06:04+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:06:04 volumiohome go-librespot[4054]: time="2026-02-13T11:06:04+09:00" level=debug msg="completed keyexchange"
Feb 13 11:06:04 volumiohome go-librespot[4054]: time="2026-02-13T11:06:04+09:00" level=debug msg="completed challenge"
Feb 13 11:06:04 volumiohome go-librespot[4054]: time="2026-02-13T11:06:04+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:06:04 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:06:04 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:06:05 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:06:05 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:06:07 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:06:07 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99.
Feb 13 11:06:07 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:06:07 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:06:07 volumiohome go-librespot[4062]: go-librespot daemon starting...
Feb 13 11:06:07 volumiohome go-librespot[4062]: time="2026-02-13T11:06:07+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:06:07 volumiohome go-librespot[4062]: time="2026-02-13T11:06:07+09:00" level=debug msg="app state loaded"
Feb 13 11:06:07 volumiohome go-librespot[4062]: time="2026-02-13T11:06:07+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:06:07 volumiohome go-librespot[4062]: time="2026-02-13T11:06:07+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]"
Feb 13 11:06:07 volumiohome go-librespot[4062]: time="2026-02-13T11:06:07+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]"
Feb 13 11:06:07 volumiohome go-librespot[4062]: time="2026-02-13T11:06:07+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]"
Feb 13 11:06:07 volumiohome go-librespot[4062]: time="2026-02-13T11:06:07+09:00" level=info msg="zeroconf server listening on port 45003"
Feb 13 11:06:08 volumiohome go-librespot[4062]: time="2026-02-13T11:06:08+09:00" level=debug msg="obtained new client token: AADeCBOcgt2HKCoLhrOQe489J54xzLjhT7h2im/NC51DWMZ4N8rOkMI08BwLGyELn8ct8wIZ5G3lpuSgolvK44GuO4za4tBPQU8z4W/4Rb2PoH+BhosM8LkjvD5mYNNQjfpht4F9vjbk0+y1K3cuTu+1Of94vQpcn+dJ88Tobj68enpwITSaGhCWXv/+MzXnlTwHEkbY+NavaN7PkTbxvmqWG1iu+d6wLUpWjWyM7AIefIXgfgSDGCBk"
Feb 13 11:06:08 volumiohome go-librespot[4062]: time="2026-02-13T11:06:08+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:06:08 volumiohome volumio[1337]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/calmradio/volumio/buster/armhf
Feb 13 11:06:08 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:06:08.135+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:06:08 volumiohome go-librespot[4062]: time="2026-02-13T11:06:08+09:00" level=debug msg="completed keyexchange"
Feb 13 11:06:08 volumiohome go-librespot[4062]: time="2026-02-13T11:06:08+09:00" level=debug msg="completed challenge"
Feb 13 11:06:08 volumiohome go-librespot[4062]: time="2026-02-13T11:06:08+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:06:08 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:06:08 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:06:08 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:06:08 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:06:09 volumiohome volumio[1337]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/calmradio/volumio/buster/armhf
Feb 13 11:06:09 volumiohome volumio[1337]: info: CoreCommandRouter::volumioRemoveToBrowseSourcescalmradio
Feb 13 11:06:09 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 11:06:09 volumiohome volumio[1337]: Cannot find translation for source Calm Radio
Feb 13 11:06:09 volumiohome volumio[1337]: Cannot find translation for source YouTube Music
Feb 13 11:06:09 volumiohome volumio[1337]: Cannot find translation for source Spotify
Feb 13 11:06:09 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:06:09.567+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:06:09 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:06:09.571+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:06:09 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:06:09.826+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:06:09 volumiohome volumio[1337]: info: Check plugin dependencies
Feb 13 11:06:09 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 13 11:06:09 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:06:09.871+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:06:09 volumiohome volumio[1337]: info: Rename folder
Feb 13 11:06:09 volumiohome volumio[1337]: info: Folder /tmp/downloaded_plugin.zip removed
Feb 13 11:06:09 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:06:09.901+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:06:09 volumiohome volumio[1337]: info: Move to category
Feb 13 11:06:11 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:06:11.195+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:06:11 volumiohome volumio[1337]: info: Checking if install.sh is present
Feb 13 11:06:11 volumiohome volumio[1337]: info: Executing install.sh
Feb 13 11:06:11 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:06:11 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 100.
Feb 13 11:06:11 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:06:11 volumiohome sudo[4086]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/calmradio/install.sh
Feb 13 11:06:11 volumiohome sudo[4086]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 13 11:06:11 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:06:11 volumiohome volumio[1337]: Plugin install end detected on script
Feb 13 11:06:11 volumiohome volumio[1337]: info: Install script completed
Feb 13 11:06:11 volumiohome volumio[1337]: info: Done installing plugin.
Feb 13 11:06:11 volumiohome volumio[1337]: info: Enabling plugin calmradio
Feb 13 11:06:11 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Feb 13 11:06:11 volumiohome volumio[1337]: info: [{"prettyName":"FusionDsp","name":"fusiondsp","category":"audio_interface","version":"1.0.62","icon":"fa-sliders fa-rotate-90","isManuallyInstalled":false,"enabled":true,"active":false},{"prettyName":"Calm Radio","name":"calmradio","category":"music_service","version":"1.2.4","icon":"fa-heartbeat","isManuallyInstalled":false,"enabled":true,"active":false},{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.2.2","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"YouTube Cast Receiver","name":"ytcr","category":"music_service","version":"1.2.0","icon":"fa-youtube","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"YouTube Music","name":"ytmusic","category":"music_service","version":"1.3.1","icon":"fa-youtube-play","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"System information","name":"Systeminfo","category":"user_interface","version":"3.0.6","icon":"fa-info-circle","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Now Playing","name":"now_playing","category":"user_interface","version":"0.5.6","icon":"fa-play-circle","isManuallyInstalled":false,"enabled":true,"active":true}]
Feb 13 11:06:11 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Feb 13 11:06:11 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:06:11.277+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:06:11 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:06:11.282+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:06:11 volumiohome sudo[4086]: pam_unix(sudo:session): session closed for user root
Feb 13 11:06:11 volumiohome go-librespot[4087]: go-librespot daemon starting...
Feb 13 11:06:11 volumiohome volumio[1337]: info: Folder /tmp/plugins removed
Feb 13 11:06:11 volumiohome volumio[1337]: info: Folder /tmp/downloaded_plugin.zip removed
Feb 13 11:06:11 volumiohome volumio[1337]: info: Folder /data/temp removed
Feb 13 11:06:11 volumiohome go-librespot[4087]: time="2026-02-13T11:06:11+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:06:11 volumiohome go-librespot[4087]: time="2026-02-13T11:06:11+09:00" level=debug msg="app state loaded"
Feb 13 11:06:11 volumiohome go-librespot[4087]: time="2026-02-13T11:06:11+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:06:11 volumiohome volumio[1337]: info: CoreCommandRouter::getUIConfigOnPlugin
Feb 13 11:06:11 volumiohome volumio[1337]: info: FusionDsp - no preset used
Feb 13 11:06:11 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:06:11 volumiohome volumio[1337]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json,home-20250604.json
Feb 13 11:06:11 volumiohome go-librespot[4087]: time="2026-02-13T11:06:11+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]"
Feb 13 11:06:11 volumiohome go-librespot[4087]: time="2026-02-13T11:06:11+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]"
Feb 13 11:06:11 volumiohome go-librespot[4087]: time="2026-02-13T11:06:11+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]"
Feb 13 11:06:11 volumiohome go-librespot[4087]: time="2026-02-13T11:06:11+09:00" level=info msg="zeroconf server listening on port 35281"
Feb 13 11:06:11 volumiohome go-librespot[4087]: time="2026-02-13T11:06:11+09:00" level=debug msg="new websocket client"
Feb 13 11:06:11 volumiohome volumio[1337]: info: Connection to go-librespot Websocket established
Feb 13 11:06:11 volumiohome go-librespot[4087]: time="2026-02-13T11:06:11+09:00" level=debug msg="obtained new client token: AAAp+DcvgHgZZvMv0gsPiynJ3P85JZ3WiIrXeIVNoYSmRBd4aBgJf0AwUE6N3+uKIkl4wkzPXDqzsRCtiWJjPR+9bLfVgGKIIPleLSbZf+lmuhKw5boKYvPAkX+/BQ3zsgUYBJXcz6LC4zvFVwG81JySaS11DXNzbENKQKO8mz2w3IjYODCwySqLj0LSc6oOyL2ONzf9JQbhcdEtDC5yXZz5G4bV9Augk2OhXHkYS/wlW61abFzxfd/8jv0="
Feb 13 11:06:11 volumiohome go-librespot[4087]: time="2026-02-13T11:06:11+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:06:11 volumiohome go-librespot[4087]: time="2026-02-13T11:06:11+09:00" level=debug msg="completed keyexchange"
Feb 13 11:06:11 volumiohome go-librespot[4087]: time="2026-02-13T11:06:11+09:00" level=debug msg="completed challenge"
Feb 13 11:06:11 volumiohome go-librespot[4087]: time="2026-02-13T11:06:11+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:06:11 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:06:11 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:06:11 volumiohome volumio[1337]: info: Connection to go-librespot Websocket closed
Feb 13 11:06:14 volumiohome volumio[1337]: info: Getting Spotify volume
Feb 13 11:06:14 volumiohome volumio[1337]: (node:1337) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:06:14 volumiohome volumio[1337]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Feb 13 11:06:14 volumiohome volumio[1337]: (node:1337) 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: 11)
Feb 13 11:06:14 volumiohome volumio[1337]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8
Feb 13 11:06:14 volumiohome volumio[1337]: info: CoreCommandRouter::volumioGetState
Feb 13 11:06:14 volumiohome volumio[1337]: info: CorePlayQueue::getTrack 0
Feb 13 11:06:14 volumiohome volumio[1337]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 13 11:06:14 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:06:14 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:06:14 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:06:14 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 101.
Feb 13 11:06:14 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:06:14 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:06:14 volumiohome go-librespot[4110]: go-librespot daemon starting...
Feb 13 11:06:14 volumiohome go-librespot[4110]: time="2026-02-13T11:06:14+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:06:14 volumiohome go-librespot[4110]: time="2026-02-13T11:06:14+09:00" level=debug msg="app state loaded"
Feb 13 11:06:14 volumiohome go-librespot[4110]: time="2026-02-13T11:06:14+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:06:14 volumiohome go-librespot[4110]: time="2026-02-13T11:06: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 11:06:14 volumiohome go-librespot[4110]: time="2026-02-13T11:06:14+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]"
Feb 13 11:06:14 volumiohome go-librespot[4110]: time="2026-02-13T11:06:14+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]"
Feb 13 11:06:14 volumiohome go-librespot[4110]: time="2026-02-13T11:06:14+09:00" level=info msg="zeroconf server listening on port 46325"
Feb 13 11:06:15 volumiohome go-librespot[4110]: time="2026-02-13T11:06:15+09:00" level=debug msg="obtained new client token: AACsYBH9s/27ol/Bns9fe+jQKF+NuHZVqT1Y7yuBqFANJG5QRcoW/BWolf2xjKwN7P1CgNzpOFT0tnVpdMPD3Ta4JUO7p21jeoAsm2GiSYJ3eVVRNBdkeL0ZoFs48zxfYb96Ynp7kRxo0JzFW/6C2LEMoeVOVUsOOeOYJArfMnsUDOBYMxR/5OHK0PCTAedjvon6Nvfb9BvNN6Ljzx+fOGZXQxbOGOPvfpop76eFe3HGJye95537Zpo9"
Feb 13 11:06:15 volumiohome go-librespot[4110]: time="2026-02-13T11:06:15+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:06:15 volumiohome go-librespot[4110]: time="2026-02-13T11:06:15+09:00" level=debug msg="completed keyexchange"
Feb 13 11:06:15 volumiohome go-librespot[4110]: time="2026-02-13T11:06:15+09:00" level=debug msg="completed challenge"
Feb 13 11:06:15 volumiohome go-librespot[4110]: time="2026-02-13T11:06:15+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:06:15 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:06:15 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:06:17 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:06:17 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:06:18 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:06:18 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 102.
Feb 13 11:06:18 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:06:18 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:06:18 volumiohome go-librespot[4162]: go-librespot daemon starting...
Feb 13 11:06:18 volumiohome go-librespot[4162]: time="2026-02-13T11:06:18+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:06:18 volumiohome go-librespot[4162]: time="2026-02-13T11:06:18+09:00" level=debug msg="app state loaded"
Feb 13 11:06:18 volumiohome go-librespot[4162]: time="2026-02-13T11:06:18+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:06:18 volumiohome go-librespot[4162]: time="2026-02-13T11:06: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-gew1.spotify.com:80]"
Feb 13 11:06:18 volumiohome go-librespot[4162]: time="2026-02-13T11:06:18+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]"
Feb 13 11:06:18 volumiohome go-librespot[4162]: time="2026-02-13T11:06:18+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]"
Feb 13 11:06:18 volumiohome go-librespot[4162]: time="2026-02-13T11:06:18+09:00" level=info msg="zeroconf server listening on port 46541"
Feb 13 11:06:18 volumiohome go-librespot[4162]: time="2026-02-13T11:06:18+09:00" level=debug msg="obtained new client token: AADLzSECE/kCNj33SVMJUhi4ipxZuTs/e/KIwA0aqJTtcVh/wILIiGAuCpXAS7m9lVwzhF27O7CJBPjxkBEW32w9k4reXlIb2J5ja4AWQMReBPsgsXosqsX3fYTp9OK6E6kmReg36qmceNZRzva+in7U5OWmCLnTUtP6nz1kuP1ojwpe9PXQvQ2037zVoxhmW7a5SSr9yeSItdtBEUPJjU0lZO3Wv9UIYRp1+tdwy91gf3iTL1jqDUMjfXQ="
Feb 13 11:06:18 volumiohome go-librespot[4162]: time="2026-02-13T11:06:18+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"
Feb 13 11:06:18 volumiohome go-librespot[4162]: time="2026-02-13T11:06:18+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"
Feb 13 11:06:18 volumiohome go-librespot[4162]: time="2026-02-13T11:06:18+09:00" level=debug msg="connected to ap-gae2.spotify.com:80"
Feb 13 11:06:18 volumiohome go-librespot[4162]: time="2026-02-13T11:06:18+09:00" level=debug msg="completed keyexchange"
Feb 13 11:06:18 volumiohome go-librespot[4162]: time="2026-02-13T11:06:18+09:00" level=debug msg="completed challenge"
Feb 13 11:06:18 volumiohome go-librespot[4162]: time="2026-02-13T11:06:18+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:06:18 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:06:18 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:06:20 volumiohome sudo[4173]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 13 11:06:20 volumiohome sudo[4173]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 13 11:06:20 volumiohome sudo[4173]: pam_unix(sudo:session): session closed for user root
Feb 13 11:06:20 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:06:20 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:06:20 volumiohome sudo[4176]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 13 11:06:20 volumiohome sudo[4176]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 13 11:06:20 volumiohome sudo[4176]: pam_unix(sudo:session): session closed for user root
Feb 13 11:06:20 volumiohome volumio[1337]: verbose: New Socket.io Connection to 192.168.1.60 from 192.168.1.180 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7
Feb 13 11:06:20 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Feb 13 11:06:20 volumiohome volumio[1337]: info: CoreCommandRouter::volumioGetVisibleSources
Feb 13 11:06:20 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 11:06:20 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Feb 13 11:06:20 volumiohome volumio[1337]: info: CoreCommandRouter::volumioGetState
Feb 13 11:06:20 volumiohome volumio[1337]: info: CorePlayQueue::getTrack 0
Feb 13 11:06:20 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Feb 13 11:06:20 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Feb 13 11:06:20 volumiohome volumio[1337]: info: Received Get System Info
Feb 13 11:06:20 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Feb 13 11:06:20 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Feb 13 11:06:20 volumiohome volumio[1337]: info: Discovery: Getting this device information
Feb 13 11:06:20 volumiohome volumio[1337]: info: CoreCommandRouter::volumioGetState
Feb 13 11:06:20 volumiohome volumio[1337]: info: CorePlayQueue::getTrack 0
Feb 13 11:06:20 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Feb 13 11:06:20 volumiohome volumio[1337]: info: CoreCommandRouter::volumioGetState
Feb 13 11:06:20 volumiohome volumio[1337]: info: CorePlayQueue::getTrack 0
Feb 13 11:06:20 volumiohome volumio[1337]: info: Listing playlists
Feb 13 11:06:20 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Feb 13 11:06:20 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Feb 13 11:06:20 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Feb 13 11:06:21 volumiohome volumio[1337]: info: CoreCommandRouter::getUIConfigOnPlugin
Feb 13 11:06:21 volumiohome volumio[1337]: info: CoreCommandRouter::getUIConfigOnPlugin
Feb 13 11:06:21 volumiohome volumio[1337]: info: FusionDsp - no preset used
Feb 13 11:06:21 volumiohome volumio[1337]: info: FusionDsp - no preset used
Feb 13 11:06:21 volumiohome volumio[1337]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json,home-20250604.json
Feb 13 11:06:21 volumiohome volumio[1337]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json,home-20250604.json
Feb 13 11:06:21 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Feb 13 11:06:21 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:06:21 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 103.
Feb 13 11:06:21 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:06:22 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:06:22 volumiohome go-librespot[4178]: go-librespot daemon starting...
Feb 13 11:06:22 volumiohome go-librespot[4178]: time="2026-02-13T11:06:22+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:06:22 volumiohome go-librespot[4178]: time="2026-02-13T11:06:22+09:00" level=debug msg="app state loaded"
Feb 13 11:06:22 volumiohome go-librespot[4178]: time="2026-02-13T11:06:22+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:06:22 volumiohome go-librespot[4178]: time="2026-02-13T11:06:22+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]"
Feb 13 11:06:22 volumiohome go-librespot[4178]: time="2026-02-13T11:06:22+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]"
Feb 13 11:06:22 volumiohome go-librespot[4178]: time="2026-02-13T11:06:22+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]"
Feb 13 11:06:22 volumiohome go-librespot[4178]: time="2026-02-13T11:06:22+09:00" level=info msg="zeroconf server listening on port 40363"
Feb 13 11:06:22 volumiohome go-librespot[4178]: time="2026-02-13T11:06:22+09:00" level=debug msg="obtained new client token: AABQRpc0gaLmb5xhPnkxGN6T8A3EV1Pdg3ao/gy9IVyq5pFhRrJcZ20/7roP36ecNQ/y/PBB4Q50/A30xDg+LeWQ1Y4bPQaZl3F7OKaOVzmQS4BXAyNRIH7+4+dbTgCsYKATa734jrp1StU9vnH8wtmKrElaVQMBfkSFzmRaTIu816lzLMCzJulEV+pur35TLGpt97N6SYp6BNq3QYztgd45lx+9V304SAtNaAo0KXS+kyUay2izpodpuL0="
Feb 13 11:06:22 volumiohome go-librespot[4178]: time="2026-02-13T11:06:22+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:06:22 volumiohome go-librespot[4178]: time="2026-02-13T11:06:22+09:00" level=debug msg="completed keyexchange"
Feb 13 11:06:22 volumiohome go-librespot[4178]: time="2026-02-13T11:06:22+09:00" level=debug msg="completed challenge"
Feb 13 11:06:22 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard
Feb 13 11:06:22 volumiohome go-librespot[4178]: time="2026-02-13T11:06:22+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:06:22 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:06:22 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:06:22 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Feb 13 11:06:22 volumiohome volumio[1337]: info: Received Get System Info
Feb 13 11:06:22 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Feb 13 11:06:22 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Feb 13 11:06:22 volumiohome volumio[1337]: info: Discovery: Getting this device information
Feb 13 11:06:22 volumiohome volumio[1337]: info: CoreCommandRouter::volumioGetState
Feb 13 11:06:22 volumiohome volumio[1337]: info: CorePlayQueue::getTrack 0
Feb 13 11:06:22 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Feb 13 11:06:23 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Feb 13 11:06:23 volumiohome volumio[1337]: info: Received Get System Info
Feb 13 11:06:23 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Feb 13 11:06:23 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Feb 13 11:06:23 volumiohome volumio[1337]: info: Discovery: Getting this device information
Feb 13 11:06:23 volumiohome volumio[1337]: info: CoreCommandRouter::volumioGetState
Feb 13 11:06:23 volumiohome volumio[1337]: info: CorePlayQueue::getTrack 0
Feb 13 11:06:23 volumiohome volumio[1337]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Feb 13 11:06:23 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:06:23 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:06:25 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:06:25 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 104.
Feb 13 11:06:25 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:06:25 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:06:25 volumiohome go-librespot[4200]: go-librespot daemon starting...
Feb 13 11:06:25 volumiohome go-librespot[4200]: time="2026-02-13T11:06:25+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:06:25 volumiohome go-librespot[4200]: time="2026-02-13T11:06:25+09:00" level=debug msg="app state loaded"
Feb 13 11:06:25 volumiohome go-librespot[4200]: time="2026-02-13T11:06:25+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:06:25 volumiohome go-librespot[4200]: time="2026-02-13T11:06: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-gew4.spotify.com:80]"
Feb 13 11:06:25 volumiohome go-librespot[4200]: time="2026-02-13T11:06:25+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]"
Feb 13 11:06:25 volumiohome go-librespot[4200]: time="2026-02-13T11:06:25+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]"
Feb 13 11:06:25 volumiohome go-librespot[4200]: time="2026-02-13T11:06:25+09:00" level=info msg="zeroconf server listening on port 33689"
Feb 13 11:06:26 volumiohome go-librespot[4200]: time="2026-02-13T11:06:26+09:00" level=debug msg="obtained new client token: AAD4vN86/si6VwjMIFQfJMQ7aL4xevW/u3VWKHTSP0j4sQY9rjImDyYhSUK+W7hPDVC+WcFYOWdo6d7YoXe6kKAOZIA/6zNfhxkDzIeKU1aFjFKHaQmGMyEREqkb2CDNgfL8SNpLhn2iZIlV3ZETMsnvTtjG29CMTf3pxrox/Ttav04zpRKVw2eoNQdPruf3Zdtd3C6jvG8BTD71COZDtpkVqvnEqe4FhupUwQwxvCQlug14RY9nRExm"
Feb 13 11:06:26 volumiohome go-librespot[4200]: time="2026-02-13T11:06:26+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:06:26 volumiohome go-librespot[4200]: time="2026-02-13T11:06:26+09:00" level=debug msg="completed keyexchange"
Feb 13 11:06:26 volumiohome go-librespot[4200]: time="2026-02-13T11:06:26+09:00" level=debug msg="completed challenge"
Feb 13 11:06:26 volumiohome go-librespot[4200]: time="2026-02-13T11:06:26+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:06:26 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:06:26 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:06:26 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:06:26 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 11:06:28 volumiohome volumio[1337]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/fusiondsp/volumio/buster/armhf
Feb 13 11:06:28 volumiohome volumio5-onboarding[1928]: time=2026-02-13T11:06:28.153+09:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Feb 13 11:06:29 volumiohome systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Feb 13 11:06:29 volumiohome systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 105.
Feb 13 11:06:29 volumiohome systemd[1]: Stopped go-librespot Daemon.
Feb 13 11:06:29 volumiohome systemd[1]: Started go-librespot Daemon.
Feb 13 11:06:29 volumiohome go-librespot[4210]: go-librespot daemon starting...
Feb 13 11:06:29 volumiohome go-librespot[4210]: time="2026-02-13T11:06:29+09:00" level=info msg="running go-librespot 0.3.2"
Feb 13 11:06:29 volumiohome go-librespot[4210]: time="2026-02-13T11:06:29+09:00" level=debug msg="app state loaded"
Feb 13 11:06:29 volumiohome go-librespot[4210]: time="2026-02-13T11:06:29+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 11:06:29 volumiohome go-librespot[4210]: time="2026-02-13T11:06: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]"
Feb 13 11:06:29 volumiohome go-librespot[4210]: time="2026-02-13T11:06: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]"
Feb 13 11:06:29 volumiohome go-librespot[4210]: time="2026-02-13T11:06: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]"
Feb 13 11:06:29 volumiohome go-librespot[4210]: time="2026-02-13T11:06:29+09:00" level=info msg="zeroconf server listening on port 45027"
Feb 13 11:06:29 volumiohome go-librespot[4210]: time="2026-02-13T11:06:29+09:00" level=debug msg="obtained new client token: AAAxogG2H1D7lr5xYGanfYL6RHV+nJly08MbNZ8U/LyIAOtwTOobJCRpdMV0Z83htdp22Tzj3khXBb/j6Gobcl2F7n2eo4Z+zKgP8YkOZULQYs1h8cqAk0TMuZC3NFHsAuTe7ey1cnhLQVLl1P5MPKZ34C6Fi62331izGcl1uA0CelTCR0xwGDC/7jMsqfRZCuXTFu5vbM1Utf/9iDugqcoZI9BZt8zp2aIfAPGB+b8kHWtzG3VVESXhN6s="
Feb 13 11:06:29 volumiohome go-librespot[4210]: time="2026-02-13T11:06:29+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 11:06:29 volumiohome go-librespot[4210]: time="2026-02-13T11:06:29+09:00" level=debug msg="completed keyexchange"
Feb 13 11:06:29 volumiohome go-librespot[4210]: time="2026-02-13T11:06:29+09:00" level=debug msg="completed challenge"
Feb 13 11:06:29 volumiohome volumio[1337]: info: Initializing connection to go-librespot Websocket
Feb 13 11:06:29 volumiohome go-librespot[4210]: time="2026-02-13T11:06:29+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 11:06:29 volumiohome systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 11:06:29 volumiohome systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 11:06:29 volumiohome volumio[1337]: info: Error connecting to go-librespot Websocket: Error: socket hang up
Feb 13 11:06:29 volumiohome volumio[1337]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/fusiondsp/volumio/buster/armhf
Feb 13 11:06:29 volumiohome volumio[1337]: info: FusionDsp - Stopping FusionDsp service
Feb 13 11:06:29 volumiohome volumio[1337]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 13 11:06:29 volumiohome volumio[1337]: TypeError: Cannot read property 'stop' of null
Feb 13 11:06:29 volumiohome volumio[1337]: at FusionDsp.onStop (/data/plugins/audio_interface/fusiondsp/index.js:109:23)
Feb 13 11:06:29 volumiohome volumio[1337]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30)
Feb 13 11:06:29 volumiohome volumio[1337]: at /volumio/app/pluginmanager.js:956:12
Feb 13 11:06:29 volumiohome volumio[1337]: at ChildProcess.exithandler (child_process.js:299:7)
Feb 13 11:06:29 volumiohome volumio[1337]: at ChildProcess.emit (events.js:315:20)
Feb 13 11:06:29 volumiohome volumio[1337]: at maybeClose (internal/child_process.js:1048:16)
Feb 13 11:06:29 volumiohome volumio[1337]: at Socket. (internal/child_process.js:439:11)
Feb 13 11:06:29 volumiohome volumio[1337]: at Socket.emit (events.js:315:20)
Feb 13 11:06:29 volumiohome volumio[1337]: at Pipe. (net.js:673:12)
Feb 13 11:06:29 volumiohome volumio[1337]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 13 11:06:30 volumiohome sudo[4227]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-02-13 11:05
Feb 13 11:06:30 volumiohome sudo[4227]: pam_unix(sudo:session): session opened for user root by (uid=0)
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="e9612ec5034fb2e958508aaefbca2962fd6f6654"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu 05 Feb 2026 01:46:18 PM CET"
VOLUMIO_VERSION="3.908"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="3e9dbaf8f44792d26e97456a18f12823"