Feb 07 21:13:00 volumio volumio[32430]: info: Initializing connection to go-librespot Websocket Feb 07 21:13:00 volumio go-librespot[301]: time="2026-02-07T21:13:00+07:00" level=debug msg="new websocket client" Feb 07 21:13:00 volumio volumio[32430]: info: Connection to go-librespot Websocket established Feb 07 21:13:00 volumio go-librespot[301]: time="2026-02-07T21:13:00+07:00" level=debug msg="obtained new client token: AACnMjgK4K6IQb1M4gle8W991PTCiGrknYC/FT5Fh3MWhiIO5EPKrMHpsL8dkapahLAKcdHqSC0yIk4YXLbj0LYdUrYkYyOPJYozxcXN7OBOF/sSG1WQ9sXYMGe1UTpOgrF2or4uygMEZoDRk0PqkOksDo3jyHpr3Uf09LB4VqIdZM/b1zkzh6NuurV6LTqeQg1BpghRfddJTE24iZQOAkml2nMT1Q2yboiT85NloqzH4gdVyJdR/1c=" Feb 07 21:13:00 volumio go-librespot[301]: time="2026-02-07T21:13:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:13:00 volumio go-librespot[301]: time="2026-02-07T21:13:00+07:00" level=debug msg="completed keyexchange" Feb 07 21:13:00 volumio go-librespot[301]: time="2026-02-07T21:13:00+07:00" level=debug msg="completed challenge" Feb 07 21:13:00 volumio go-librespot[301]: time="2026-02-07T21:13:00+07: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 07 21:13:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:13:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:13:00 volumio volumio[32430]: info: Connection to go-librespot Websocket closed Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 21:13:00 volumio volumio[32430]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 21:13:00 volumio volumio[32430]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 21:13:00 volumio volumio[32430]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 21:13:00 volumio volumio[32430]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 21:13:00 volumio volumio[32430]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 21:13:01 volumio volumio[32430]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 21:13:01 volumio volumio[32430]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 21:13:01 volumio volumio[32430]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 21:13:01 volumio volumio[32430]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 21:13:02 volumio volumio[32430]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 21:13:02 volumio volumio[32430]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 21:13:02 volumio volumio[32430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:02 volumio volumio[32430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:02 volumio volumio[32430]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 21:13:02 volumio volumio[32430]: info: MyVolumio login type: Token Feb 07 21:13:02 volumio volumio[32430]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 21:13:02 volumio volumio[32430]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 21:13:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Feb 07 21:13:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:03 volumio go-librespot[323]: go-librespot daemon starting... Feb 07 21:13:03 volumio go-librespot[324]: time="2026-02-07T21:13:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:13:03 volumio go-librespot[324]: time="2026-02-07T21:13:03+07:00" level=debug msg="app state loaded" Feb 07 21:13:03 volumio go-librespot[324]: time="2026-02-07T21:13:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:13:04 volumio go-librespot[324]: time="2026-02-07T21:13:04+07: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 07 21:13:04 volumio go-librespot[324]: time="2026-02-07T21:13:04+07: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 07 21:13:04 volumio go-librespot[324]: time="2026-02-07T21:13:04+07: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 07 21:13:04 volumio go-librespot[324]: time="2026-02-07T21:13:04+07:00" level=info msg="zeroconf server listening on port 34583" Feb 07 21:13:04 volumio go-librespot[324]: time="2026-02-07T21:13:04+07:00" level=debug msg="obtained new client token: AAA/ze8PB45ja2OyoWtaqoi34ubp2riTinNJ8Pb/ST3c1k3ppgnutLFF6VRY2P3Y2XC7OywwKpyK/qsiZnqq6ZLD2wLseGLXZdfZNwYNOtFuaTJiWMNx8RXV0Uqfcmf4/RT139AiweoNZ9XoHJrSvxIEW8zqHVZ2DVN1kI18zvrS17JBZvXo4HUmRv/NW6sMEp4RAaZWArhrTuRhuSeaANHU4jtMEF9pyl3WoYY8sjRp6iACyS6aUzSeLQ==" Feb 07 21:13:04 volumio go-librespot[324]: time="2026-02-07T21:13:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:13:04 volumio volumio[32430]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 21:13:04 volumio volumio[32430]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 21:13:04 volumio volumio[32430]: info: Streaming services startup Feb 07 21:13:04 volumio volumio[32430]: info: Starting Streaming Daemon Feb 07 21:13:04 volumio go-librespot[324]: time="2026-02-07T21:13:04+07:00" level=debug msg="completed keyexchange" Feb 07 21:13:04 volumio go-librespot[324]: time="2026-02-07T21:13:04+07:00" level=debug msg="completed challenge" Feb 07 21:13:04 volumio sudo[335]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 21:13:04 volumio sudo[335]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:04 volumio volumio[32430]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 21:13:04 volumio go-librespot[324]: time="2026-02-07T21:13:04+07: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 07 21:13:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:13:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:13:04 volumio sudo[335]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:04 volumio volumio[32430]: info: Getting Spotify volume Feb 07 21:13:04 volumio volumio[32430]: info: Initializing connection to go-librespot Websocket Feb 07 21:13:04 volumio volumio[32430]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 21:13:04 volumio volumio[32430]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 21:13:04 volumio volumio[32430]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 07 21:13:04 volumio volumio[32430]: errno: -111, Feb 07 21:13:04 volumio volumio[32430]: code: 'ECONNREFUSED', Feb 07 21:13:04 volumio volumio[32430]: syscall: 'connect', Feb 07 21:13:04 volumio volumio[32430]: address: '127.0.0.1', Feb 07 21:13:04 volumio volumio[32430]: port: 9879, Feb 07 21:13:04 volumio volumio[32430]: response: undefined Feb 07 21:13:04 volumio volumio[32430]: } Feb 07 21:13:04 volumio volumio[32430]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 21:13:06 volumio sudo[355]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 21:12' Feb 07 21:13:06 volumio sudo[355]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:06 volumio sudo[355]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:06 volumio volumio-remote-updater[643]: [2026-02-07 21:13:06] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 21:13:06 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:13:06 volumio volumio-remote-updater[643]: [2026-02-07 21:13:06] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 21:13:06 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 21:13:06 volumio systemd[1]: volumio.service: Consumed 54.852s CPU time. Feb 07 21:13:06 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 21:13:06 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 21:13:07 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6335. Feb 07 21:13:07 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 21:13:07 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 21:13:07 volumio systemd[1]: volumio.service: Consumed 54.852s CPU time. Feb 07 21:13:07 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 21:13:07 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 21:13:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Feb 07 21:13:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:08 volumio go-librespot[385]: go-librespot daemon starting... Feb 07 21:13:08 volumio go-librespot[386]: time="2026-02-07T21:13:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:13:08 volumio go-librespot[386]: time="2026-02-07T21:13:08+07:00" level=debug msg="app state loaded" Feb 07 21:13:08 volumio go-librespot[386]: time="2026-02-07T21:13:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:13:08 volumio go-librespot[386]: time="2026-02-07T21:13:08+07: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 07 21:13:08 volumio go-librespot[386]: time="2026-02-07T21:13:08+07: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 07 21:13:08 volumio go-librespot[386]: time="2026-02-07T21:13:08+07: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 07 21:13:08 volumio go-librespot[386]: time="2026-02-07T21:13:08+07:00" level=info msg="zeroconf server listening on port 42051" Feb 07 21:13:09 volumio go-librespot[386]: time="2026-02-07T21:13:09+07:00" level=debug msg="obtained new client token: AAC/b9eszLtiNXsHVYFZpV06/aZDa9bT4Gvjm7zzPpVyu98ZFh7ebFz41aA8Rz0K6jK+6x7q3cDwG7bbEPH9Dg8T5nhnUE7nntcp+sREJAzu2epbXG8T5CjST4cCtYfzlN3egaz81O5idmA29Fquahnh64g//VI69zAEjvosx6MW4CzJM0ecVmk124X4R9VK0aF6d1C6Slzlmdj95oGWV9sM3rysDjaEl4ICZxzQQHy1Go+AAlBjq0L1Pw==" Feb 07 21:13:09 volumio go-librespot[386]: time="2026-02-07T21:13:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:13:09 volumio go-librespot[386]: time="2026-02-07T21:13:09+07:00" level=debug msg="completed keyexchange" Feb 07 21:13:09 volumio go-librespot[386]: time="2026-02-07T21:13:09+07:00" level=debug msg="completed challenge" Feb 07 21:13:09 volumio go-librespot[386]: time="2026-02-07T21:13:09+07: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 07 21:13:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:13:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:13:10 volumio volumio[367]: info: ------------------------------------------- Feb 07 21:13:10 volumio volumio[367]: info: ----- Volumio3 ---- Feb 07 21:13:10 volumio volumio[367]: info: ------------------------------------------- Feb 07 21:13:10 volumio volumio[367]: info: ----- System startup ---- Feb 07 21:13:10 volumio volumio[367]: info: ------------------------------------------- Feb 07 21:13:11 volumio volumio-remote-updater[643]: [2026-02-07 21:13:11] [connect] Successful connection Feb 07 21:13:12 volumio volumio[367]: info: MYVOLUMIO Environment detected Feb 07 21:13:12 volumio volumio[367]: info: Plugin folders cleanup Feb 07 21:13:12 volumio volumio[367]: info: Scanning into folder /volumio/app/plugins/ Feb 07 21:13:12 volumio volumio[367]: info: Scanning category audio_interface Feb 07 21:13:12 volumio volumio[367]: info: Scanning category miscellanea Feb 07 21:13:12 volumio volumio[367]: info: Scanning category music_service Feb 07 21:13:12 volumio volumio[367]: info: Scanning category plugins.json Feb 07 21:13:12 volumio volumio[367]: info: Scanning category system_controller Feb 07 21:13:12 volumio volumio[367]: info: Scanning category user_interface Feb 07 21:13:12 volumio volumio[367]: info: Scanning into folder /data/plugins/ Feb 07 21:13:12 volumio volumio[367]: info: Scanning category music_service Feb 07 21:13:12 volumio volumio[367]: info: Plugin folders cleanup completed Feb 07 21:13:12 volumio volumio[367]: info: ------------------------------------------- Feb 07 21:13:12 volumio volumio[367]: info: ----- Core plugins startup ---- Feb 07 21:13:12 volumio volumio[367]: info: ------------------------------------------- Feb 07 21:13:12 volumio volumio[367]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 21:13:12 volumio volumio[367]: info: Adding plugin upnp to MyMusic Plugins Feb 07 21:13:12 volumio volumio[367]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 21:13:12 volumio volumio[367]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 21:13:12 volumio volumio[367]: info: Loading plugins from folder /data/plugins/ Feb 07 21:13:12 volumio volumio[367]: info: Loading plugin "system"... Feb 07 21:13:12 volumio volumio[367]: info: Loading plugin "appearance"... Feb 07 21:13:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Feb 07 21:13:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:12 volumio go-librespot[405]: go-librespot daemon starting... Feb 07 21:13:12 volumio go-librespot[406]: time="2026-02-07T21:13:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:13:12 volumio go-librespot[406]: time="2026-02-07T21:13:12+07:00" level=debug msg="app state loaded" Feb 07 21:13:12 volumio go-librespot[406]: time="2026-02-07T21:13:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:13:13 volumio go-librespot[406]: time="2026-02-07T21:13:13+07: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 07 21:13:13 volumio go-librespot[406]: time="2026-02-07T21:13:13+07: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 07 21:13:13 volumio go-librespot[406]: time="2026-02-07T21:13:13+07: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 07 21:13:13 volumio go-librespot[406]: time="2026-02-07T21:13:13+07:00" level=info msg="zeroconf server listening on port 44541" Feb 07 21:13:13 volumio go-librespot[406]: time="2026-02-07T21:13:13+07:00" level=debug msg="obtained new client token: AAAKRjMEXLUCEq7aYLN2hx5VfS0+foOKu1BvY76CyH/H8tfaM1wTW4zMMapadRNwE+wZVWjRtTFLLIIyxn8WWWUvOYHIwiRJcMs8a7uypoiBRdZzel7s48VOlPPtnOSicxXxDUfKoXY+5pkBPyVJJaSlzmqvMPXbqxIxJz/mhJCxsUWCfaTvAJbHk0hLKZJNbT5GsFYtS+bBJb41K0vwKnETWGZIgL4iWIbU7MbrtAG/4ND/Q+MvJZMy6A==" Feb 07 21:13:13 volumio go-librespot[406]: time="2026-02-07T21:13:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:13:13 volumio go-librespot[406]: time="2026-02-07T21:13:13+07:00" level=debug msg="completed keyexchange" Feb 07 21:13:13 volumio go-librespot[406]: time="2026-02-07T21:13:13+07:00" level=debug msg="completed challenge" Feb 07 21:13:13 volumio go-librespot[406]: time="2026-02-07T21:13:13+07: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 07 21:13:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:13:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:13:14 volumio volumio[367]: info: Loading plugin "network"... Feb 07 21:13:14 volumio volumio[367]: info: Refreshing Cached IP Addresses Feb 07 21:13:14 volumio sudo[416]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 21:13:14 volumio sudo[416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:14 volumio sudo[416]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:14 volumio sudo[418]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 21:13:14 volumio volumio[367]: info: Loading plugin "services"... Feb 07 21:13:14 volumio sudo[418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:14 volumio volumio[367]: info: Loading plugin "alsa_controller"... Feb 07 21:13:14 volumio sudo[418]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:14 volumio sudo[426]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 21:13:14 volumio sudo[426]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:14 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 21:13:14 volumio volumio[367]: info: Loading plugin "wizard"... Feb 07 21:13:14 volumio volumio[367]: info: Loading plugin "networkfs"... Feb 07 21:13:14 volumio volumio[367]: info: Starting Udev Watcher for removable devices Feb 07 21:13:14 volumio volumio[367]: info: Ignoring mount for partition: boot Feb 07 21:13:14 volumio volumio[367]: info: Ignoring mount for partition: volumio Feb 07 21:13:14 volumio volumio[367]: info: Ignoring mount for partition: volumio_data Feb 07 21:13:14 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 21:13:14 volumio volumio[367]: info: Loading plugin "volumio_command_line_client"... Feb 07 21:13:14 volumio volumio[367]: info: Loading plugin "upnp"... Feb 07 21:13:14 volumio volumio[367]: info: [1770473594684] Starting Upmpd Daemon Feb 07 21:13:14 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 21:13:14 volumio volumio[367]: info: Loading plugin "my_music"... Feb 07 21:13:14 volumio volumio[367]: info: Loading plugin "mpd"... Feb 07 21:13:15 volumio volumio[367]: info: Loading plugin "upnp_browser"... Feb 07 21:13:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Feb 07 21:13:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:16 volumio go-librespot[450]: go-librespot daemon starting... Feb 07 21:13:16 volumio go-librespot[451]: time="2026-02-07T21:13:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:13:16 volumio go-librespot[451]: time="2026-02-07T21:13:16+07:00" level=debug msg="app state loaded" Feb 07 21:13:16 volumio go-librespot[451]: time="2026-02-07T21:13:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:13:17 volumio sudo[426]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:17 volumio go-librespot[451]: time="2026-02-07T21:13:17+07: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 07 21:13:17 volumio go-librespot[451]: time="2026-02-07T21:13:17+07: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 07 21:13:17 volumio go-librespot[451]: time="2026-02-07T21:13:17+07: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 07 21:13:17 volumio go-librespot[451]: time="2026-02-07T21:13:17+07:00" level=info msg="zeroconf server listening on port 43031" Feb 07 21:13:17 volumio go-librespot[451]: time="2026-02-07T21:13:17+07:00" level=debug msg="obtained new client token: AABjmm9dfkSap0XInp3oL9E98+eJJjxztc7hp+3vwpcMQl1jyzv25JsiefvlbEGFo6tcTbaMddGta7nNePLJgvf7rVEqMjfP+X8HgLSTRKq5HnLK+w/038Uyp9espqxlIbwqc1uyoPqJzGWkFpdfx00gIxwaxiFWd5a53JBn3CE6LYu2iDWyNYq/e6p43TY190C2BOxzeUEDlF1C1Y01qfNu0dOc0XfFcmyuSYNcxIu/HAtYVBfvoxK1rw==" Feb 07 21:13:17 volumio go-librespot[451]: time="2026-02-07T21:13:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:13:17 volumio go-librespot[451]: time="2026-02-07T21:13:17+07:00" level=debug msg="completed keyexchange" Feb 07 21:13:17 volumio go-librespot[451]: time="2026-02-07T21:13:17+07:00" level=debug msg="completed challenge" Feb 07 21:13:17 volumio go-librespot[451]: time="2026-02-07T21:13:17+07: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 07 21:13:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:13:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:13:18 volumio volumio[367]: info: Starting UPNP Browser Feb 07 21:13:18 volumio volumio[367]: info: Loading plugin "alarm-clock"... Feb 07 21:13:18 volumio volumio[367]: info: Loading plugin "airplay_emulation"... Feb 07 21:13:18 volumio volumio[367]: info: Starting Shairport Sync Feb 07 21:13:18 volumio volumio[367]: info: Loading plugin "last_100"... Feb 07 21:13:18 volumio volumio[367]: info: Loading plugin "webradio"... Feb 07 21:13:18 volumio volumio[367]: info: Loading plugin "i2s_dacs"... Feb 07 21:13:18 volumio volumio[367]: info: Loading plugin "volumiodiscovery"... Feb 07 21:13:18 volumio volumio[367]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 21:13:18 volumio volumio[367]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 21:13:18 volumio node[367]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 21:13:18 volumio volumio[367]: *** WARNING *** For more information see Feb 07 21:13:18 volumio volumio[367]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 21:13:18 volumio volumio[367]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 21:13:18 volumio volumio[367]: *** WARNING *** For more information see Feb 07 21:13:18 volumio node[367]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 21:13:18 volumio node[367]: *** WARNING *** For more information see Feb 07 21:13:18 volumio node[367]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 21:13:18 volumio node[367]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 21:13:18 volumio node[367]: *** WARNING *** For more information see Feb 07 21:13:18 volumio volumio[367]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 21:13:18 volumio volumio[367]: info: Discovery: Started advertising with name: Volumio Feb 07 21:13:19 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 21:13:19 volumio volumio[367]: info: Loading plugin "spop"... Feb 07 21:13:20 volumio volumio[367]: info: Loading plugin "ytcr"... Feb 07 21:13:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Feb 07 21:13:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:21 volumio go-librespot[460]: go-librespot daemon starting... Feb 07 21:13:21 volumio go-librespot[461]: time="2026-02-07T21:13:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:13:21 volumio go-librespot[461]: time="2026-02-07T21:13:21+07:00" level=debug msg="app state loaded" Feb 07 21:13:21 volumio go-librespot[461]: time="2026-02-07T21:13:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:13:21 volumio go-librespot[461]: time="2026-02-07T21:13:21+07: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 07 21:13:21 volumio go-librespot[461]: time="2026-02-07T21:13:21+07: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 07 21:13:21 volumio go-librespot[461]: time="2026-02-07T21:13:21+07: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 07 21:13:21 volumio go-librespot[461]: time="2026-02-07T21:13:21+07:00" level=info msg="zeroconf server listening on port 35637" Feb 07 21:13:21 volumio go-librespot[461]: time="2026-02-07T21:13:21+07:00" level=debug msg="obtained new client token: AAC3dkEYClxv3Jya7T5S835VTxr62C17wtF/8+5RBvD9Jkhne3S0MJ1pNB1zfAu875LJZi5msYBP6yOqXWrIwSnKVlWNGg89WgIy/o2OI/tD7IuDnvIIVxoYJfAluUyS4dX6U12mPz0hZjCKU6HP2Sy7TkQmrFn8TF969+gUsp8kNP9xjwwBeGBsfgjL4R0Qh71Oe00NXCeQgYJ7itxLumMKUIHxGQErRfvCfvR+BdIcb6PO+UqkJMc7rQ==" Feb 07 21:13:22 volumio go-librespot[461]: time="2026-02-07T21:13:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:13:22 volumio go-librespot[461]: time="2026-02-07T21:13:22+07:00" level=debug msg="completed keyexchange" Feb 07 21:13:22 volumio go-librespot[461]: time="2026-02-07T21:13:22+07:00" level=debug msg="completed challenge" Feb 07 21:13:22 volumio go-librespot[461]: time="2026-02-07T21:13:22+07: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 07 21:13:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:13:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:13:23 volumio volumio[367]: info: Loading plugin "ytmusic"... Feb 07 21:13:24 volumio volumio-remote-updater[643]: [2026-02-07 21:13:24] [connect] Successful connection Feb 07 21:13:24 volumio volumio[367]: info: Loading plugin "outputs"... Feb 07 21:13:24 volumio volumio[367]: info: Loading plugin "albumart"... Feb 07 21:13:24 volumio volumio[367]: info: Plugin example_plugin is not enabled Feb 07 21:13:24 volumio volumio[367]: info: Loading plugin "inputs"... Feb 07 21:13:24 volumio volumio[367]: info: Loading plugin "updater_comm"... Feb 07 21:13:24 volumio volumio[367]: info: Plugin mpdemulation is not enabled Feb 07 21:13:24 volumio volumio[367]: info: Loading plugin "rest_api"... Feb 07 21:13:24 volumio volumio[367]: info: Loading plugin "websocket"... Feb 07 21:13:24 volumio volumio[367]: info: Starting Socket.io Server version 1.7.4 Feb 07 21:13:24 volumio volumio[367]: info: Loading plugin "RoonBridge"... Feb 07 21:13:25 volumio volumio[367]: info: Applying required configuration parameters for plugin RoonBridge Feb 07 21:13:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Feb 07 21:13:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:25 volumio volumio[367]: info: Loading i18n strings for locale en Feb 07 21:13:25 volumio volumio[367]: Updating browse sources language Feb 07 21:13:25 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:13:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:25 volumio go-librespot[493]: go-librespot daemon starting... Feb 07 21:13:25 volumio go-librespot[494]: time="2026-02-07T21:13:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:13:25 volumio go-librespot[494]: time="2026-02-07T21:13:25+07:00" level=debug msg="app state loaded" Feb 07 21:13:25 volumio go-librespot[494]: time="2026-02-07T21:13:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:13:25 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 21:13:25 volumio volumio[367]: info: CoreCommandRouter::initPlayerControls Feb 07 21:13:25 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:25 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:25 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:25 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:25 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:25 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:25 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:25 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:25 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 21:13:25 volumio volumio[367]: Express server listening on port 3000 Feb 07 21:13:25 volumio volumio[367]: [Metrics] WebUI: 15s 825.95ms Feb 07 21:13:25 volumio volumio[367]: info: CoreStateMachine::resetVolumioState Feb 07 21:13:25 volumio volumio[367]: info: CoreStateMachine::getcurrentVolume Feb 07 21:13:25 volumio volumio[367]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 21:13:25 volumio volumio[482]: Forking 3 albumart workers Feb 07 21:13:25 volumio sudo[511]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 21:13:25 volumio sudo[511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:25 volumio sudo[511]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:25 volumio sudo[516]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 21:13:25 volumio sudo[516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:25 volumio sudo[516]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:25 volumio volumio[367]: info: Volumio Network Manager: Network status updated: 1 Feb 07 21:13:26 volumio go-librespot[494]: time="2026-02-07T21:13:26+07: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 07 21:13:26 volumio go-librespot[494]: time="2026-02-07T21:13:26+07: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 07 21:13:26 volumio go-librespot[494]: time="2026-02-07T21:13:26+07: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 07 21:13:26 volumio go-librespot[494]: time="2026-02-07T21:13:26+07:00" level=info msg="zeroconf server listening on port 34145" Feb 07 21:13:26 volumio volumio[367]: info: VolumeController:: Volume=100 Mute =false Feb 07 21:13:26 volumio volumio[367]: info: CoreStateMachine::pushState Feb 07 21:13:26 volumio volumio[367]: info: CorePlayQueue::getTrack 0 Feb 07 21:13:26 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 21:13:26 volumio volumio[367]: info: CoreCommandRouter::volumioPushState Feb 07 21:13:26 volumio volumio[367]: info: CoreStateMachine::updateTrackBlock Feb 07 21:13:26 volumio volumio[367]: info: CorePlayQueue::getTrackBlock Feb 07 21:13:26 volumio volumio[367]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 21:13:26 volumio go-librespot[494]: time="2026-02-07T21:13:26+07:00" level=debug msg="obtained new client token: AAB0w3vJ82cSA7EZaqKf7+LcZtgFE/QWK+GD6iJQmT4KY+oAJ5UkvluKbXbP9uLuLNkTOWpSoBUrxlrLqAI0vnDmBIO/rkOqeleNnglSJxdXazDugbaNXrADIgGAtrRaC2N2jGh2TT3daKyMs0tmZL8hbiyC53UgswGe13WFreRMeFBw8V4m77rFKjZsklRVyXCvfZSYRLhaRsB1ULI1p0lne4gdeXu2TxR9Y11sV76Y0cOAuaU0lY6ZAg==" Feb 07 21:13:26 volumio volumio-remote-updater[643]: [2026-02-07 21:13:26] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770473604 101 Feb 07 21:13:26 volumio volumio[367]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 07 21:13:26 volumio go-librespot[494]: time="2026-02-07T21:13:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:13:26 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:26 volumio volumio[367]: info: Reloading queue from file Feb 07 21:13:26 volumio volumio[367]: info: CoreStateMachine::setRepeat null single undefined Feb 07 21:13:26 volumio volumio[367]: info: CoreStateMachine::pushState Feb 07 21:13:26 volumio volumio[367]: info: CorePlayQueue::getTrack 0 Feb 07 21:13:26 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 21:13:26 volumio volumio[367]: info: CoreCommandRouter::volumioPushState Feb 07 21:13:26 volumio volumio[367]: info: CoreStateMachine::setRandom null Feb 07 21:13:26 volumio volumio[367]: info: CoreStateMachine::pushState Feb 07 21:13:26 volumio volumio[367]: info: CorePlayQueue::getTrack 0 Feb 07 21:13:26 volumio volumio[367]: info: CoreCommandRouter::volumioPushState Feb 07 21:13:26 volumio go-librespot[494]: time="2026-02-07T21:13:26+07:00" level=debug msg="completed keyexchange" Feb 07 21:13:26 volumio go-librespot[494]: time="2026-02-07T21:13:26+07:00" level=debug msg="completed challenge" Feb 07 21:13:26 volumio volumio[367]: info: Setting Device type: Raspberry PI Feb 07 21:13:26 volumio volumio[367]: info: Completed loading Core Plugins Feb 07 21:13:26 volumio volumio[367]: info: Preparing to generate the ALSA configuration file Feb 07 21:13:26 volumio go-librespot[494]: time="2026-02-07T21:13:26+07: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 07 21:13:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:13:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:13:26 volumio volumio[367]: info: VolumeController:: Volume=100 Mute =false Feb 07 21:13:26 volumio volumio[367]: info: CoreStateMachine::pushState Feb 07 21:13:26 volumio volumio[367]: info: CorePlayQueue::getTrack 0 Feb 07 21:13:26 volumio volumio[367]: info: CoreCommandRouter::volumioPushState Feb 07 21:13:26 volumio volumio[367]: info: Asound.conf file unchanged, so no further update is needed Feb 07 21:13:26 volumio volumio[367]: info: Output device has changed, restarting MPD Feb 07 21:13:26 volumio sudo[559]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 07 21:13:26 volumio volumio[367]: info: Output device has changed, restarting Shairport Sync Feb 07 21:13:26 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:26 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:26 volumio sudo[559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:26 volumio sudo[561]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 21:13:26 volumio sudo[561]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:26 volumio sudo[561]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:27 volumio sudo[563]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 21:13:27 volumio sudo[563]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:27 volumio sudo[559]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:27 volumio volumio[367]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 21:13:27 volumio volumio[367]: info: ___________ START PLUGINS ___________ Feb 07 21:13:27 volumio volumio[367]: info: ControllerMpd::onStart: Initializing MPD Feb 07 21:13:27 volumio volumio[367]: info: Creating MPD Configuration file Feb 07 21:13:27 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 21:13:27 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 21:13:27 volumio sudo[574]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 21:13:27 volumio sudo[574]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:27 volumio volumio[367]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:13:27 volumio volumio[367]: info: [1770473607241] CoreMusicLibrary::Adding element Media Servers Feb 07 21:13:27 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:13:27 volumio sudo[574]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:27 volumio sudo[576]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 21:13:27 volumio sudo[576]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:27 volumio volumio[367]: info: UPNP Browser: Client initialized successfully Feb 07 21:13:27 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 07 21:13:27 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 21:13:27 volumio systemd[1]: mpd.service: Consumed 7.251s CPU time. Feb 07 21:13:27 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 07 21:13:27 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 21:13:27 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 21:13:27 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:27 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:27 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 21:13:27 volumio volumio[367]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 21:13:27 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:27 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:27 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 21:13:27 volumio volumio[367]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 21:13:27 volumio volumio[367]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:13:27 volumio volumio[367]: info: [1770473607589] CoreMusicLibrary::Adding element Last_100 Feb 07 21:13:27 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:13:27 volumio volumio[367]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:13:27 volumio volumio[367]: info: [1770473607608] CoreMusicLibrary::Adding element Webradio Feb 07 21:13:27 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:13:27 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 21:13:27 volumio volumio[367]: info: Initializing BBC Radios Feb 07 21:13:27 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 21:13:27 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:27 volumio volumio[367]: info: Creating Spotify config file Feb 07 21:13:27 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:28 volumio sudo[585]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 21:13:28 volumio sudo[585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 21:13:28 volumio sudo[585]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:28 volumio volumio[518]: Starting albumart workers Feb 07 21:13:28 volumio volumio[514]: Starting albumart workers Feb 07 21:13:28 volumio volumio[517]: Starting albumart workers Feb 07 21:13:29 volumio volumio[367]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:13:29 volumio volumio[367]: info: [1770473609255] CoreMusicLibrary::Adding element YouTube Music Feb 07 21:13:29 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:13:29 volumio volumio[367]: Cannot find translation for source YouTube Music Feb 07 21:13:29 volumio volumio[367]: info: Volumio Calling Home Feb 07 21:13:29 volumio sudo[607]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 07 21:13:29 volumio sudo[607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:29 volumio sudo[607]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Feb 07 21:13:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:29 volumio go-librespot[612]: go-librespot daemon starting... Feb 07 21:13:30 volumio go-librespot[613]: time="2026-02-07T21:13:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:13:30 volumio volumio[367]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 07 21:13:30 volumio volumio[367]: info: Discovery: Found device Volumio Feb 07 21:13:30 volumio volumio[367]: info: CoreCommandRouter::volumioGetState Feb 07 21:13:30 volumio volumio[367]: info: CorePlayQueue::getTrack 0 Feb 07 21:13:30 volumio volumio[367]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 07 21:13:30 volumio volumio[367]: info: Discovery: Found device Volumio Feb 07 21:13:30 volumio volumio[367]: info: CoreCommandRouter::volumioGetState Feb 07 21:13:30 volumio volumio[367]: info: CorePlayQueue::getTrack 0 Feb 07 21:13:30 volumio volumio[367]: info: MPD Permissions set Feb 07 21:13:30 volumio volumio[367]: info: MPD Permissions set Feb 07 21:13:30 volumio volumio[367]: info: Upmpdcli Daemon Started Feb 07 21:13:30 volumio volumio[367]: info: Spotify config file written Feb 07 21:13:30 volumio sudo[622]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 21:13:30 volumio sudo[622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:30 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 21:13:30 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 21:13:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:30 volumio go-librespot[625]: go-librespot daemon starting... Feb 07 21:13:30 volumio sudo[622]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:30 volumio volumio[367]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 07 21:13:30 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:30 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:30 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:30 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:30 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:30 volumio go-librespot[626]: time="2026-02-07T21:13:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:13:30 volumio go-librespot[626]: time="2026-02-07T21:13:30+07:00" level=debug msg="app state loaded" Feb 07 21:13:30 volumio go-librespot[626]: time="2026-02-07T21:13:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:13:30 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:30 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:30 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:31 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:31 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:31 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:31 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:31 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:31 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:31 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:31 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:31 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:31 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:31 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:31 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:13:31 volumio volumio[367]: info: No need to fix Spotify hosts Feb 07 21:13:31 volumio go-librespot[626]: time="2026-02-07T21:13:31+07: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 07 21:13:31 volumio go-librespot[626]: time="2026-02-07T21:13:31+07: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 07 21:13:31 volumio go-librespot[626]: time="2026-02-07T21:13:31+07: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 07 21:13:31 volumio go-librespot[626]: time="2026-02-07T21:13:31+07:00" level=info msg="zeroconf server listening on port 39627" Feb 07 21:13:31 volumio volumio[367]: info: Volumio called home Feb 07 21:13:31 volumio go-librespot[626]: time="2026-02-07T21:13:31+07:00" level=debug msg="obtained new client token: AABePLQaM4SSUjvj0tk4RQyGZVL3hZlsu3L0zHz7pv5kvqHO+1T5PbyxOZKsDfTCpOnkrVI1ju5U89PfSsQNeRSEKk7oEmKpijJOBBDTys4m/7hj8/DgAidLkaF2spkUzTp4A1kBTc6lsuRiPY6IrJGKLiDS3zrK03/otFJ4hrt0985iaiWRfCtzRSIMNhR0vvzMFqpUQHNQ0LEk5+GSwfzMS6aD2yWBsma3DOTI5M4CcxKGiXAg02Cmng==" Feb 07 21:13:31 volumio go-librespot[626]: time="2026-02-07T21:13:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:13:32 volumio go-librespot[626]: time="2026-02-07T21:13:32+07:00" level=debug msg="completed keyexchange" Feb 07 21:13:32 volumio go-librespot[626]: time="2026-02-07T21:13:32+07:00" level=debug msg="completed challenge" Feb 07 21:13:32 volumio volumio[367]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 07 21:13:32 volumio volumio[367]: SPOTIFY: BQCp1Lt78gWltbMaTnXyUCsRdI6iKw5SfyqBskKc5UvDVrSoG5irLtpRlYfV60ApRMa4AgMJnNggdr2LW2hzk3ikLTa1Dh4jnEdMpr5fS7b3rKwFl09vfqPms61-4IXiR8k6Uu4HZXQXQUx9HBuKdj3A4NgeIXE2a6pvUz_IiH6AvkMHYfVlRlMyvZdxMQieLo96TbhGXJThl-FNBagqH4RxTi6NxVi36HnzrG6lqwbagTj_C6yIvYMig-IO3PhaJtykpBcna5ZJXLS9f2YYMYxjIVf0UEo81Sza2WOHmzcUL8xw6_lGn7NF Feb 07 21:13:32 volumio volumio[367]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 07 21:13:32 volumio volumio[367]: info: New Spotify access token = BQCp1Lt78gWltbMaTnXyUCsRdI6iKw5SfyqBskKc5UvDVrSoG5irLtpRlYfV60ApRMa4AgMJnNggdr2LW2hzk3ikLTa1Dh4jnEdMpr5fS7b3rKwFl09vfqPms61-4IXiR8k6Uu4HZXQXQUx9HBuKdj3A4NgeIXE2a6pvUz_IiH6AvkMHYfVlRlMyvZdxMQieLo96TbhGXJThl-FNBagqH4RxTi6NxVi36HnzrG6lqwbagTj_C6yIvYMig-IO3PhaJtykpBcna5ZJXLS9f2YYMYxjIVf0UEo81Sza2WOHmzcUL8xw6_lGn7NF Feb 07 21:13:32 volumio volumio[367]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 07 21:13:32 volumio go-librespot[626]: time="2026-02-07T21:13:32+07: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 07 21:13:32 volumio volumio[367]: info: Starting Shairport Sync Feb 07 21:13:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:13:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:13:32 volumio volumio[367]: info: Starting Shairport Sync Feb 07 21:13:32 volumio volumio[367]: info: Starting Shairport Sync Feb 07 21:13:32 volumio sudo[674]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 21:13:32 volumio sudo[674]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:32 volumio sudo[676]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 21:13:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 21:13:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 21:13:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 21:13:32 volumio systemd[1]: shairport-sync.service: Consumed 2.278s CPU time. Feb 07 21:13:32 volumio sudo[676]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:32 volumio sudo[679]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 21:13:32 volumio sudo[679]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:32 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 21:13:32 volumio sudo[674]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 21:13:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 21:13:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 21:13:32 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 21:13:32 volumio sudo[676]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:32 volumio sudo[679]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:32 volumio volumio[367]: info: Shairport-Sync Started Feb 07 21:13:32 volumio volumio[367]: Error adding Membership: Error: addMembership EINVAL Feb 07 21:13:32 volumio volumio[367]: info: Shairport-Sync Started Feb 07 21:13:32 volumio volumio[367]: info: Shairport-Sync Started Feb 07 21:13:32 volumio volumio[367]: info: CoreCommandRouter::volumioGetState Feb 07 21:13:32 volumio volumio[367]: info: CorePlayQueue::getTrack 0 Feb 07 21:13:32 volumio volumio[367]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 07 21:13:32 volumio volumio[367]: info: Spotify Successfully logged in Feb 07 21:13:32 volumio volumio[367]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:13:32 volumio volumio[367]: info: [1770473612956] CoreMusicLibrary::Adding element Spotify Feb 07 21:13:32 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:13:32 volumio volumio[367]: Cannot find translation for source YouTube Music Feb 07 21:13:32 volumio volumio[367]: Cannot find translation for source Spotify Feb 07 21:13:33 volumio volumio[367]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 07 21:13:33 volumio volumio[367]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 21:13:33 volumio volumio[367]: info: VolumeController:: Volume=100 Mute =false Feb 07 21:13:33 volumio volumio[367]: info: CoreCommandRouter::volumioGetState Feb 07 21:13:33 volumio volumio[367]: info: CorePlayQueue::getTrack 0 Feb 07 21:13:33 volumio volumio[367]: info: CoreStateMachine::pushState Feb 07 21:13:33 volumio volumio[367]: info: CorePlayQueue::getTrack 0 Feb 07 21:13:33 volumio volumio[367]: info: CoreCommandRouter::volumioPushState Feb 07 21:13:34 volumio volumio[367]: info: go-librespot daemon successfully initialized Feb 07 21:13:35 volumio mpd[605]: 2026-02-07T21:13:35 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 21:13:35 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 21:13:35 volumio sudo[576]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:35 volumio sudo[563]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 21:13:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:35 volumio volumio[367]: error: MPD error: The expression evaluated to a falsy value: Feb 07 21:13:35 volumio volumio[367]: assert.ok(self.idling) Feb 07 21:13:35 volumio volumio[367]: error: The expression evaluated to a falsy value: Feb 07 21:13:35 volumio volumio[367]: assert.ok(self.idling) Feb 07 21:13:35 volumio go-librespot[720]: go-librespot daemon starting... Feb 07 21:13:35 volumio volumio[367]: info: MPD running with PID605 Feb 07 21:13:35 volumio volumio[367]: ,establishing connection Feb 07 21:13:35 volumio volumio[367]: error: updateQueue error: null Feb 07 21:13:35 volumio go-librespot[721]: time="2026-02-07T21:13:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:13:35 volumio go-librespot[721]: time="2026-02-07T21:13:35+07:00" level=debug msg="app state loaded" Feb 07 21:13:35 volumio go-librespot[721]: time="2026-02-07T21:13:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:13:35 volumio volumio[367]: info: Completed starting Core Plugins Feb 07 21:13:35 volumio volumio[367]: info: ------------------------------------------- Feb 07 21:13:35 volumio volumio[367]: info: ----- MyVolumio plugins startup ---- Feb 07 21:13:35 volumio volumio[367]: info: ------------------------------------------- Feb 07 21:13:35 volumio volumio[367]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 21:13:35 volumio volumio[367]: error: updateQueue error: null Feb 07 21:13:35 volumio go-librespot[721]: time="2026-02-07T21:13:35+07: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 07 21:13:35 volumio go-librespot[721]: time="2026-02-07T21:13:35+07: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 07 21:13:35 volumio go-librespot[721]: time="2026-02-07T21:13:35+07: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 07 21:13:35 volumio go-librespot[721]: time="2026-02-07T21:13:35+07:00" level=info msg="zeroconf server listening on port 35301" Feb 07 21:13:36 volumio go-librespot[721]: time="2026-02-07T21:13:36+07:00" level=debug msg="obtained new client token: AAC6MigFn15JH0I6ve6bbv24OnXQ8kSWS5+CJeEyMeco/Cs3QGlHpWDrQueKSu7IKcd+7fJkMxA/fCEHXV72im8nwxbixc80zGlz2UPpVOmOSRnqqRU61ASMez91hOzMExtCaYI6OrQZdsdj5FzrVc9I1H9rDiwbfLWDhXARxW1Prp0Hi+pqnxuej6DfV6V9V8/g1NA2D9ta9kG9AjSIdOKsyUitY7Sc/SAh1tn6XEUhcAwBBdSNoVI=" Feb 07 21:13:36 volumio go-librespot[721]: time="2026-02-07T21:13:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:13:36 volumio go-librespot[721]: time="2026-02-07T21:13:36+07:00" level=debug msg="completed keyexchange" Feb 07 21:13:36 volumio go-librespot[721]: time="2026-02-07T21:13:36+07:00" level=debug msg="completed challenge" Feb 07 21:13:36 volumio go-librespot[721]: time="2026-02-07T21:13:36+07: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 07 21:13:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:13:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:13:37 volumio volumio[367]: info: Initializing connection to go-librespot Websocket Feb 07 21:13:37 volumio volumio[367]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 21:13:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 21:13:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:39 volumio go-librespot[729]: go-librespot daemon starting... Feb 07 21:13:39 volumio go-librespot[730]: time="2026-02-07T21:13:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:13:39 volumio go-librespot[730]: time="2026-02-07T21:13:39+07:00" level=debug msg="app state loaded" Feb 07 21:13:39 volumio go-librespot[730]: time="2026-02-07T21:13:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:13:40 volumio go-librespot[730]: time="2026-02-07T21:13:40+07: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 07 21:13:40 volumio go-librespot[730]: time="2026-02-07T21:13:40+07: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 07 21:13:40 volumio go-librespot[730]: time="2026-02-07T21:13:40+07: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 07 21:13:40 volumio go-librespot[730]: time="2026-02-07T21:13:40+07:00" level=info msg="zeroconf server listening on port 39731" Feb 07 21:13:40 volumio volumio[367]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 21:13:40 volumio go-librespot[730]: time="2026-02-07T21:13:40+07:00" level=debug msg="obtained new client token: AACmtLoH4l/QUUNhBm2sVHBEGwfQOpdNwcBB5pAq52Bj74AyFLL7I6Md1mLfZ44PVLjRtrJrXPPoQbO35KppUltCmtVkw8upr0/iEEY42SWheiV7Oqh5ue9xjA6seiYWQFfC5jJE0pxiDBS641U85ITwopgMUqKJE8zNwWciSKFnta9yC/Nae/zjbvxFrf3cnhu6v7BSnknVwm84dRwlI8DgyYwEKIMoPl8zFhccjqRLy7sre7PfSGLB8w==" Feb 07 21:13:40 volumio go-librespot[730]: time="2026-02-07T21:13:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:13:40 volumio go-librespot[730]: time="2026-02-07T21:13:40+07:00" level=debug msg="completed keyexchange" Feb 07 21:13:40 volumio go-librespot[730]: time="2026-02-07T21:13:40+07:00" level=debug msg="completed challenge" Feb 07 21:13:40 volumio go-librespot[730]: time="2026-02-07T21:13:40+07: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 07 21:13:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:13:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:13:40 volumio volumio[367]: info: Initializing connection to go-librespot Websocket Feb 07 21:13:40 volumio volumio[367]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 21:13:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 21:13:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:43 volumio go-librespot[737]: go-librespot daemon starting... Feb 07 21:13:43 volumio volumio[367]: info: Initializing connection to go-librespot Websocket Feb 07 21:13:43 volumio volumio[367]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 21:13:43 volumio go-librespot[738]: time="2026-02-07T21:13:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:13:43 volumio go-librespot[738]: time="2026-02-07T21:13:43+07:00" level=debug msg="app state loaded" Feb 07 21:13:43 volumio go-librespot[738]: time="2026-02-07T21:13:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 21:13:44 volumio volumio[367]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 21:13:44 volumio volumio[367]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 21:13:44 volumio volumio[367]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 21:13:44 volumio volumio[367]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 21:13:44 volumio volumio[367]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 21:13:44 volumio volumio[367]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 21:13:44 volumio volumio[367]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 21:13:44 volumio volumio[367]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 21:13:44 volumio go-librespot[738]: time="2026-02-07T21:13:44+07: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 07 21:13:44 volumio go-librespot[738]: time="2026-02-07T21:13:44+07: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 07 21:13:44 volumio go-librespot[738]: time="2026-02-07T21:13:44+07: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 07 21:13:44 volumio go-librespot[738]: time="2026-02-07T21:13:44+07:00" level=info msg="zeroconf server listening on port 39883" Feb 07 21:13:44 volumio go-librespot[738]: time="2026-02-07T21:13:44+07:00" level=debug msg="obtained new client token: AAD8TLRPSxZ+X5u63GL+FGEH8d7cEH7rdRrAx7iMnc+5JkjxfxG7PcX1oZ9QIbRlpNFJx/O56kvD5sT6Ng3PAZrqNu7TopdqqMgsau06v5uACMJb0ffO7EslI/MwqgHCj+gZs6/UR62mUNjim4zAHPJfnV59qvj5hjWWGCjr7fyLwcB/Xazt1bLwbkkepxm9vGNtDYwHNqPu29QVtyrI3VLcotza0EEQfjSXkkFCFGKAoacV7MONi7fltA==" Feb 07 21:13:44 volumio go-librespot[738]: time="2026-02-07T21:13:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:13:44 volumio go-librespot[738]: time="2026-02-07T21:13:44+07:00" level=debug msg="completed keyexchange" Feb 07 21:13:44 volumio go-librespot[738]: time="2026-02-07T21:13:44+07:00" level=debug msg="completed challenge" Feb 07 21:13:44 volumio go-librespot[738]: time="2026-02-07T21:13:44+07: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 07 21:13:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:13:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:13:46 volumio volumio[367]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 21:13:46 volumio volumio[367]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 21:13:46 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:46 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:46 volumio volumio[367]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 21:13:46 volumio volumio[367]: info: MyVolumio login type: Token Feb 07 21:13:46 volumio volumio[367]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 21:13:46 volumio volumio[367]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 21:13:47 volumio volumio[367]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 21:13:47 volumio volumio[367]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 21:13:47 volumio volumio[367]: info: Streaming services startup Feb 07 21:13:47 volumio volumio[367]: info: Starting Streaming Daemon Feb 07 21:13:47 volumio sudo[765]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 21:13:47 volumio sudo[765]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:47 volumio volumio[367]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 21:13:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 07 21:13:48 volumio sudo[765]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:48 volumio volumio[367]: info: Initializing connection to go-librespot Websocket Feb 07 21:13:48 volumio volumio[367]: error: Cannot start Volumio Streaming Daemon Feb 07 21:13:48 volumio volumio[367]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 21:13:48 volumio volumio[367]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 21:13:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:48 volumio go-librespot[771]: go-librespot daemon starting... Feb 07 21:13:48 volumio volumio[367]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 21:13:48 volumio go-librespot[773]: time="2026-02-07T21:13:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:13:48 volumio go-librespot[773]: time="2026-02-07T21:13:48+07:00" level=debug msg="app state loaded" Feb 07 21:13:48 volumio go-librespot[773]: time="2026-02-07T21:13:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:13:48 volumio go-librespot[773]: time="2026-02-07T21:13:48+07: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 07 21:13:48 volumio go-librespot[773]: time="2026-02-07T21:13:48+07: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 07 21:13:48 volumio go-librespot[773]: time="2026-02-07T21:13:48+07: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 07 21:13:48 volumio go-librespot[773]: time="2026-02-07T21:13:48+07:00" level=info msg="zeroconf server listening on port 46207" Feb 07 21:13:48 volumio go-librespot[773]: time="2026-02-07T21:13:48+07:00" level=debug msg="obtained new client token: AACsbTXnlWnWp58Ck3pX9Lfes8Xhp7YLmZm7PCtu/Ipe2zmNU9KdEMJlpve8Aq21220bZrT24YAfEXdiD33X5KtYN69+Ee8ixq6IBKawCP37oPRMaq8bcrWd5pIfyfkafQYj0sg0WOEUcU/XNIXmNH7FGrNF1sPrliFGYfGKfLzb6O6BnFkaUlEN+P8IZrrfDXmcZ8JKP3YCsYhRZr7xI7SwpMHZ6T2W3q4u5A4mu5M8GqtIf8MJr/D2xA==" Feb 07 21:13:49 volumio volumio[367]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 07 21:13:49 volumio go-librespot[773]: time="2026-02-07T21:13:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:13:49 volumio go-librespot[773]: time="2026-02-07T21:13:49+07:00" level=debug msg="completed keyexchange" Feb 07 21:13:49 volumio go-librespot[773]: time="2026-02-07T21:13:49+07:00" level=debug msg="completed challenge" Feb 07 21:13:49 volumio go-librespot[773]: time="2026-02-07T21:13:49+07: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 07 21:13:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:13:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:13:49 volumio volumio[367]: info: MyVolumio token set successfully Feb 07 21:13:49 volumio volumio[367]: info: MYVOLUMIO: Adding device Feb 07 21:13:49 volumio volumio[367]: info: MYVOLUMIO: Evaluating Server Feb 07 21:13:50 volumio volumio[367]: info: MyVolumio status changed Feb 07 21:13:50 volumio volumio[367]: info: Streaming services startup Feb 07 21:13:50 volumio volumio[367]: info: Starting Streaming Daemon Feb 07 21:13:50 volumio volumio[367]: info: Removing browser output: myVolumio user plan is not superstar Feb 07 21:13:50 volumio volumio[367]: info: Removing audio output: Feb 07 21:13:50 volumio volumio[367]: info: Stoppping Tunnel 1 Feb 07 21:13:50 volumio sudo[807]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 21:13:50 volumio sudo[807]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:50 volumio sudo[807]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:50 volumio sudo[810]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 07 21:13:50 volumio sudo[810]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:13:50 volumio volumio[367]: error: Cannot start Volumio Streaming Daemon Feb 07 21:13:50 volumio volumio[367]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 21:13:50 volumio volumio[367]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 21:13:50 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 21:13:50 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 21:13:50 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 21:13:50 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 21:13:50 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 21:13:50 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 21:13:50 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 21:13:50 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 21:13:50 volumio sudo[810]: pam_unix(sudo:session): session closed for user root Feb 07 21:13:50 volumio volumio[367]: info: Remote SSH Stopped Feb 07 21:13:51 volumio volumio[367]: info: Initializing connection to go-librespot Websocket Feb 07 21:13:51 volumio volumio[367]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 21:13:52 volumio volumio[367]: info: Setting Geolocation for MyVolumio to as1 Feb 07 21:13:52 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:52 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:52 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 07 21:13:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:52 volumio go-librespot[812]: go-librespot daemon starting... Feb 07 21:13:52 volumio go-librespot[813]: time="2026-02-07T21:13:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:13:52 volumio go-librespot[813]: time="2026-02-07T21:13:52+07:00" level=debug msg="app state loaded" Feb 07 21:13:52 volumio go-librespot[813]: time="2026-02-07T21:13:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:13:52 volumio volumio[367]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 07 21:13:52 volumio go-librespot[813]: time="2026-02-07T21:13:52+07: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 07 21:13:52 volumio go-librespot[813]: time="2026-02-07T21:13:52+07: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 07 21:13:52 volumio go-librespot[813]: time="2026-02-07T21:13:52+07: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 07 21:13:52 volumio go-librespot[813]: time="2026-02-07T21:13:52+07:00" level=info msg="zeroconf server listening on port 38315" Feb 07 21:13:53 volumio volumio[367]: info: Updating MyVolumio device info Feb 07 21:13:53 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:53 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:53 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:53 volumio go-librespot[813]: time="2026-02-07T21:13:53+07:00" level=debug msg="obtained new client token: AACI0ZZF22ryYJqEam+jFPnfVaEiCbPNU9loru8u69KmqL+q/16a3dSAgamS081TXhrO275HyyvdYe8SjsM3mODjpGxweqdbOPCg+OZBbGjLjkR5fVOY1X0YTqgHwiNLOKB2ww8ez3cuIHye55FrQJ8wrBO56pOdndGBakuZTqjaiGUkj1udlWrvf8DbEH9HSFY12myaEc9A4x2tGyfX/afZhIwoEOLERNrvaJBTFEI409ctc7HrxZo=" Feb 07 21:13:53 volumio go-librespot[813]: time="2026-02-07T21:13:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:13:53 volumio go-librespot[813]: time="2026-02-07T21:13:53+07:00" level=debug msg="completed keyexchange" Feb 07 21:13:53 volumio go-librespot[813]: time="2026-02-07T21:13:53+07:00" level=debug msg="completed challenge" Feb 07 21:13:53 volumio go-librespot[813]: time="2026-02-07T21:13:53+07: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 07 21:13:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:13:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:13:53 volumio volumio[367]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 07 21:13:54 volumio volumio[367]: info: Initializing connection to go-librespot Websocket Feb 07 21:13:54 volumio volumio[367]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 21:13:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 07 21:13:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:13:56 volumio go-librespot[838]: go-librespot daemon starting... Feb 07 21:13:56 volumio go-librespot[839]: time="2026-02-07T21:13:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:13:56 volumio go-librespot[839]: time="2026-02-07T21:13:56+07:00" level=debug msg="app state loaded" Feb 07 21:13:56 volumio go-librespot[839]: time="2026-02-07T21:13:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:13:56 volumio volumio[367]: info: MYVOLUMIO: Adding device Feb 07 21:13:56 volumio volumio[367]: info: MYVOLUMIO: Evaluating Server Feb 07 21:13:57 volumio go-librespot[839]: time="2026-02-07T21:13:57+07: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 07 21:13:57 volumio go-librespot[839]: time="2026-02-07T21:13:57+07: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 07 21:13:57 volumio go-librespot[839]: time="2026-02-07T21:13:57+07: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 07 21:13:57 volumio go-librespot[839]: time="2026-02-07T21:13:57+07:00" level=info msg="zeroconf server listening on port 43559" Feb 07 21:13:57 volumio volumio[367]: info: Initializing connection to go-librespot Websocket Feb 07 21:13:57 volumio go-librespot[839]: time="2026-02-07T21:13:57+07:00" level=debug msg="new websocket client" Feb 07 21:13:57 volumio volumio[367]: info: Connection to go-librespot Websocket established Feb 07 21:13:57 volumio go-librespot[839]: time="2026-02-07T21:13:57+07:00" level=debug msg="obtained new client token: AAA4QyfEl3mU3zwurshv7ofwN4q4hwLKrNE4VgYuu1cHS+rR86xSEyYHTHvotwbbV7Q7xSFSNaw99kSSysgKtdgETs6uBgvX+iyWB4usN0SoP8t4eP1EXvqdiROG75zaEuCshoC4TL+zHoA0yiDUIKCsjHFZs/N3/6YdZid2nPL62kaRU5QEccG/GHQ9mqaU1s1GAI05hwUQLk38sT0K/I/edNm8WjS6EO7NW80AH8BZcz8b/MDZIssj/g==" Feb 07 21:13:57 volumio go-librespot[839]: time="2026-02-07T21:13:57+07: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 07 21:13:57 volumio go-librespot[839]: time="2026-02-07T21:13:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 21:13:58 volumio go-librespot[839]: time="2026-02-07T21:13:58+07:00" level=debug msg="completed keyexchange" Feb 07 21:13:58 volumio go-librespot[839]: time="2026-02-07T21:13:58+07:00" level=debug msg="completed challenge" Feb 07 21:13:58 volumio go-librespot[839]: time="2026-02-07T21:13:58+07: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 07 21:13:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:13:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:13:58 volumio volumio[367]: info: Connection to go-librespot Websocket closed Feb 07 21:13:59 volumio volumio[367]: info: Setting Geolocation for MyVolumio to as1 Feb 07 21:13:59 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:59 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:59 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:59 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 21:13:59 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:13:59 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 07 21:13:59 volumio volumio-remote-updater[643]: Test mode disabled Feb 07 21:13:59 volumio volumio-remote-updater[643]: Alpha mode disabled Feb 07 21:13:59 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled Feb 07 21:13:59 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 07 21:13:59 volumio volumio[367]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 07 21:14:00 volumio volumio[367]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 07 21:14:00 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 07 21:14:00 volumio volumio[367]: info: Updating MyVolumio device info Feb 07 21:14:00 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:14:00 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:14:00 volumio volumio[367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:14:00 volumio volumio[367]: info: Getting Spotify volume Feb 07 21:14:00 volumio volumio[367]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 21:14:00 volumio volumio[367]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 21:14:00 volumio volumio[367]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 07 21:14:00 volumio volumio[367]: errno: -111, Feb 07 21:14:00 volumio volumio[367]: code: 'ECONNREFUSED', Feb 07 21:14:00 volumio volumio[367]: syscall: 'connect', Feb 07 21:14:00 volumio volumio[367]: address: '127.0.0.1', Feb 07 21:14:00 volumio volumio[367]: port: 9879, Feb 07 21:14:00 volumio volumio[367]: response: undefined Feb 07 21:14:00 volumio volumio[367]: } Feb 07 21:14:00 volumio volumio[367]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 21:14:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 07 21:14:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:01 volumio go-librespot[889]: go-librespot daemon starting... Feb 07 21:14:01 volumio go-librespot[890]: time="2026-02-07T21:14:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:14:01 volumio go-librespot[890]: time="2026-02-07T21:14:01+07:00" level=debug msg="app state loaded" Feb 07 21:14:01 volumio go-librespot[890]: time="2026-02-07T21:14:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:14:01 volumio sudo[898]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 21:13' Feb 07 21:14:01 volumio sudo[898]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:14:02 volumio go-librespot[890]: time="2026-02-07T21:14:02+07: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 07 21:14:02 volumio go-librespot[890]: time="2026-02-07T21:14:02+07: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 07 21:14:02 volumio go-librespot[890]: time="2026-02-07T21:14:02+07: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 07 21:14:02 volumio sudo[898]: pam_unix(sudo:session): session closed for user root Feb 07 21:14:02 volumio go-librespot[890]: time="2026-02-07T21:14:02+07:00" level=info msg="zeroconf server listening on port 37549" Feb 07 21:14:02 volumio volumio-remote-updater[643]: [2026-02-07 21:14:02] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 21:14:02 volumio volumio-remote-updater[643]: [2026-02-07 21:14:02] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 21:14:02 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:14:02 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 21:14:02 volumio systemd[1]: volumio.service: Consumed 58.418s CPU time. Feb 07 21:14:02 volumio go-librespot[890]: time="2026-02-07T21:14:02+07:00" level=debug msg="obtained new client token: AADa7tR7aEvTKVZlVh8TzySs9BGJIF99APbQyXmuB+0lUoKltTX/Ptmbv65LJKHOnXdTi0RGeAHGp2h19h9c4mnsHDd04LXh9yDJAcBDGKBXODLBjTUg7yHiaxSfqwznCjv28nkpPgn9GWRFzJLRGSxshMvKWCKOvEn73TdyFHxOyNItHwSw049hHb46SnVBU7SDnf9MJ6bsD34TIHM7pu3J2kE8Dn3fBG7/F4/SCinPZZXzqODLgor4WQ==" Feb 07 21:14:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 21:14:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 21:14:02 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6336. Feb 07 21:14:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 21:14:02 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 21:14:02 volumio systemd[1]: volumio.service: Consumed 58.418s CPU time. Feb 07 21:14:02 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 21:14:02 volumio go-librespot[890]: time="2026-02-07T21:14:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:14:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 21:14:02 volumio go-librespot[890]: time="2026-02-07T21:14:02+07:00" level=debug msg="completed keyexchange" Feb 07 21:14:02 volumio go-librespot[890]: time="2026-02-07T21:14:02+07:00" level=debug msg="completed challenge" Feb 07 21:14:03 volumio go-librespot[890]: time="2026-02-07T21:14:03+07: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 07 21:14:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:14:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:14:06 volumio volumio[918]: info: ------------------------------------------- Feb 07 21:14:06 volumio volumio[918]: info: ----- Volumio3 ---- Feb 07 21:14:06 volumio volumio[918]: info: ------------------------------------------- Feb 07 21:14:06 volumio volumio[918]: info: ----- System startup ---- Feb 07 21:14:06 volumio volumio[918]: info: ------------------------------------------- Feb 07 21:14:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 07 21:14:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:06 volumio go-librespot[939]: go-librespot daemon starting... Feb 07 21:14:06 volumio go-librespot[940]: time="2026-02-07T21:14:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:14:06 volumio go-librespot[940]: time="2026-02-07T21:14:06+07:00" level=debug msg="app state loaded" Feb 07 21:14:06 volumio go-librespot[940]: time="2026-02-07T21:14:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:14:06 volumio go-librespot[940]: time="2026-02-07T21:14:06+07: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 07 21:14:06 volumio go-librespot[940]: time="2026-02-07T21:14:06+07: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 07 21:14:06 volumio go-librespot[940]: time="2026-02-07T21:14:06+07: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 07 21:14:06 volumio go-librespot[940]: time="2026-02-07T21:14:06+07:00" level=info msg="zeroconf server listening on port 41069" Feb 07 21:14:07 volumio go-librespot[940]: time="2026-02-07T21:14:07+07:00" level=debug msg="obtained new client token: AAD835Ii0Rud1iYtmtS32yTpCUuaQKdNb8ui6iE59WO4m2YjrsYqZianTB/ouR3s1gslPU8VhIRgfpltEA72etQoqwWa+4pcS74PpbRfkNroII/UUa/HcVr96nTZzxUDVLHoFLqXTRTXMXu5UstyVEA73ebkwfqjyN8AjZakXRieEV2XyN5GzaHHwd5xbbv01/QR8Ng6s2FC/yBpw5r2OncKZ7Lv4l6763CtumIEcCmK9xxS4QfwRus=" Feb 07 21:14:07 volumio go-librespot[940]: time="2026-02-07T21:14:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:14:07 volumio volumio-remote-updater[643]: [2026-02-07 21:14:07] [connect] Successful connection Feb 07 21:14:07 volumio go-librespot[940]: time="2026-02-07T21:14:07+07:00" level=debug msg="completed keyexchange" Feb 07 21:14:07 volumio go-librespot[940]: time="2026-02-07T21:14:07+07:00" level=debug msg="completed challenge" Feb 07 21:14:07 volumio go-librespot[940]: time="2026-02-07T21:14:07+07: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 07 21:14:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:14:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:14:07 volumio volumio[918]: info: MYVOLUMIO Environment detected Feb 07 21:14:07 volumio volumio[918]: info: Plugin folders cleanup Feb 07 21:14:07 volumio volumio[918]: info: Scanning into folder /volumio/app/plugins/ Feb 07 21:14:07 volumio volumio[918]: info: Scanning category audio_interface Feb 07 21:14:07 volumio volumio[918]: info: Scanning category miscellanea Feb 07 21:14:07 volumio volumio[918]: info: Scanning category music_service Feb 07 21:14:07 volumio volumio[918]: info: Scanning category plugins.json Feb 07 21:14:07 volumio volumio[918]: info: Scanning category system_controller Feb 07 21:14:07 volumio volumio[918]: info: Scanning category user_interface Feb 07 21:14:07 volumio volumio[918]: info: Scanning into folder /data/plugins/ Feb 07 21:14:07 volumio volumio[918]: info: Scanning category music_service Feb 07 21:14:07 volumio volumio[918]: info: Plugin folders cleanup completed Feb 07 21:14:07 volumio volumio[918]: info: ------------------------------------------- Feb 07 21:14:07 volumio volumio[918]: info: ----- Core plugins startup ---- Feb 07 21:14:07 volumio volumio[918]: info: ------------------------------------------- Feb 07 21:14:07 volumio volumio[918]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 21:14:07 volumio volumio[918]: info: Adding plugin upnp to MyMusic Plugins Feb 07 21:14:07 volumio volumio[918]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 21:14:07 volumio volumio[918]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 21:14:07 volumio volumio[918]: info: Loading plugins from folder /data/plugins/ Feb 07 21:14:07 volumio volumio[918]: info: Loading plugin "system"... Feb 07 21:14:07 volumio volumio[918]: info: Loading plugin "appearance"... Feb 07 21:14:09 volumio volumio[918]: info: Loading plugin "network"... Feb 07 21:14:09 volumio volumio[918]: info: Refreshing Cached IP Addresses Feb 07 21:14:09 volumio sudo[955]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 21:14:09 volumio sudo[955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:14:09 volumio sudo[957]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 21:14:09 volumio sudo[957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:14:09 volumio volumio[918]: info: Loading plugin "services"... Feb 07 21:14:09 volumio sudo[955]: pam_unix(sudo:session): session closed for user root Feb 07 21:14:09 volumio volumio[918]: info: Loading plugin "alsa_controller"... Feb 07 21:14:09 volumio sudo[957]: pam_unix(sudo:session): session closed for user root Feb 07 21:14:09 volumio sudo[964]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 21:14:09 volumio sudo[964]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:14:09 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 21:14:09 volumio volumio[918]: info: Loading plugin "wizard"... Feb 07 21:14:09 volumio volumio[918]: info: Loading plugin "networkfs"... Feb 07 21:14:10 volumio volumio[918]: info: Starting Udev Watcher for removable devices Feb 07 21:14:10 volumio volumio[918]: info: Ignoring mount for partition: boot Feb 07 21:14:10 volumio volumio[918]: info: Ignoring mount for partition: volumio Feb 07 21:14:10 volumio volumio[918]: info: Ignoring mount for partition: volumio_data Feb 07 21:14:10 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 21:14:10 volumio volumio[918]: info: Loading plugin "volumio_command_line_client"... Feb 07 21:14:10 volumio volumio[918]: info: Loading plugin "upnp"... Feb 07 21:14:10 volumio volumio[918]: info: [1770473650125] Starting Upmpd Daemon Feb 07 21:14:10 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 21:14:10 volumio volumio[918]: info: Loading plugin "my_music"... Feb 07 21:14:10 volumio volumio[918]: info: Loading plugin "mpd"... Feb 07 21:14:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 07 21:14:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:10 volumio go-librespot[992]: go-librespot daemon starting... Feb 07 21:14:10 volumio go-librespot[993]: time="2026-02-07T21:14:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:14:10 volumio go-librespot[993]: time="2026-02-07T21:14:10+07:00" level=debug msg="app state loaded" Feb 07 21:14:10 volumio go-librespot[993]: time="2026-02-07T21:14:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:14:10 volumio volumio[918]: info: Loading plugin "upnp_browser"... Feb 07 21:14:11 volumio go-librespot[993]: time="2026-02-07T21:14:11+07: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 07 21:14:11 volumio go-librespot[993]: time="2026-02-07T21:14:11+07: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 07 21:14:11 volumio go-librespot[993]: time="2026-02-07T21:14:11+07: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 07 21:14:11 volumio go-librespot[993]: time="2026-02-07T21:14:11+07:00" level=info msg="zeroconf server listening on port 34397" Feb 07 21:14:11 volumio go-librespot[993]: time="2026-02-07T21:14:11+07:00" level=debug msg="obtained new client token: AABwUQJmWIOzz6HWjZph0WoStKJWS0BHahbndIAqhobEw44+JfBjsWWakI1epTo/OP4RkbDNUnfY+8xnggUo2uDSXTH6nVw3vaWHWzZj9hHssbHBVLOHrqXOBYR9fSQJ/sPNH6YfiZEDYBkYTzG2BLPpgAjrrYQd+26+UyOP9iida/MpzadApFQDco1z7IlDlruEFDkj3Hy+jUbxkvaK7Qr/UDUN9F43NyZCzwXe5YaBzAHxRLWZf2YjiA==" Feb 07 21:14:11 volumio go-librespot[993]: time="2026-02-07T21:14:11+07: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 07 21:14:11 volumio go-librespot[993]: time="2026-02-07T21:14:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 21:14:11 volumio go-librespot[993]: time="2026-02-07T21:14:11+07:00" level=debug msg="completed keyexchange" Feb 07 21:14:11 volumio go-librespot[993]: time="2026-02-07T21:14:11+07:00" level=debug msg="completed challenge" Feb 07 21:14:11 volumio go-librespot[993]: time="2026-02-07T21:14:11+07: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 07 21:14:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:14:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:14:12 volumio sudo[964]: pam_unix(sudo:session): session closed for user root Feb 07 21:14:13 volumio volumio[918]: info: Starting UPNP Browser Feb 07 21:14:13 volumio volumio[918]: info: Loading plugin "alarm-clock"... Feb 07 21:14:14 volumio volumio[918]: info: Loading plugin "airplay_emulation"... Feb 07 21:14:14 volumio volumio[918]: info: Starting Shairport Sync Feb 07 21:14:14 volumio volumio[918]: info: Loading plugin "last_100"... Feb 07 21:14:14 volumio volumio[918]: info: Loading plugin "webradio"... Feb 07 21:14:14 volumio volumio[918]: info: Loading plugin "i2s_dacs"... Feb 07 21:14:14 volumio volumio[918]: info: Loading plugin "volumiodiscovery"... Feb 07 21:14:14 volumio volumio[918]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 21:14:14 volumio volumio[918]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 21:14:14 volumio volumio[918]: *** WARNING *** For more information see Feb 07 21:14:14 volumio volumio[918]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 21:14:14 volumio volumio[918]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 21:14:14 volumio volumio[918]: *** WARNING *** For more information see Feb 07 21:14:14 volumio node[918]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 21:14:14 volumio node[918]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 21:14:14 volumio node[918]: *** WARNING *** For more information see Feb 07 21:14:14 volumio node[918]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 21:14:14 volumio node[918]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 21:14:14 volumio node[918]: *** WARNING *** For more information see Feb 07 21:14:14 volumio volumio[918]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 21:14:14 volumio volumio[918]: info: Discovery: Started advertising with name: Volumio Feb 07 21:14:14 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 21:14:14 volumio volumio[918]: info: Loading plugin "spop"... Feb 07 21:14:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 07 21:14:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:15 volumio go-librespot[1004]: go-librespot daemon starting... Feb 07 21:14:15 volumio go-librespot[1005]: time="2026-02-07T21:14:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:14:15 volumio go-librespot[1005]: time="2026-02-07T21:14:15+07:00" level=debug msg="app state loaded" Feb 07 21:14:15 volumio go-librespot[1005]: time="2026-02-07T21:14:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:14:15 volumio go-librespot[1005]: time="2026-02-07T21:14:15+07: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 07 21:14:15 volumio go-librespot[1005]: time="2026-02-07T21:14:15+07: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 07 21:14:15 volumio go-librespot[1005]: time="2026-02-07T21:14:15+07: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 07 21:14:15 volumio go-librespot[1005]: time="2026-02-07T21:14:15+07:00" level=info msg="zeroconf server listening on port 38083" Feb 07 21:14:15 volumio go-librespot[1005]: time="2026-02-07T21:14:15+07:00" level=debug msg="obtained new client token: AABNrZOmyO4CaDddTL4ZV3NhjgQWgW36xPZYpWa+RkP3wPE9dY9v6zCu7TPaOaoAEOMhAiqjMnnzRfDDjYUwhV96B6Bcwi7siREWdvZh/xzp5GxxZuogHO+frjrKkZJq3TnMfSETVSFs9kcy1xhC2RB668+wufoOuH2w2FBO+Mao2m309cA3FbS15wmlVEPZJhJMrs69K921fGMlXz+ZIIEyH+59Dqv+u9OlDTlj/UkTLPeJC/Q3J8nGcA==" Feb 07 21:14:16 volumio go-librespot[1005]: time="2026-02-07T21:14:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:14:16 volumio go-librespot[1005]: time="2026-02-07T21:14:16+07:00" level=debug msg="completed keyexchange" Feb 07 21:14:16 volumio go-librespot[1005]: time="2026-02-07T21:14:16+07:00" level=debug msg="completed challenge" Feb 07 21:14:16 volumio go-librespot[1005]: time="2026-02-07T21:14:16+07: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 07 21:14:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:14:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:14:16 volumio volumio[918]: info: Loading plugin "ytcr"... Feb 07 21:14:18 volumio volumio[918]: info: Loading plugin "ytmusic"... Feb 07 21:14:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 07 21:14:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:19 volumio go-librespot[1012]: go-librespot daemon starting... Feb 07 21:14:19 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Feb 07 21:14:19 volumio go-librespot[1013]: time="2026-02-07T21:14:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:14:19 volumio go-librespot[1013]: time="2026-02-07T21:14:19+07:00" level=debug msg="app state loaded" Feb 07 21:14:19 volumio go-librespot[1013]: time="2026-02-07T21:14:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:14:19 volumio volumio-remote-updater[643]: [2026-02-07 21:14:19] [connect] Successful connection Feb 07 21:14:20 volumio go-librespot[1013]: time="2026-02-07T21:14:20+07: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 07 21:14:20 volumio go-librespot[1013]: time="2026-02-07T21:14:20+07: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 07 21:14:20 volumio go-librespot[1013]: time="2026-02-07T21:14:20+07: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 07 21:14:20 volumio go-librespot[1013]: time="2026-02-07T21:14:20+07:00" level=info msg="zeroconf server listening on port 46209" Feb 07 21:14:20 volumio volumio[918]: info: Loading plugin "outputs"... Feb 07 21:14:20 volumio volumio[918]: info: Loading plugin "albumart"... Feb 07 21:14:20 volumio volumio[918]: info: Plugin example_plugin is not enabled Feb 07 21:14:20 volumio volumio[918]: info: Loading plugin "inputs"... Feb 07 21:14:20 volumio volumio[918]: info: Loading plugin "updater_comm"... Feb 07 21:14:20 volumio go-librespot[1013]: time="2026-02-07T21:14:20+07:00" level=debug msg="obtained new client token: AAAzr01rAs62fGl4592/SMO48VQmKIhkonFDH4gU2L1BRCAAE2JKkD/vjiCpxyg4GLzVbt3AXRVoTSKS4RQ9DyiLWiF3AWiMVaUQURerLCHfoYIwcMdOR5PVJw5HAEuBpDPWJqfp3omsRmQeTglGr+BMUkfFhyR3X3Ge7983q0oiJvPHoYv77jBs3rSF8oJGrayrHkRnRxdm9+pB0RnxZWBhUQIOVmhkBp1vY/r0dyR5Hl/hDlnSKq15Yw==" Feb 07 21:14:20 volumio go-librespot[1013]: time="2026-02-07T21:14:20+07: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 07 21:14:20 volumio go-librespot[1013]: time="2026-02-07T21:14:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 21:14:20 volumio volumio[918]: info: Plugin mpdemulation is not enabled Feb 07 21:14:20 volumio volumio[918]: info: Loading plugin "rest_api"... Feb 07 21:14:20 volumio go-librespot[1013]: time="2026-02-07T21:14:20+07:00" level=debug msg="completed keyexchange" Feb 07 21:14:20 volumio go-librespot[1013]: time="2026-02-07T21:14:20+07:00" level=debug msg="completed challenge" Feb 07 21:14:20 volumio volumio[918]: info: Loading plugin "websocket"... Feb 07 21:14:20 volumio volumio[918]: info: Starting Socket.io Server version 1.7.4 Feb 07 21:14:20 volumio volumio[918]: info: Loading plugin "RoonBridge"... Feb 07 21:14:20 volumio go-librespot[1013]: time="2026-02-07T21:14:20+07: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 07 21:14:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:14:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:14:21 volumio volumio[918]: info: Applying required configuration parameters for plugin RoonBridge Feb 07 21:14:21 volumio volumio[918]: info: Loading i18n strings for locale en Feb 07 21:14:21 volumio volumio[918]: Updating browse sources language Feb 07 21:14:21 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:14:21 volumio volumio[1053]: Forking 3 albumart workers Feb 07 21:14:21 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 21:14:21 volumio volumio[918]: info: CoreCommandRouter::initPlayerControls Feb 07 21:14:21 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:21 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:21 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:21 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:21 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:21 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:21 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:21 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:21 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 21:14:21 volumio volumio[918]: Express server listening on port 3000 Feb 07 21:14:21 volumio volumio[918]: [Metrics] WebUI: 16s 297.27ms Feb 07 21:14:21 volumio volumio[918]: info: CoreStateMachine::resetVolumioState Feb 07 21:14:21 volumio volumio[918]: info: CoreStateMachine::getcurrentVolume Feb 07 21:14:21 volumio volumio[918]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 21:14:21 volumio sudo[1105]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 21:14:21 volumio sudo[1105]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:14:21 volumio sudo[1105]: pam_unix(sudo:session): session closed for user root Feb 07 21:14:21 volumio sudo[1107]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 21:14:21 volumio sudo[1107]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:14:21 volumio sudo[1107]: pam_unix(sudo:session): session closed for user root Feb 07 21:14:21 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 07 21:14:21 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 07 21:14:21 volumio systemd[1]: setdatetime-helper.service: Consumed 2.075s CPU time. Feb 07 21:14:21 volumio volumio[918]: info: Volumio Network Manager: Network status updated: 1 Feb 07 21:14:22 volumio volumio[918]: info: VolumeController:: Volume=100 Mute =false Feb 07 21:14:22 volumio volumio[918]: info: CoreStateMachine::pushState Feb 07 21:14:22 volumio volumio[918]: info: CorePlayQueue::getTrack 0 Feb 07 21:14:22 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 21:14:22 volumio volumio[918]: info: CoreCommandRouter::volumioPushState Feb 07 21:14:22 volumio volumio[918]: info: CoreStateMachine::updateTrackBlock Feb 07 21:14:22 volumio volumio[918]: info: CorePlayQueue::getTrackBlock Feb 07 21:14:22 volumio volumio[918]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 21:14:22 volumio volumio-remote-updater[643]: [2026-02-07 21:14:22] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770473659 101 Feb 07 21:14:22 volumio volumio[918]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 07 21:14:22 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:14:22 volumio volumio[918]: info: Reloading queue from file Feb 07 21:14:22 volumio volumio[918]: info: CoreStateMachine::setRepeat null single undefined Feb 07 21:14:22 volumio volumio[918]: info: CoreStateMachine::pushState Feb 07 21:14:22 volumio volumio[918]: info: CorePlayQueue::getTrack 0 Feb 07 21:14:22 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 21:14:22 volumio volumio[918]: info: CoreCommandRouter::volumioPushState Feb 07 21:14:22 volumio volumio[918]: info: CoreStateMachine::setRandom null Feb 07 21:14:22 volumio volumio[918]: info: CoreStateMachine::pushState Feb 07 21:14:22 volumio volumio[918]: info: CorePlayQueue::getTrack 0 Feb 07 21:14:22 volumio volumio[918]: info: CoreCommandRouter::volumioPushState Feb 07 21:14:22 volumio volumio[918]: info: Setting Device type: Raspberry PI Feb 07 21:14:22 volumio volumio[918]: info: Completed loading Core Plugins Feb 07 21:14:22 volumio volumio[918]: info: Preparing to generate the ALSA configuration file Feb 07 21:14:22 volumio volumio[918]: info: VolumeController:: Volume=100 Mute =false Feb 07 21:14:22 volumio volumio[918]: info: CoreStateMachine::pushState Feb 07 21:14:22 volumio volumio[918]: info: CorePlayQueue::getTrack 0 Feb 07 21:14:22 volumio volumio[918]: info: CoreCommandRouter::volumioPushState Feb 07 21:14:22 volumio volumio[918]: info: Asound.conf file unchanged, so no further update is needed Feb 07 21:14:22 volumio volumio[918]: info: Output device has changed, restarting MPD Feb 07 21:14:22 volumio volumio[918]: info: Output device has changed, restarting Shairport Sync Feb 07 21:14:22 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:22 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:14:22 volumio sudo[1126]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 07 21:14:22 volumio sudo[1126]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:14:22 volumio sudo[1130]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 21:14:22 volumio sudo[1128]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 21:14:22 volumio sudo[1130]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:14:22 volumio sudo[1128]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:14:22 volumio volumio[918]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 21:14:22 volumio volumio[918]: info: ___________ START PLUGINS ___________ Feb 07 21:14:22 volumio sudo[1128]: pam_unix(sudo:session): session closed for user root Feb 07 21:14:22 volumio volumio[918]: info: ControllerMpd::onStart: Initializing MPD Feb 07 21:14:22 volumio volumio[918]: info: Creating MPD Configuration file Feb 07 21:14:23 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 21:14:23 volumio volumio[918]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:14:23 volumio sudo[1126]: pam_unix(sudo:session): session closed for user root Feb 07 21:14:23 volumio volumio[918]: info: [1770473663036] CoreMusicLibrary::Adding element Media Servers Feb 07 21:14:23 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:14:23 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 21:14:23 volumio sudo[1141]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 21:14:23 volumio sudo[1141]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:14:23 volumio sudo[1141]: pam_unix(sudo:session): session closed for user root Feb 07 21:14:23 volumio volumio[918]: info: UPNP Browser: Client initialized successfully Feb 07 21:14:23 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 07 21:14:23 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 21:14:23 volumio systemd[1]: mpd.service: Consumed 7.199s CPU time. Feb 07 21:14:23 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 07 21:14:23 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 21:14:23 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 21:14:23 volumio sudo[1142]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 21:14:23 volumio sudo[1142]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:14:23 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:23 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:14:23 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 21:14:23 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 21:14:23 volumio volumio[918]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 21:14:23 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 07 21:14:23 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:23 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 21:14:23 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 07 21:14:23 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:14:23 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 21:14:23 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 21:14:23 volumio volumio[918]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 21:14:23 volumio volumio[918]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:14:23 volumio volumio[918]: info: [1770473663447] CoreMusicLibrary::Adding element Last_100 Feb 07 21:14:23 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 21:14:23 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:14:23 volumio volumio[918]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:14:23 volumio volumio[918]: info: [1770473663477] CoreMusicLibrary::Adding element Webradio Feb 07 21:14:23 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:14:23 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 21:14:23 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 21:14:23 volumio volumio[918]: info: Initializing BBC Radios Feb 07 21:14:23 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 21:14:23 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:14:23 volumio volumio[918]: info: Creating Spotify config file Feb 07 21:14:23 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 07 21:14:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:23 volumio go-librespot[1170]: go-librespot daemon starting... Feb 07 21:14:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:23 volumio sudo[1156]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 21:14:23 volumio sudo[1156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 21:14:23 volumio sudo[1156]: pam_unix(sudo:session): session closed for user root Feb 07 21:14:24 volumio go-librespot[1171]: time="2026-02-07T21:14:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:14:24 volumio go-librespot[1171]: time="2026-02-07T21:14:24+07:00" level=info msg="zeroconf server listening on port 45951" Feb 07 21:14:24 volumio volumio[1071]: Starting albumart workers Feb 07 21:14:24 volumio volumio[1070]: Starting albumart workers Feb 07 21:14:24 volumio volumio[1072]: Starting albumart workers Feb 07 21:14:25 volumio volumio[918]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:14:25 volumio volumio[918]: info: [1770473665113] CoreMusicLibrary::Adding element YouTube Music Feb 07 21:14:25 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:14:25 volumio volumio[918]: Cannot find translation for source YouTube Music Feb 07 21:14:25 volumio volumio[918]: info: Volumio Calling Home Feb 07 21:14:25 volumio sudo[1181]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 07 21:14:25 volumio sudo[1181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:14:25 volumio sudo[1181]: pam_unix(sudo:session): session closed for user root Feb 07 21:14:25 volumio volumio[918]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 07 21:14:25 volumio volumio[918]: info: Discovery: Found device Volumio Feb 07 21:14:25 volumio volumio[918]: info: CoreCommandRouter::volumioGetState Feb 07 21:14:25 volumio volumio[918]: info: CorePlayQueue::getTrack 0 Feb 07 21:14:25 volumio volumio[918]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 07 21:14:25 volumio volumio[918]: info: Discovery: Found device Volumio Feb 07 21:14:25 volumio volumio[918]: info: CoreCommandRouter::volumioGetState Feb 07 21:14:25 volumio volumio[918]: info: CorePlayQueue::getTrack 0 Feb 07 21:14:25 volumio volumio[918]: info: MPD Permissions set Feb 07 21:14:26 volumio volumio[918]: info: MPD Permissions set Feb 07 21:14:26 volumio volumio[918]: info: Upmpdcli Daemon Started Feb 07 21:14:26 volumio volumio[918]: info: Spotify config file written Feb 07 21:14:26 volumio sudo[1187]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 21:14:26 volumio sudo[1187]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:14:26 volumio volumio[918]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 07 21:14:26 volumio volumio[918]: info: Volumio called home Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:26 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 21:14:26 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 21:14:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:14:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:26 volumio go-librespot[1194]: go-librespot daemon starting... Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:26 volumio sudo[1187]: pam_unix(sudo:session): session closed for user root Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:26 volumio go-librespot[1195]: time="2026-02-07T21:14:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:14:26 volumio go-librespot[1195]: time="2026-02-07T21:14:26+07:00" level=debug msg="app state loaded" Feb 07 21:14:26 volumio go-librespot[1195]: time="2026-02-07T21:14:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:14:26 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:14:26 volumio volumio[918]: info: No need to fix Spotify hosts Feb 07 21:14:27 volumio go-librespot[1195]: time="2026-02-07T21:14:27+07: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 07 21:14:27 volumio go-librespot[1195]: time="2026-02-07T21:14:27+07: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 07 21:14:27 volumio go-librespot[1195]: time="2026-02-07T21:14:27+07: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 07 21:14:27 volumio go-librespot[1195]: time="2026-02-07T21:14:27+07:00" level=info msg="zeroconf server listening on port 33935" Feb 07 21:14:27 volumio go-librespot[1195]: time="2026-02-07T21:14:27+07:00" level=debug msg="obtained new client token: AAAHgh/B+YwGhbRHJrRsie8XGYdeh7cIi58sPKF3pJga0bLVNzL8gcB/VQ+YdjGSGgEcOj68/AayFKw+IXsh0ncwuk/yoxMmxpgCd+r3iXj+t4tq4DtFJSLD3Lp4n+kfozjrIE68c4fVPJJ6D8Hz8m+qFqGw/SKNPuWGU4T9LIahiLoAkNna06mY9LreM8nfD27ZQiP6uIHK4KS96tSIjKj6DHnZpPf7OR3BeJOuTj1X7HJUW5geQiJBcw==" Feb 07 21:14:27 volumio go-librespot[1195]: time="2026-02-07T21:14:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:14:27 volumio go-librespot[1195]: time="2026-02-07T21:14:27+07:00" level=debug msg="completed keyexchange" Feb 07 21:14:27 volumio go-librespot[1195]: time="2026-02-07T21:14:27+07:00" level=debug msg="completed challenge" Feb 07 21:14:27 volumio volumio[918]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 07 21:14:27 volumio volumio[918]: SPOTIFY: BQB5E5iN-pcC76pdBNOKIaatm88WIZD9R6heigfBYeE7fvL0s1nAF22ZK0o2EmWBGSA5UztBDWn4EJKxFBaY-aHVvvo3Hm4wE8syEm4UiBZ7hcw2UjMOXbNlpuf3NEc2-i2ptqwSJGiMtEW69rUZfuoffUlWmUGOBjQs6dRHj2ysOd-bzWuuNAD-f35WvExQ2_-tCBAzKt_2BktPm3iOvAN-m-yDljQDsv2p0bZtP11qo4wuhwlseTUq8dXMM1YnY3eABy4ArN6_OhMJ2DzZv0i8Y2qMLzOduq3oaJykae3mX96ASPT46QpQ Feb 07 21:14:27 volumio volumio[918]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 07 21:14:27 volumio volumio[918]: info: New Spotify access token = BQB5E5iN-pcC76pdBNOKIaatm88WIZD9R6heigfBYeE7fvL0s1nAF22ZK0o2EmWBGSA5UztBDWn4EJKxFBaY-aHVvvo3Hm4wE8syEm4UiBZ7hcw2UjMOXbNlpuf3NEc2-i2ptqwSJGiMtEW69rUZfuoffUlWmUGOBjQs6dRHj2ysOd-bzWuuNAD-f35WvExQ2_-tCBAzKt_2BktPm3iOvAN-m-yDljQDsv2p0bZtP11qo4wuhwlseTUq8dXMM1YnY3eABy4ArN6_OhMJ2DzZv0i8Y2qMLzOduq3oaJykae3mX96ASPT46QpQ Feb 07 21:14:27 volumio volumio[918]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 07 21:14:27 volumio go-librespot[1195]: time="2026-02-07T21:14:27+07: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 07 21:14:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:14:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:14:27 volumio volumio[918]: info: Starting Shairport Sync Feb 07 21:14:27 volumio volumio[918]: info: Starting Shairport Sync Feb 07 21:14:27 volumio volumio[918]: info: Starting Shairport Sync Feb 07 21:14:27 volumio sudo[1226]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 21:14:27 volumio sudo[1226]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:14:27 volumio sudo[1228]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 21:14:27 volumio sudo[1228]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:14:27 volumio sudo[1231]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 21:14:27 volumio sudo[1231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:14:28 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 21:14:28 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 21:14:28 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 21:14:28 volumio systemd[1]: shairport-sync.service: Consumed 2.432s CPU time. Feb 07 21:14:28 volumio volumio[918]: info: CoreCommandRouter::volumioGetState Feb 07 21:14:28 volumio volumio[918]: info: CorePlayQueue::getTrack 0 Feb 07 21:14:28 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 21:14:28 volumio sudo[1228]: pam_unix(sudo:session): session closed for user root Feb 07 21:14:28 volumio sudo[1226]: pam_unix(sudo:session): session closed for user root Feb 07 21:14:28 volumio sudo[1231]: pam_unix(sudo:session): session closed for user root Feb 07 21:14:28 volumio volumio[918]: info: Shairport-Sync Started Feb 07 21:14:28 volumio volumio[918]: Error adding Membership: Error: addMembership EINVAL Feb 07 21:14:28 volumio volumio[918]: info: Shairport-Sync Started Feb 07 21:14:28 volumio volumio[918]: info: Shairport-Sync Started Feb 07 21:14:28 volumio volumio[918]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 07 21:14:28 volumio volumio[918]: info: Spotify Successfully logged in Feb 07 21:14:28 volumio volumio[918]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:14:28 volumio volumio[918]: info: [1770473668449] CoreMusicLibrary::Adding element Spotify Feb 07 21:14:28 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:14:28 volumio volumio[918]: Cannot find translation for source YouTube Music Feb 07 21:14:28 volumio volumio[918]: Cannot find translation for source Spotify Feb 07 21:14:29 volumio volumio[918]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 07 21:14:29 volumio volumio[918]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 21:14:29 volumio volumio[918]: info: VolumeController:: Volume=100 Mute =false Feb 07 21:14:29 volumio volumio[918]: info: CoreCommandRouter::volumioGetState Feb 07 21:14:29 volumio volumio[918]: info: CorePlayQueue::getTrack 0 Feb 07 21:14:29 volumio volumio[918]: info: CoreStateMachine::pushState Feb 07 21:14:29 volumio volumio[918]: info: CorePlayQueue::getTrack 0 Feb 07 21:14:29 volumio volumio[918]: info: CoreCommandRouter::volumioPushState Feb 07 21:14:30 volumio volumio[918]: info: go-librespot daemon successfully initialized Feb 07 21:14:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 21:14:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:30 volumio go-librespot[1267]: go-librespot daemon starting... Feb 07 21:14:30 volumio go-librespot[1268]: time="2026-02-07T21:14:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:14:30 volumio go-librespot[1268]: time="2026-02-07T21:14:30+07:00" level=debug msg="app state loaded" Feb 07 21:14:30 volumio go-librespot[1268]: time="2026-02-07T21:14:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:14:31 volumio mpd[1178]: 2026-02-07T21:14:31 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 21:14:31 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 21:14:31 volumio sudo[1142]: pam_unix(sudo:session): session closed for user root Feb 07 21:14:31 volumio sudo[1130]: pam_unix(sudo:session): session closed for user root Feb 07 21:14:31 volumio volumio[918]: error: MPD error: The expression evaluated to a falsy value: Feb 07 21:14:31 volumio volumio[918]: assert.ok(self.idling) Feb 07 21:14:31 volumio volumio[918]: error: The expression evaluated to a falsy value: Feb 07 21:14:31 volumio volumio[918]: assert.ok(self.idling) Feb 07 21:14:31 volumio volumio[918]: error: updateQueue error: null Feb 07 21:14:31 volumio volumio[918]: info: MPD running with PID1178 Feb 07 21:14:31 volumio volumio[918]: ,establishing connection Feb 07 21:14:31 volumio volumio[918]: info: Completed starting Core Plugins Feb 07 21:14:31 volumio volumio[918]: info: ------------------------------------------- Feb 07 21:14:31 volumio volumio[918]: info: ----- MyVolumio plugins startup ---- Feb 07 21:14:31 volumio volumio[918]: info: ------------------------------------------- Feb 07 21:14:31 volumio volumio[918]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 21:14:31 volumio volumio[918]: error: updateQueue error: null Feb 07 21:14:31 volumio go-librespot[1268]: time="2026-02-07T21:14:31+07: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 07 21:14:31 volumio go-librespot[1268]: time="2026-02-07T21:14:31+07: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 07 21:14:31 volumio go-librespot[1268]: time="2026-02-07T21:14:31+07: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 07 21:14:31 volumio go-librespot[1268]: time="2026-02-07T21:14:31+07:00" level=info msg="zeroconf server listening on port 40161" Feb 07 21:14:31 volumio go-librespot[1268]: time="2026-02-07T21:14:31+07:00" level=debug msg="obtained new client token: AAAJoK4V2i58rCnsB8dUvpRy/Chz6qykF57NJWNY1tkENfK90UTe0Z4y1c8+R1E8UMCAV6Bdfm2AaK+sXkdS+pUPksxjbqiz58GyPYvll5Hyd55AobB1ZMHzyD3+dkiOwdgFGVGd/FW8LGhbQRW2nEUdW09o9+SPnbAyiM9r7hDdG/6cBHSCLZF2QeujAGElAgvTSpqOXpV54TZgPTXCgzj2EIbHNMFDs90tYjm4XMH8KlRm//+Z4AHO1Q==" Feb 07 21:14:31 volumio go-librespot[1268]: time="2026-02-07T21:14:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:14:31 volumio go-librespot[1268]: time="2026-02-07T21:14:31+07:00" level=debug msg="completed keyexchange" Feb 07 21:14:31 volumio go-librespot[1268]: time="2026-02-07T21:14:31+07:00" level=debug msg="completed challenge" Feb 07 21:14:31 volumio go-librespot[1268]: time="2026-02-07T21:14:31+07: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 07 21:14:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:14:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:14:33 volumio volumio[918]: info: Initializing connection to go-librespot Websocket Feb 07 21:14:33 volumio volumio[918]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 21:14:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 21:14:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:35 volumio go-librespot[1282]: go-librespot daemon starting... Feb 07 21:14:35 volumio go-librespot[1283]: time="2026-02-07T21:14:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:14:35 volumio go-librespot[1283]: time="2026-02-07T21:14:35+07:00" level=debug msg="app state loaded" Feb 07 21:14:35 volumio go-librespot[1283]: time="2026-02-07T21:14:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:14:35 volumio go-librespot[1283]: time="2026-02-07T21:14:35+07: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 07 21:14:35 volumio go-librespot[1283]: time="2026-02-07T21:14:35+07: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 07 21:14:35 volumio go-librespot[1283]: time="2026-02-07T21:14:35+07: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 07 21:14:35 volumio go-librespot[1283]: time="2026-02-07T21:14:35+07:00" level=info msg="zeroconf server listening on port 45053" Feb 07 21:14:35 volumio go-librespot[1283]: time="2026-02-07T21:14:35+07:00" level=debug msg="obtained new client token: AAAG71vaiuQPcexbJKcePcvDOZ6lyv5tDSzHH0NDBuIi5xiBoDFbvtJTMPE0IwnmlBphQsHTCxpc0RVVWMd31KXECxmUl2sN/k5xx9EuCHZquClScAg66KAi5yC+v1wT15ixsUElEc0d573qjz6OynRePipwLfncmrm9IIGFWnvKKvMRAo59vYzGZ725rjvy8ou9N43rnXCpOOFjSgvhdz/Uh9Jwrf9EK/GH9GzAfPbTOLQefPXJt1lZoA==" Feb 07 21:14:35 volumio go-librespot[1283]: time="2026-02-07T21:14:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:14:36 volumio go-librespot[1283]: time="2026-02-07T21:14:36+07:00" level=debug msg="completed keyexchange" Feb 07 21:14:36 volumio go-librespot[1283]: time="2026-02-07T21:14:36+07:00" level=debug msg="completed challenge" Feb 07 21:14:36 volumio go-librespot[1283]: time="2026-02-07T21:14:36+07: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 07 21:14:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:14:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:14:36 volumio volumio[918]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 21:14:36 volumio volumio[918]: info: Initializing connection to go-librespot Websocket Feb 07 21:14:36 volumio volumio[918]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 21:14:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 21:14:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:39 volumio go-librespot[1290]: go-librespot daemon starting... Feb 07 21:14:39 volumio go-librespot[1291]: time="2026-02-07T21:14:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:14:39 volumio go-librespot[1291]: time="2026-02-07T21:14:39+07:00" level=debug msg="app state loaded" Feb 07 21:14:39 volumio go-librespot[1291]: time="2026-02-07T21:14:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:14:39 volumio volumio[918]: info: Initializing connection to go-librespot Websocket Feb 07 21:14:39 volumio go-librespot[1291]: time="2026-02-07T21:14:39+07:00" level=debug msg="new websocket client" Feb 07 21:14:39 volumio volumio[918]: info: Connection to go-librespot Websocket established Feb 07 21:14:39 volumio go-librespot[1291]: time="2026-02-07T21:14:39+07: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 07 21:14:39 volumio go-librespot[1291]: time="2026-02-07T21:14:39+07: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 07 21:14:39 volumio go-librespot[1291]: time="2026-02-07T21:14:39+07: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 07 21:14:39 volumio go-librespot[1291]: time="2026-02-07T21:14:39+07:00" level=info msg="zeroconf server listening on port 40743" Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 21:14:40 volumio go-librespot[1291]: time="2026-02-07T21:14:40+07:00" level=debug msg="obtained new client token: AADipuIgBN35ikX5VSNgRkaZ4LjZMR/LVLF1JsDpyvgVqSrG5raQNckztCXSanoOjZHxQ9zEYYZ7NXeU84O1iSp5ouNVg9BSCQ88EYw0PLyTDzfez9VoivUTqLEugldojSTS+k78Vyz9UNY41hcDqlffDYQOAjAAV2SNf/I+ydpXzsxO33/zKc+BoazZgu5c7RgK39gBFEuTt/sEPlQXw/gFk1N7NWR1+VsuiCaghIUj69keUxB+mmo=" Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 21:14:40 volumio volumio[918]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 21:14:40 volumio volumio[918]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 21:14:40 volumio volumio[918]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 21:14:40 volumio volumio[918]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 21:14:40 volumio volumio[918]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 21:14:40 volumio volumio[918]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 21:14:40 volumio volumio[918]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 21:14:40 volumio volumio[918]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 21:14:40 volumio go-librespot[1291]: time="2026-02-07T21:14:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:14:40 volumio go-librespot[1291]: time="2026-02-07T21:14:40+07:00" level=debug msg="completed keyexchange" Feb 07 21:14:40 volumio go-librespot[1291]: time="2026-02-07T21:14:40+07:00" level=debug msg="completed challenge" Feb 07 21:14:40 volumio go-librespot[1291]: time="2026-02-07T21:14:40+07: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 07 21:14:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:14:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:14:41 volumio volumio[918]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 21:14:41 volumio volumio[918]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 21:14:41 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:14:41 volumio volumio[918]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:14:41 volumio volumio[918]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 21:14:42 volumio volumio[918]: info: MyVolumio login type: Token Feb 07 21:14:42 volumio volumio[918]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 21:14:42 volumio volumio[918]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 21:14:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 07 21:14:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:14:43 volumio go-librespot[1314]: go-librespot daemon starting... Feb 07 21:14:43 volumio go-librespot[1315]: time="2026-02-07T21:14:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:14:43 volumio go-librespot[1315]: time="2026-02-07T21:14:43+07:00" level=debug msg="app state loaded" Feb 07 21:14:43 volumio go-librespot[1315]: time="2026-02-07T21:14:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:14:43 volumio volumio[918]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 21:14:43 volumio volumio[918]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 21:14:43 volumio volumio[918]: info: Streaming services startup Feb 07 21:14:43 volumio volumio[918]: info: Starting Streaming Daemon Feb 07 21:14:43 volumio sudo[1322]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 21:14:43 volumio sudo[1322]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:14:43 volumio volumio[918]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 21:14:44 volumio sudo[1322]: pam_unix(sudo:session): session closed for user root Feb 07 21:14:44 volumio volumio[918]: info: Getting Spotify volume Feb 07 21:14:44 volumio volumio[918]: info: Connection to go-librespot Websocket closed Feb 07 21:14:44 volumio volumio[918]: error: Cannot start Volumio Streaming Daemon Feb 07 21:14:44 volumio volumio[918]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 21:14:44 volumio volumio[918]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 21:14:44 volumio go-librespot[1315]: time="2026-02-07T21:14:44+07: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 07 21:14:44 volumio go-librespot[1315]: time="2026-02-07T21:14:44+07: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 07 21:14:44 volumio go-librespot[1315]: time="2026-02-07T21:14:44+07: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 07 21:14:44 volumio volumio[918]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 07 21:14:44 volumio go-librespot[1315]: time="2026-02-07T21:14:44+07:00" level=info msg="zeroconf server listening on port 40161" Feb 07 21:14:44 volumio volumio[918]: info: CoreCommandRouter::volumioGetState Feb 07 21:14:44 volumio volumio[918]: info: CorePlayQueue::getTrack 0 Feb 07 21:14:44 volumio volumio[918]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 07 21:14:44 volumio volumio[918]: SPOTIFY: SPOTIFY VOLUME undefined Feb 07 21:14:44 volumio volumio[918]: SPOTIFY: VOLUMIO VOLUME 100 Feb 07 21:14:44 volumio volumio[918]: info: Aligning Spotify Volume to Volumio Volume Feb 07 21:14:44 volumio volumio[918]: info: CoreCommandRouter::volumioGetState Feb 07 21:14:44 volumio volumio[918]: info: CorePlayQueue::getTrack 0 Feb 07 21:14:44 volumio volumio[918]: info: Setting Spotify Volume from Volumio: 100 Feb 07 21:14:44 volumio go-librespot[1315]: time="2026-02-07T21:14:44+07:00" level=debug msg="obtained new client token: AACTZqRsPr9lorgxXmiAIEZtuIO8WtUt8bj/7jLU5dRS5jZ5OFWBtCNVjXSX4rj48LYTwrwyB9/oR3k6VZclcDoFlGHB9W02X+SGHWmA2ExQXAmUJugYB8Ye1LNNlJT2/4JsosOuRn+eZ5aX7WEQ+UXx+0veXrW7hFG1N9mIYM6ChPVhLPXQA/ZnhuvHeeF/c6D61WQyIKjbNtG4ZLeHI61JpTgEXxHIm/8QOcUxTismJIhpdI9uwxlDYA==" Feb 07 21:14:44 volumio go-librespot[1315]: time="2026-02-07T21:14:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:14:44 volumio go-librespot[1315]: time="2026-02-07T21:14:44+07:00" level=debug msg="completed keyexchange" Feb 07 21:14:44 volumio go-librespot[1315]: time="2026-02-07T21:14:44+07:00" level=debug msg="completed challenge" Feb 07 21:14:44 volumio go-librespot[1315]: time="2026-02-07T21:14:44+07: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 07 21:14:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:14:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:14:44 volumio volumio[918]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 21:14:44 volumio volumio[918]: Error: socket hang up Feb 07 21:14:44 volumio volumio[918]: at connResetException (node:internal/errors:720:14) Feb 07 21:14:44 volumio volumio[918]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 07 21:14:44 volumio volumio[918]: at Socket.emit (node:events:526:35) Feb 07 21:14:44 volumio volumio[918]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 07 21:14:44 volumio volumio[918]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 07 21:14:44 volumio volumio[918]: code: 'ECONNRESET', Feb 07 21:14:44 volumio volumio[918]: response: undefined Feb 07 21:14:44 volumio volumio[918]: } Feb 07 21:14:44 volumio volumio[918]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 21:14:46 volumio sudo[1344]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 21:13' Feb 07 21:14:46 volumio sudo[1344]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"