Feb 17 17:06:00 volumio go-librespot[24951]: time="2026-02-17T17:06:00+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 17 17:06:00 volumio go-librespot[24951]: time="2026-02-17T17:06:00+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 17 17:06:00 volumio go-librespot[24951]: time="2026-02-17T17:06:00+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 17 17:06:00 volumio go-librespot[24951]: time="2026-02-17T17:06:00+07:00" level=info msg="zeroconf server listening on port 41929"
Feb 17 17:06:00 volumio go-librespot[24951]: time="2026-02-17T17:06:00+07:00" level=debug msg="obtained new client token: AABXYDLFsEy3LyBaKrEY8QksrjAxWNJwOhAWHs4QLDblpGaqsQlVK3OJfg9wqrqs3dCAVuEAiV5HzJMhznW+OEqtfDYAeXpULcQVFmmGdlThnjNP9HwKgvczSwrLX98tOAIddL117PEGcil0KPvabvwmKfeu6WxKPmAftMutcr8Fh8MWoH6Tm2xo1e84uVcWH+mVr/seU22Tv280Bm1vb2dAGV1CXsFW3JHFeG/KQJV0JEgMnXZiJAtF4g=="
Feb 17 17:06:00 volumio go-librespot[24951]: time="2026-02-17T17:06:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:06:00 volumio go-librespot[24951]: time="2026-02-17T17:06:00+07:00" level=debug msg="completed keyexchange"
Feb 17 17:06:00 volumio go-librespot[24951]: time="2026-02-17T17:06:00+07:00" level=debug msg="completed challenge"
Feb 17 17:06:00 volumio go-librespot[24951]: time="2026-02-17T17:06: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 17 17:06:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:06:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:06:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Feb 17 17:06:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:03 volumio go-librespot[24975]: go-librespot daemon starting...
Feb 17 17:06:03 volumio go-librespot[24976]: time="2026-02-17T17:06:03+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:06:03 volumio go-librespot[24976]: time="2026-02-17T17:06:03+07:00" level=debug msg="app state loaded"
Feb 17 17:06:03 volumio go-librespot[24976]: time="2026-02-17T17:06:03+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:06:04 volumio go-librespot[24976]: time="2026-02-17T17:06: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-gew4.spotify.com:80]"
Feb 17 17:06:04 volumio go-librespot[24976]: time="2026-02-17T17:06:04+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 17 17:06:04 volumio go-librespot[24976]: time="2026-02-17T17:06:04+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 17 17:06:04 volumio go-librespot[24976]: time="2026-02-17T17:06:04+07:00" level=info msg="zeroconf server listening on port 34209"
Feb 17 17:06:04 volumio go-librespot[24976]: time="2026-02-17T17:06:04+07:00" level=debug msg="obtained new client token: AACV85i6ZNrlK+PIHezQu2D1s0ktGvNiv64ncdemvtIBFPPAF524jtuSVI/WN+ujBbWWJHvzxviwQ0kLYzyNy3e36ecvXtD/k9Y3M5N3ekZ7gqjSlXYErmeSj5ec+Fy2SwX6TrmTqF0sJ7bVuE/lgdvePISdJvg5S4HTvORaH4Z9rFoCTAKWAeV5RWL8S/qU77vHTfCJLwEdtED0/TuL271zOGsjJS4ByQXk1ewu8sxYc8GjpwyUtDVmTw=="
Feb 17 17:06:04 volumio go-librespot[24976]: time="2026-02-17T17:06:04+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 17 17:06:04 volumio go-librespot[24976]: time="2026-02-17T17:06:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 17 17:06:04 volumio go-librespot[24976]: time="2026-02-17T17:06:04+07:00" level=debug msg="completed keyexchange"
Feb 17 17:06:04 volumio go-librespot[24976]: time="2026-02-17T17:06:04+07:00" level=debug msg="completed challenge"
Feb 17 17:06:04 volumio go-librespot[24976]: time="2026-02-17T17:06: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 17 17:06:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:06:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:06:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Feb 17 17:06:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:08 volumio go-librespot[24983]: go-librespot daemon starting...
Feb 17 17:06:08 volumio go-librespot[24984]: time="2026-02-17T17:06:08+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:06:08 volumio go-librespot[24984]: time="2026-02-17T17:06:08+07:00" level=debug msg="app state loaded"
Feb 17 17:06:08 volumio go-librespot[24984]: time="2026-02-17T17:06:08+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:06:08 volumio go-librespot[24984]: time="2026-02-17T17:06: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 17 17:06:08 volumio go-librespot[24984]: time="2026-02-17T17:06:08+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 17 17:06:08 volumio go-librespot[24984]: time="2026-02-17T17:06:08+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 17 17:06:08 volumio go-librespot[24984]: time="2026-02-17T17:06:08+07:00" level=info msg="zeroconf server listening on port 45757"
Feb 17 17:06:08 volumio go-librespot[24984]: time="2026-02-17T17:06:08+07:00" level=debug msg="obtained new client token: AAARivBijxKgCawaO4uQBOOGhBCFlL1gU4esNZ5kdjUAeiwUo07no4J9TWftJY3m9uI+P3kYVLhiosREvLKJEsmnP5S+PCdv5CPgaarlfUtubtTExtaJgAQXHB619OXHln5QxB1/kJ9SG/orATJ28urh9kFiholZ4Ti7Zw4Cj72veol2CDngKMLJW0xSRxZuor1pcGsie/BtOCxy+4ZCfKl3uqyamKWrrD/nL5xnmzRdk5+p3LQH3aQ/mQ=="
Feb 17 17:06:09 volumio go-librespot[24984]: time="2026-02-17T17:06:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:06:09 volumio go-librespot[24984]: time="2026-02-17T17:06:09+07:00" level=debug msg="completed keyexchange"
Feb 17 17:06:09 volumio go-librespot[24984]: time="2026-02-17T17:06:09+07:00" level=debug msg="completed challenge"
Feb 17 17:06:09 volumio go-librespot[24984]: time="2026-02-17T17:06: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 17 17:06:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:06:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:06:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Feb 17 17:06:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:12 volumio go-librespot[25005]: go-librespot daemon starting...
Feb 17 17:06:12 volumio go-librespot[25006]: time="2026-02-17T17:06:12+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:06:12 volumio go-librespot[25006]: time="2026-02-17T17:06:12+07:00" level=debug msg="app state loaded"
Feb 17 17:06:12 volumio go-librespot[25006]: time="2026-02-17T17:06:12+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:06:12 volumio go-librespot[25006]: time="2026-02-17T17:06:12+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 17 17:06:12 volumio go-librespot[25006]: time="2026-02-17T17:06:12+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 17 17:06:12 volumio go-librespot[25006]: time="2026-02-17T17:06:12+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 17 17:06:12 volumio go-librespot[25006]: time="2026-02-17T17:06:12+07:00" level=info msg="zeroconf server listening on port 33373"
Feb 17 17:06:13 volumio go-librespot[25006]: time="2026-02-17T17:06:13+07:00" level=debug msg="obtained new client token: AABOs+4p/hWeL8BXM/RZsU8amnE9rJPx13Xm4YNqZmKMzfMfnD4+OurJPKgPY4aOSjDylv7X+mxzW48zcaQNUxMVhO8JmJ6sbfxQTeMXKLe/KrEGRfSh0TQRW6k637RcTfhiVT5eFjrgoF3GN1UE1POklWSIot44Vxy/O3RQsTk3B7rpMqlMcNVv6AnZlT7c9kc/V910raXnJjVK7QcGd0KUpJVzAs5VGzgHNIZU+EHsAqSbC5fWax0="
Feb 17 17:06:13 volumio go-librespot[25006]: time="2026-02-17T17:06:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:06:13 volumio go-librespot[25006]: time="2026-02-17T17:06:13+07:00" level=debug msg="completed keyexchange"
Feb 17 17:06:13 volumio go-librespot[25006]: time="2026-02-17T17:06:13+07:00" level=debug msg="completed challenge"
Feb 17 17:06:13 volumio go-librespot[25006]: time="2026-02-17T17:06: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 17 17:06:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:06:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:06:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Feb 17 17:06:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:16 volumio go-librespot[25013]: go-librespot daemon starting...
Feb 17 17:06:16 volumio go-librespot[25014]: time="2026-02-17T17:06:16+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:06:16 volumio go-librespot[25014]: time="2026-02-17T17:06:16+07:00" level=debug msg="app state loaded"
Feb 17 17:06:16 volumio go-librespot[25014]: time="2026-02-17T17:06:16+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:06:17 volumio go-librespot[25014]: time="2026-02-17T17:06: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 17 17:06:17 volumio go-librespot[25014]: time="2026-02-17T17:06:17+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 17 17:06:17 volumio go-librespot[25014]: time="2026-02-17T17:06:17+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 17 17:06:17 volumio go-librespot[25014]: time="2026-02-17T17:06:17+07:00" level=info msg="zeroconf server listening on port 43113"
Feb 17 17:06:17 volumio go-librespot[25014]: time="2026-02-17T17:06:17+07:00" level=debug msg="obtained new client token: AAAHTrjFwZbbMVcqpOGsMXg7A5lnBNx1rs++lGN6PDVWrVxPBWPu/WKtGIfLBYVw2J8G5T4kAxQPZKv49XwltYYJHxT2p/YnWBBEJuAw6ARKIXJwMmH1b3D3ZPrtW4r3yA00F+bX15MErRIJ8r3sb8gul+iPAuGwn/4ToNVqc1vCSlkpgBgppk/negPT9bI85cbNXYo2fgZjuIQAhtln42j30WIwt41WyukhFU8xfx/vXeA5/mSfjCbEbw=="
Feb 17 17:06:17 volumio go-librespot[25014]: time="2026-02-17T17:06:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:06:17 volumio go-librespot[25014]: time="2026-02-17T17:06:17+07:00" level=debug msg="completed keyexchange"
Feb 17 17:06:17 volumio go-librespot[25014]: time="2026-02-17T17:06:17+07:00" level=debug msg="completed challenge"
Feb 17 17:06:17 volumio go-librespot[25014]: time="2026-02-17T17:06: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 17 17:06:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:06:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:06:20 volumio volumio-remote-updater[25144]: [2026-02-17 17:06:20] [error] handle_read_frame error: asio.system:104 (Connection reset by peer)
Feb 17 17:06:20 volumio volumio-remote-updater[25144]: [2026-02-17 17:06:20] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006]
Feb 17 17:06:20 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:06:20 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 17 17:06:20 volumio systemd[1]: volumio.service: Consumed 51.105s CPU time.
Feb 17 17:06:20 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 17 17:06:20 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 17 17:06:20 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 20632.
Feb 17 17:06:20 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 17 17:06:20 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 17 17:06:20 volumio systemd[1]: volumio.service: Consumed 51.105s CPU time.
Feb 17 17:06:20 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 17 17:06:20 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 17 17:06:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Feb 17 17:06:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:20 volumio go-librespot[25043]: go-librespot daemon starting...
Feb 17 17:06:20 volumio go-librespot[25044]: time="2026-02-17T17:06:20+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:06:20 volumio go-librespot[25044]: time="2026-02-17T17:06:20+07:00" level=debug msg="app state loaded"
Feb 17 17:06:20 volumio go-librespot[25044]: time="2026-02-17T17:06:20+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:06:21 volumio go-librespot[25044]: time="2026-02-17T17:06: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 17 17:06:21 volumio go-librespot[25044]: time="2026-02-17T17:06: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 17 17:06:21 volumio go-librespot[25044]: time="2026-02-17T17:06: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 17 17:06:21 volumio go-librespot[25044]: time="2026-02-17T17:06:21+07:00" level=info msg="zeroconf server listening on port 43487"
Feb 17 17:06:21 volumio go-librespot[25044]: time="2026-02-17T17:06:21+07:00" level=debug msg="obtained new client token: AADQKR5ToskN652WfmUNGrpSQ7MZQZbNgL3GzteTKZsEuV1BSKh/pSkOAKzgRF5YSpEWJsCH7gGVcmbHw21+PHS8qkG93W0l/OkjH1KQW6mZd2uSv5eScXqfKvVFAmBgP5tCRGpClQWrtDxS10cGHT4zSflX02/zvQlKUATYpTGoxmPdFl034Tr32lbCIxLKPQuVOmQLED3yO71NoMC4e5ahI4zfzTn3MQZQ7MfdntMBf9+wtknNFlCb+A=="
Feb 17 17:06:21 volumio go-librespot[25044]: time="2026-02-17T17:06:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:06:21 volumio go-librespot[25044]: time="2026-02-17T17:06:21+07:00" level=debug msg="completed keyexchange"
Feb 17 17:06:21 volumio go-librespot[25044]: time="2026-02-17T17:06:21+07:00" level=debug msg="completed challenge"
Feb 17 17:06:22 volumio go-librespot[25044]: time="2026-02-17T17:06: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 17 17:06:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:06:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:06:24 volumio volumio[25028]: info: -------------------------------------------
Feb 17 17:06:24 volumio volumio[25028]: info: ----- Volumio3 ----
Feb 17 17:06:24 volumio volumio[25028]: info: -------------------------------------------
Feb 17 17:06:24 volumio volumio[25028]: info: ----- System startup ----
Feb 17 17:06:24 volumio volumio[25028]: info: -------------------------------------------
Feb 17 17:06:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11.
Feb 17 17:06:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:25 volumio volumio-remote-updater[25144]: [2026-02-17 17:06:25] [connect] Successful connection
Feb 17 17:06:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:25 volumio go-librespot[25059]: go-librespot daemon starting...
Feb 17 17:06:25 volumio go-librespot[25060]: time="2026-02-17T17:06:25+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:06:25 volumio go-librespot[25060]: time="2026-02-17T17:06:25+07:00" level=debug msg="app state loaded"
Feb 17 17:06:25 volumio go-librespot[25060]: time="2026-02-17T17:06:25+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:06:25 volumio volumio[25028]: info: MYVOLUMIO Environment detected
Feb 17 17:06:25 volumio volumio[25028]: info: Plugin folders cleanup
Feb 17 17:06:25 volumio volumio[25028]: info: Scanning into folder /volumio/app/plugins/
Feb 17 17:06:25 volumio volumio[25028]: info: Scanning category audio_interface
Feb 17 17:06:25 volumio volumio[25028]: info: Scanning category miscellanea
Feb 17 17:06:25 volumio volumio[25028]: info: Scanning category music_service
Feb 17 17:06:25 volumio volumio[25028]: info: Scanning category plugins.json
Feb 17 17:06:25 volumio volumio[25028]: info: Scanning category system_controller
Feb 17 17:06:25 volumio volumio[25028]: info: Scanning category user_interface
Feb 17 17:06:25 volumio volumio[25028]: info: Scanning into folder /data/plugins/
Feb 17 17:06:25 volumio volumio[25028]: info: Scanning category music_service
Feb 17 17:06:25 volumio volumio[25028]: info: Plugin folders cleanup completed
Feb 17 17:06:25 volumio volumio[25028]: info: -------------------------------------------
Feb 17 17:06:25 volumio volumio[25028]: info: ----- Core plugins startup ----
Feb 17 17:06:25 volumio volumio[25028]: info: -------------------------------------------
Feb 17 17:06:25 volumio volumio[25028]: info: Loading plugins from folder /volumio/app/plugins/
Feb 17 17:06:25 volumio volumio[25028]: info: Adding plugin upnp to MyMusic Plugins
Feb 17 17:06:25 volumio volumio[25028]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 17 17:06:25 volumio volumio[25028]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 17 17:06:25 volumio volumio[25028]: info: Loading plugins from folder /data/plugins/
Feb 17 17:06:25 volumio volumio[25028]: info: Loading plugin "system"...
Feb 17 17:06:25 volumio volumio[25028]: info: Loading plugin "appearance"...
Feb 17 17:06:25 volumio go-librespot[25060]: time="2026-02-17T17:06:25+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 17 17:06:25 volumio go-librespot[25060]: time="2026-02-17T17:06:25+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 17 17:06:25 volumio go-librespot[25060]: time="2026-02-17T17:06:25+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 17 17:06:25 volumio go-librespot[25060]: time="2026-02-17T17:06:25+07:00" level=info msg="zeroconf server listening on port 42749"
Feb 17 17:06:26 volumio go-librespot[25060]: time="2026-02-17T17:06:26+07:00" level=debug msg="obtained new client token: AACx74UZH6Z3RVT6Vl0OV9IQkCdWbWzt6ctUyyCE0ZBRNCfZmgyYn53u0x7KhM8+dGKWXeju4p2YhSxAEaGvguMIecABPsE5AxcxWYBVJwfBvG7eZCKhjFD43NLk3gPCI8q7mmTnyriUCySMKt9i7eAHYTPM/NlrTnqgu5gjyviw+ODzpXsBrrkS7DBLdva/ZltVFoA8sPOhMfjFD+zUcirYzgP6pgPbzmUKhVxbXshZSf2MIdn0ORo="
Feb 17 17:06:26 volumio go-librespot[25060]: time="2026-02-17T17:06:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:06:26 volumio go-librespot[25060]: time="2026-02-17T17:06:26+07:00" level=debug msg="completed keyexchange"
Feb 17 17:06:26 volumio go-librespot[25060]: time="2026-02-17T17:06:26+07:00" level=debug msg="completed challenge"
Feb 17 17:06:26 volumio go-librespot[25060]: time="2026-02-17T17:06: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 17 17:06:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:06:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:06:27 volumio volumio[25028]: info: Loading plugin "network"...
Feb 17 17:06:27 volumio volumio[25028]: info: Refreshing Cached IP Addresses
Feb 17 17:06:27 volumio sudo[25074]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 17 17:06:27 volumio sudo[25074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:06:27 volumio sudo[25076]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 17 17:06:27 volumio sudo[25076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:06:27 volumio sudo[25074]: pam_unix(sudo:session): session closed for user root
Feb 17 17:06:27 volumio volumio[25028]: info: Loading plugin "services"...
Feb 17 17:06:27 volumio volumio[25028]: info: Loading plugin "alsa_controller"...
Feb 17 17:06:27 volumio sudo[25076]: pam_unix(sudo:session): session closed for user root
Feb 17 17:06:27 volumio sudo[25084]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 17 17:06:27 volumio sudo[25084]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:06:27 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 17 17:06:27 volumio volumio[25028]: info: Loading plugin "wizard"...
Feb 17 17:06:27 volumio volumio[25028]: info: Loading plugin "networkfs"...
Feb 17 17:06:27 volumio volumio[25028]: info: Starting Udev Watcher for removable devices
Feb 17 17:06:27 volumio volumio[25028]: info: Ignoring mount for partition: boot
Feb 17 17:06:27 volumio volumio[25028]: info: Ignoring mount for partition: volumio
Feb 17 17:06:27 volumio volumio[25028]: info: Ignoring mount for partition: volumio_data
Feb 17 17:06:27 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 17 17:06:27 volumio volumio[25028]: info: Loading plugin "volumio_command_line_client"...
Feb 17 17:06:28 volumio volumio[25028]: info: Loading plugin "upnp"...
Feb 17 17:06:28 volumio volumio[25028]: info: [1771322788019] Starting Upmpd Daemon
Feb 17 17:06:28 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 17 17:06:28 volumio volumio[25028]: info: Loading plugin "my_music"...
Feb 17 17:06:28 volumio volumio[25028]: info: Loading plugin "mpd"...
Feb 17 17:06:28 volumio volumio[25028]: info: Loading plugin "upnp_browser"...
Feb 17 17:06:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12.
Feb 17 17:06:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:29 volumio go-librespot[25107]: go-librespot daemon starting...
Feb 17 17:06:29 volumio go-librespot[25108]: time="2026-02-17T17:06:29+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:06:29 volumio go-librespot[25108]: time="2026-02-17T17:06:29+07:00" level=debug msg="app state loaded"
Feb 17 17:06:29 volumio go-librespot[25108]: time="2026-02-17T17:06:29+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:06:30 volumio go-librespot[25108]: time="2026-02-17T17:06:30+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 17 17:06:30 volumio go-librespot[25108]: time="2026-02-17T17:06:30+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 17 17:06:30 volumio go-librespot[25108]: time="2026-02-17T17:06:30+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 17 17:06:30 volumio go-librespot[25108]: time="2026-02-17T17:06:30+07:00" level=info msg="zeroconf server listening on port 42409"
Feb 17 17:06:30 volumio go-librespot[25108]: time="2026-02-17T17:06:30+07:00" level=debug msg="obtained new client token: AABfun0EgjVdTI9HIflBkcGaONX50ecPO8UMrb1tR2X2RtlAkm4LZ9dWW+subF2+0kdSCibqotBknFHRT4k/eSne+nw7GncZxwff3uEMoPSxbR2WypnIxrqLFR823zj1/6552ob4sDOPBNWS3O5XBYem0807A0LOJ0PxWcixjZ4UHuxJVwJ2wTtoqS1pydIbLTemwF/3RxC5HQ3qqcGcRHlYks21hff1hg2ZUYzdzjVqIVQA0OLV/kPZFw=="
Feb 17 17:06:30 volumio go-librespot[25108]: time="2026-02-17T17:06:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:06:30 volumio sudo[25084]: pam_unix(sudo:session): session closed for user root
Feb 17 17:06:30 volumio go-librespot[25108]: time="2026-02-17T17:06:30+07:00" level=debug msg="completed keyexchange"
Feb 17 17:06:30 volumio go-librespot[25108]: time="2026-02-17T17:06:30+07:00" level=debug msg="completed challenge"
Feb 17 17:06:30 volumio go-librespot[25108]: time="2026-02-17T17:06:30+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 17 17:06:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:06:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:06:31 volumio volumio[25028]: info: Starting UPNP Browser
Feb 17 17:06:31 volumio volumio[25028]: info: Loading plugin "alarm-clock"...
Feb 17 17:06:31 volumio volumio[25028]: info: Loading plugin "airplay_emulation"...
Feb 17 17:06:32 volumio volumio[25028]: info: Starting Shairport Sync
Feb 17 17:06:32 volumio volumio[25028]: info: Loading plugin "last_100"...
Feb 17 17:06:32 volumio volumio[25028]: info: Loading plugin "webradio"...
Feb 17 17:06:32 volumio volumio[25028]: info: Loading plugin "i2s_dacs"...
Feb 17 17:06:32 volumio volumio[25028]: info: Loading plugin "volumiodiscovery"...
Feb 17 17:06:32 volumio volumio[25028]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 17 17:06:32 volumio volumio[25028]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 17 17:06:32 volumio volumio[25028]: *** WARNING *** For more information see
Feb 17 17:06:32 volumio volumio[25028]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 17 17:06:32 volumio volumio[25028]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 17 17:06:32 volumio volumio[25028]: *** WARNING *** For more information see
Feb 17 17:06:32 volumio node[25028]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 17 17:06:32 volumio node[25028]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 17 17:06:32 volumio node[25028]: *** WARNING *** For more information see
Feb 17 17:06:32 volumio node[25028]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 17 17:06:32 volumio node[25028]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 17 17:06:32 volumio node[25028]: *** WARNING *** For more information see
Feb 17 17:06:32 volumio volumio[25028]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 17 17:06:32 volumio volumio[25028]: info: Discovery: Started advertising with name: Volumio
Feb 17 17:06:32 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 17 17:06:32 volumio volumio[25028]: info: Loading plugin "spop"...
Feb 17 17:06:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13.
Feb 17 17:06:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:33 volumio go-librespot[25117]: go-librespot daemon starting...
Feb 17 17:06:33 volumio go-librespot[25118]: time="2026-02-17T17:06:33+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:06:33 volumio go-librespot[25118]: time="2026-02-17T17:06:33+07:00" level=debug msg="app state loaded"
Feb 17 17:06:33 volumio go-librespot[25118]: time="2026-02-17T17:06:33+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:06:34 volumio volumio[25028]: info: Loading plugin "ytcr"...
Feb 17 17:06:34 volumio go-librespot[25118]: time="2026-02-17T17:06:34+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 17 17:06:34 volumio go-librespot[25118]: time="2026-02-17T17:06:34+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 17 17:06:34 volumio go-librespot[25118]: time="2026-02-17T17:06:34+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 17 17:06:34 volumio go-librespot[25118]: time="2026-02-17T17:06:34+07:00" level=info msg="zeroconf server listening on port 41139"
Feb 17 17:06:34 volumio go-librespot[25118]: time="2026-02-17T17:06:34+07:00" level=debug msg="obtained new client token: AABJDFrKUto4fmlRnQBxm5jYTUemsQHd30fevkeioKVcOKCOClYV6fHTNiK/fxPjRbqjNgOVOUvauOvbYuOuhJrZaj9OypoKEqAa5xwROcWpHi+qL/SDEWv2ZTK+wVSKEISSUf7dCCxsff0XKYPfESOHX+rqDnr2WoFZeVGiKJzzSkvl/CH/GhKlmG/mmyVXTY7FZN4idiGPDhwgCAkWbDjzdQTBYjU/5KzAju1zq1C3UvxKEr1MFVJR9w=="
Feb 17 17:06:34 volumio go-librespot[25118]: time="2026-02-17T17:06:34+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 17 17:06:34 volumio go-librespot[25118]: time="2026-02-17T17:06:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 17 17:06:34 volumio go-librespot[25118]: time="2026-02-17T17:06:34+07:00" level=debug msg="completed keyexchange"
Feb 17 17:06:35 volumio go-librespot[25118]: time="2026-02-17T17:06:34+07:00" level=debug msg="completed challenge"
Feb 17 17:06:35 volumio go-librespot[25118]: time="2026-02-17T17:06:35+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 17 17:06:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:06:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:06:36 volumio volumio[25028]: info: Loading plugin "ytmusic"...
Feb 17 17:06:37 volumio volumio-remote-updater[25144]: [2026-02-17 17:06:37] [connect] Successful connection
Feb 17 17:06:38 volumio volumio[25028]: info: Loading plugin "outputs"...
Feb 17 17:06:38 volumio volumio[25028]: info: Loading plugin "albumart"...
Feb 17 17:06:38 volumio volumio[25028]: info: Plugin example_plugin is not enabled
Feb 17 17:06:38 volumio volumio[25028]: info: Loading plugin "inputs"...
Feb 17 17:06:38 volumio volumio[25028]: info: Loading plugin "updater_comm"...
Feb 17 17:06:38 volumio volumio[25028]: info: Plugin mpdemulation is not enabled
Feb 17 17:06:38 volumio volumio[25028]: info: Loading plugin "rest_api"...
Feb 17 17:06:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14.
Feb 17 17:06:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:38 volumio volumio[25028]: info: Loading plugin "websocket"...
Feb 17 17:06:38 volumio volumio[25028]: info: Starting Socket.io Server version 1.7.4
Feb 17 17:06:38 volumio volumio[25028]: info: Loading plugin "RoonBridge"...
Feb 17 17:06:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:38 volumio go-librespot[25153]: go-librespot daemon starting...
Feb 17 17:06:38 volumio go-librespot[25154]: time="2026-02-17T17:06:38+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:06:38 volumio go-librespot[25154]: time="2026-02-17T17:06:38+07:00" level=debug msg="app state loaded"
Feb 17 17:06:38 volumio go-librespot[25154]: time="2026-02-17T17:06:38+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:06:38 volumio volumio[25028]: info: Applying required configuration parameters for plugin RoonBridge
Feb 17 17:06:39 volumio volumio[25028]: info: Loading i18n strings for locale en
Feb 17 17:06:39 volumio volumio[25028]: Updating browse sources language
Feb 17 17:06:39 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 17:06:39 volumio go-librespot[25154]: time="2026-02-17T17:06: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 17 17:06:39 volumio go-librespot[25154]: time="2026-02-17T17:06:39+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 17 17:06:39 volumio go-librespot[25154]: time="2026-02-17T17:06:39+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 17 17:06:39 volumio go-librespot[25154]: time="2026-02-17T17:06:39+07:00" level=info msg="zeroconf server listening on port 44191"
Feb 17 17:06:39 volumio volumio[25140]: Forking 3 albumart workers
Feb 17 17:06:39 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 17 17:06:39 volumio volumio[25028]: info: CoreCommandRouter::initPlayerControls
Feb 17 17:06:39 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:39 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:39 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:39 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:39 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:39 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:39 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:39 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:39 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 17 17:06:39 volumio volumio[25028]: Express server listening on port 3000
Feb 17 17:06:39 volumio volumio[25028]: [Metrics] WebUI: 16s 176.07ms
Feb 17 17:06:39 volumio go-librespot[25154]: time="2026-02-17T17:06:39+07:00" level=debug msg="obtained new client token: AABdw7FfMt7JtJZuURE0MY3O/GBFqsYJjhSkcqWak6vCX+BmbFHZA15AWCrDUrpmJef9ohGh05Ntso3fcC35WeC42yZcQldyNUvrP7SVVCzYUt05Pn7Y7SIcl0FTUEnu5G2HaI1+33DsGbdSg73S6xrnzNbMgjN+Ju9K2tDL/lQGkKGAJY6libjpE7Q9vk84m4/iQAkH5qCU8K5ipcLVXc1Zfvo+itMTFjuTlFZq+c9mlb1z5N9KOsG3yA=="
Feb 17 17:06:39 volumio volumio[25028]: info: CoreStateMachine::resetVolumioState
Feb 17 17:06:39 volumio volumio[25028]: info: CoreStateMachine::getcurrentVolume
Feb 17 17:06:39 volumio volumio[25028]: info: CoreCommandRouter::volumioRetrievevolume
Feb 17 17:06:39 volumio go-librespot[25154]: time="2026-02-17T17:06:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:06:39 volumio go-librespot[25154]: time="2026-02-17T17:06:39+07:00" level=debug msg="completed keyexchange"
Feb 17 17:06:39 volumio go-librespot[25154]: time="2026-02-17T17:06:39+07:00" level=debug msg="completed challenge"
Feb 17 17:06:39 volumio sudo[25193]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 17 17:06:39 volumio sudo[25193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:06:39 volumio sudo[25193]: pam_unix(sudo:session): session closed for user root
Feb 17 17:06:39 volumio sudo[25197]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 17 17:06:39 volumio sudo[25197]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:06:39 volumio sudo[25197]: pam_unix(sudo:session): session closed for user root
Feb 17 17:06:39 volumio go-librespot[25154]: time="2026-02-17T17:06:39+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 17 17:06:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:06:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:06:39 volumio volumio[25028]: info: Volumio Network Manager: Network status updated: 1
Feb 17 17:06:40 volumio volumio[25028]: info: VolumeController:: Volume=100 Mute =false
Feb 17 17:06:40 volumio volumio[25028]: info: CoreStateMachine::pushState
Feb 17 17:06:40 volumio volumio[25028]: info: CorePlayQueue::getTrack 0
Feb 17 17:06:40 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 17 17:06:40 volumio volumio[25028]: info: CoreCommandRouter::volumioPushState
Feb 17 17:06:40 volumio volumio[25028]: info: CoreStateMachine::updateTrackBlock
Feb 17 17:06:40 volumio volumio[25028]: info: CorePlayQueue::getTrackBlock
Feb 17 17:06:40 volumio volumio[25028]: info: CoreCommandRouter::volumioRetrievevolume
Feb 17 17:06:40 volumio volumio-remote-updater[25144]: [2026-02-17 17:06:40] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771322797 101
Feb 17 17:06:40 volumio volumio[25028]: 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 17 17:06:40 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 17:06:40 volumio volumio[25028]: info: Reloading queue from file
Feb 17 17:06:40 volumio volumio[25028]: info: CoreStateMachine::setRepeat null single undefined
Feb 17 17:06:40 volumio volumio[25028]: info: CoreStateMachine::pushState
Feb 17 17:06:40 volumio volumio[25028]: info: CorePlayQueue::getTrack 0
Feb 17 17:06:40 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 17 17:06:40 volumio volumio[25028]: info: CoreCommandRouter::volumioPushState
Feb 17 17:06:40 volumio volumio[25028]: info: CoreStateMachine::setRandom null
Feb 17 17:06:40 volumio volumio[25028]: info: CoreStateMachine::pushState
Feb 17 17:06:40 volumio volumio[25028]: info: CorePlayQueue::getTrack 0
Feb 17 17:06:40 volumio volumio[25028]: info: CoreCommandRouter::volumioPushState
Feb 17 17:06:40 volumio volumio[25028]: info: Setting Device type: Raspberry PI
Feb 17 17:06:40 volumio volumio[25028]: info: Completed loading Core Plugins
Feb 17 17:06:40 volumio volumio[25028]: info: Preparing to generate the ALSA configuration file
Feb 17 17:06:40 volumio volumio[25028]: info: VolumeController:: Volume=100 Mute =false
Feb 17 17:06:40 volumio volumio[25028]: info: CoreStateMachine::pushState
Feb 17 17:06:40 volumio volumio[25028]: info: CorePlayQueue::getTrack 0
Feb 17 17:06:40 volumio volumio[25028]: info: CoreCommandRouter::volumioPushState
Feb 17 17:06:40 volumio volumio[25028]: info: Asound.conf file unchanged, so no further update is needed
Feb 17 17:06:40 volumio volumio[25028]: info: Output device has changed, restarting MPD
Feb 17 17:06:40 volumio volumio[25028]: info: Output device has changed, restarting Shairport Sync
Feb 17 17:06:40 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:40 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 17:06:40 volumio sudo[25212]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 17 17:06:40 volumio sudo[25212]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:06:40 volumio sudo[25214]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 17 17:06:40 volumio sudo[25214]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:06:40 volumio sudo[25214]: pam_unix(sudo:session): session closed for user root
Feb 17 17:06:40 volumio sudo[25216]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 17 17:06:40 volumio sudo[25216]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:06:40 volumio volumio[25028]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 17 17:06:40 volumio volumio[25028]: info: ___________ START PLUGINS ___________
Feb 17 17:06:40 volumio volumio[25028]: info: ControllerMpd::onStart: Initializing MPD
Feb 17 17:06:40 volumio volumio[25028]: info: Creating MPD Configuration file
Feb 17 17:06:40 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 17 17:06:40 volumio volumio[25028]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 17:06:40 volumio volumio[25028]: info: [1771322800840] CoreMusicLibrary::Adding element Media Servers
Feb 17 17:06:40 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 17:06:40 volumio sudo[25212]: pam_unix(sudo:session): session closed for user root
Feb 17 17:06:40 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 17 17:06:40 volumio sudo[25225]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 17 17:06:40 volumio sudo[25225]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:06:40 volumio sudo[25225]: pam_unix(sudo:session): session closed for user root
Feb 17 17:06:40 volumio volumio[25028]: info: UPNP Browser: Client initialized successfully
Feb 17 17:06:40 volumio sudo[25227]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 17 17:06:41 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 17 17:06:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 17 17:06:41 volumio systemd[1]: mpd.service: Consumed 7.155s CPU time.
Feb 17 17:06:41 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 17 17:06:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 17 17:06:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 17 17:06:41 volumio sudo[25227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:06:41 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:41 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 17:06:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 17 17:06:41 volumio volumio[25028]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 17 17:06:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 17 17:06:41 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:41 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 17:06:41 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 17 17:06:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 17 17:06:41 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 17 17:06:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 17 17:06:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 17 17:06:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 17 17:06:41 volumio volumio[25028]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 17 17:06:41 volumio volumio[25028]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 17:06:41 volumio volumio[25028]: info: [1771322801245] CoreMusicLibrary::Adding element Last_100
Feb 17 17:06:41 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 17:06:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 17 17:06:41 volumio volumio[25028]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 17:06:41 volumio volumio[25028]: info: [1771322801268] CoreMusicLibrary::Adding element Webradio
Feb 17 17:06:41 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 17:06:41 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 17 17:06:41 volumio volumio[25028]: info: Initializing BBC Radios
Feb 17 17:06:41 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 17 17:06:41 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 17:06:41 volumio volumio[25028]: info: Creating Spotify config file
Feb 17 17:06:41 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:41 volumio sudo[25241]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 17 17:06:41 volumio sudo[25241]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 17 17:06:41 volumio sudo[25241]: pam_unix(sudo:session): session closed for user root
Feb 17 17:06:42 volumio volumio[25163]: Starting albumart workers
Feb 17 17:06:42 volumio volumio[25162]: Starting albumart workers
Feb 17 17:06:42 volumio volumio[25161]: Starting albumart workers
Feb 17 17:06:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15.
Feb 17 17:06:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:42 volumio volumio[25028]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 17:06:42 volumio volumio[25028]: info: [1771322802876] CoreMusicLibrary::Adding element YouTube Music
Feb 17 17:06:42 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 17:06:42 volumio volumio[25028]: Cannot find translation for source YouTube Music
Feb 17 17:06:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:42 volumio go-librespot[25258]: go-librespot daemon starting...
Feb 17 17:06:42 volumio volumio[25028]: info: Volumio Calling Home
Feb 17 17:06:42 volumio go-librespot[25259]: time="2026-02-17T17:06:42+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:06:43 volumio sudo[25262]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 17 17:06:43 volumio sudo[25262]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:06:43 volumio sudo[25262]: pam_unix(sudo:session): session closed for user root
Feb 17 17:06:43 volumio go-librespot[25259]: time="2026-02-17T17:06:43+07:00" level=info msg="zeroconf server listening on port 32787"
Feb 17 17:06:44 volumio volumio[25028]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 17 17:06:44 volumio volumio[25028]: info: Discovery: Found device Volumio
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::volumioGetState
Feb 17 17:06:44 volumio volumio[25028]: info: CorePlayQueue::getTrack 0
Feb 17 17:06:44 volumio volumio[25028]: info: MPD Permissions set
Feb 17 17:06:44 volumio volumio[25028]: info: MPD Permissions set
Feb 17 17:06:44 volumio volumio[25028]: info: Upmpdcli Daemon Started
Feb 17 17:06:44 volumio volumio[25028]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7
Feb 17 17:06:44 volumio volumio[25028]: info: Discovery: Found device Volumio
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::volumioGetState
Feb 17 17:06:44 volumio volumio[25028]: info: CorePlayQueue::getTrack 0
Feb 17 17:06:44 volumio volumio[25028]: info: Volumio called home
Feb 17 17:06:44 volumio volumio[25028]: info: Spotify config file written
Feb 17 17:06:44 volumio volumio[25028]: 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 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:44 volumio sudo[25275]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 17 17:06:44 volumio sudo[25275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:06:44 volumio volumio[25028]: info: No need to fix Spotify hosts
Feb 17 17:06:44 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Feb 17 17:06:44 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Feb 17 17:06:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:44 volumio go-librespot[25293]: go-librespot daemon starting...
Feb 17 17:06:44 volumio sudo[25275]: pam_unix(sudo:session): session closed for user root
Feb 17 17:06:44 volumio go-librespot[25294]: time="2026-02-17T17:06:44+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:06:44 volumio go-librespot[25294]: time="2026-02-17T17:06:44+07:00" level=debug msg="app state loaded"
Feb 17 17:06:44 volumio go-librespot[25294]: time="2026-02-17T17:06:44+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:06:45 volumio go-librespot[25294]: time="2026-02-17T17:06:45+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 17 17:06:45 volumio go-librespot[25294]: time="2026-02-17T17:06:45+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 17 17:06:45 volumio go-librespot[25294]: time="2026-02-17T17:06:45+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 17 17:06:45 volumio go-librespot[25294]: time="2026-02-17T17:06:45+07:00" level=info msg="zeroconf server listening on port 41725"
Feb 17 17:06:45 volumio volumio[25028]: info: Starting Shairport Sync
Feb 17 17:06:45 volumio volumio[25028]: info: Starting Shairport Sync
Feb 17 17:06:45 volumio volumio[25028]: info: Starting Shairport Sync
Feb 17 17:06:45 volumio sudo[25314]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 17 17:06:45 volumio go-librespot[25294]: time="2026-02-17T17:06:45+07:00" level=debug msg="obtained new client token: AAA6W1igeVVPgUrZ0Cp6Jht42F1EcHpkCnljNpWHvrzRk+NAHnD/9D11dfylhRa5W6QaeJVBd9NABX2dBx7sL3GYyRw5hZP11HJrE1OVLrluXyVOdd/SBTyGcbLpzeTkTjdYCLqTEXeH3MpqCcTOTtOHlzMsQ+B1hY3uQN37PLEJ02jiqSUepyK6BTG9bQjzbc8NUxEVgMxDYOcgEjRfYdvuqCF2zdwHik7Stnv4zbuAuyCUsLYPZeqWDQ=="
Feb 17 17:06:45 volumio sudo[25314]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:06:45 volumio sudo[25316]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 17 17:06:45 volumio sudo[25316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:06:45 volumio sudo[25318]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 17 17:06:45 volumio sudo[25318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:06:45 volumio go-librespot[25294]: time="2026-02-17T17:06:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:06:45 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 17 17:06:45 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 17 17:06:45 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 17 17:06:45 volumio systemd[1]: shairport-sync.service: Consumed 2.456s CPU time.
Feb 17 17:06:45 volumio go-librespot[25294]: time="2026-02-17T17:06:45+07:00" level=debug msg="completed keyexchange"
Feb 17 17:06:45 volumio go-librespot[25294]: time="2026-02-17T17:06:45+07:00" level=debug msg="completed challenge"
Feb 17 17:06:45 volumio volumio[25028]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 17 17:06:45 volumio volumio[25028]: SPOTIFY: BQAJzo4hM9epvTMHcl3LIuNqNhKd_vGvNYrHrzFfjShs-k72u2wkfufvEdCiDQUeL3LvAGEErj_x7lUn7sYQOyLa5y-tROxWfQ5eQf92pwdzbig7UkOsUwaNneaVX18XtdV3OjOzq_eUmfBSAJ-Jl3MHQBtBtFztexHaVw0UhRxeyMoB9PK4X8IfCLrO4msAoIPSwr5u4-EN6OyHMWzM_AkBVUKrbNC3-m0Kkcph68z2e6XPfPfvy35V85EOZRFgfQkGAjFEIH55DozP_ClggRqhfYuXwYWbhqYLCRgbhKJ2xVgrMQ3QaRNI
Feb 17 17:06:45 volumio volumio[25028]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 17 17:06:45 volumio volumio[25028]: info: New Spotify access token = BQAJzo4hM9epvTMHcl3LIuNqNhKd_vGvNYrHrzFfjShs-k72u2wkfufvEdCiDQUeL3LvAGEErj_x7lUn7sYQOyLa5y-tROxWfQ5eQf92pwdzbig7UkOsUwaNneaVX18XtdV3OjOzq_eUmfBSAJ-Jl3MHQBtBtFztexHaVw0UhRxeyMoB9PK4X8IfCLrO4msAoIPSwr5u4-EN6OyHMWzM_AkBVUKrbNC3-m0Kkcph68z2e6XPfPfvy35V85EOZRFgfQkGAjFEIH55DozP_ClggRqhfYuXwYWbhqYLCRgbhKJ2xVgrMQ3QaRNI
Feb 17 17:06:45 volumio volumio[25028]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 17 17:06:46 volumio go-librespot[25294]: time="2026-02-17T17:06:45+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 17 17:06:46 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 17 17:06:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:06:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:06:46 volumio sudo[25314]: pam_unix(sudo:session): session closed for user root
Feb 17 17:06:46 volumio volumio[25028]: info: CoreCommandRouter::volumioGetState
Feb 17 17:06:46 volumio volumio[25028]: info: CorePlayQueue::getTrack 0
Feb 17 17:06:46 volumio volumio[25028]: info: Shairport-Sync Started
Feb 17 17:06:46 volumio volumio[25028]: Error adding Membership: Error: addMembership EINVAL
Feb 17 17:06:46 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 17 17:06:46 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 17 17:06:46 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 17 17:06:46 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 17 17:06:46 volumio sudo[25316]: pam_unix(sudo:session): session closed for user root
Feb 17 17:06:46 volumio sudo[25318]: pam_unix(sudo:session): session closed for user root
Feb 17 17:06:46 volumio volumio[25028]: info: Shairport-Sync Started
Feb 17 17:06:46 volumio volumio[25028]: info: Shairport-Sync Started
Feb 17 17:06:46 volumio volumio[25028]: 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 17 17:06:46 volumio volumio[25028]: info: Spotify Successfully logged in
Feb 17 17:06:46 volumio volumio[25028]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 17:06:46 volumio volumio[25028]: info: [1771322806700] CoreMusicLibrary::Adding element Spotify
Feb 17 17:06:46 volumio volumio[25028]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 17:06:46 volumio volumio[25028]: Cannot find translation for source YouTube Music
Feb 17 17:06:46 volumio volumio[25028]: Cannot find translation for source Spotify
Feb 17 17:06:46 volumio volumio[25028]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 17 17:06:46 volumio volumio[25028]: info: CoreCommandRouter::volumioRetrievevolume
Feb 17 17:06:47 volumio volumio[25028]: info: VolumeController:: Volume=100 Mute =false
Feb 17 17:06:47 volumio volumio[25028]: info: CoreCommandRouter::volumioGetState
Feb 17 17:06:47 volumio volumio[25028]: info: CorePlayQueue::getTrack 0
Feb 17 17:06:47 volumio volumio[25028]: info: CoreStateMachine::pushState
Feb 17 17:06:47 volumio volumio[25028]: info: CorePlayQueue::getTrack 0
Feb 17 17:06:47 volumio volumio[25028]: info: CoreCommandRouter::volumioPushState
Feb 17 17:06:48 volumio volumio[25028]: info: go-librespot daemon successfully initialized
Feb 17 17:06:48 volumio mpd[25257]: 2026-02-17T17:06:48 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 17 17:06:48 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 17 17:06:48 volumio sudo[25227]: pam_unix(sudo:session): session closed for user root
Feb 17 17:06:48 volumio sudo[25216]: pam_unix(sudo:session): session closed for user root
Feb 17 17:06:49 volumio volumio[25028]: error: MPD error: The expression evaluated to a falsy value:
Feb 17 17:06:49 volumio volumio[25028]: assert.ok(self.idling)
Feb 17 17:06:49 volumio volumio[25028]: error: The expression evaluated to a falsy value:
Feb 17 17:06:49 volumio volumio[25028]: assert.ok(self.idling)
Feb 17 17:06:49 volumio volumio[25028]: error: updateQueue error: null
Feb 17 17:06:49 volumio volumio[25028]: info: MPD running with PID25257
Feb 17 17:06:49 volumio volumio[25028]: ,establishing connection
Feb 17 17:06:49 volumio volumio[25028]: info: Completed starting Core Plugins
Feb 17 17:06:49 volumio volumio[25028]: info: -------------------------------------------
Feb 17 17:06:49 volumio volumio[25028]: info: ----- MyVolumio plugins startup ----
Feb 17 17:06:49 volumio volumio[25028]: info: -------------------------------------------
Feb 17 17:06:49 volumio volumio[25028]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 17 17:06:49 volumio volumio[25028]: error: updateQueue error: null
Feb 17 17:06:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Feb 17 17:06:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:49 volumio go-librespot[25373]: go-librespot daemon starting...
Feb 17 17:06:49 volumio go-librespot[25374]: time="2026-02-17T17:06:49+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:06:49 volumio go-librespot[25374]: time="2026-02-17T17:06:49+07:00" level=debug msg="app state loaded"
Feb 17 17:06:49 volumio go-librespot[25374]: time="2026-02-17T17:06:49+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:06:49 volumio go-librespot[25374]: time="2026-02-17T17:06:49+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 17 17:06:49 volumio go-librespot[25374]: time="2026-02-17T17:06:49+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 17 17:06:49 volumio go-librespot[25374]: time="2026-02-17T17:06:49+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 17 17:06:49 volumio go-librespot[25374]: time="2026-02-17T17:06:49+07:00" level=info msg="zeroconf server listening on port 43447"
Feb 17 17:06:50 volumio go-librespot[25374]: time="2026-02-17T17:06:50+07:00" level=debug msg="obtained new client token: AABi6IGVPUypGixJZkkEjiXk2LP9CUy2sB+r5f0AsBXrfnuXV72tXsxNGMbI+0pHQdUqIy86C7vzkCniNjI/FJJPoUIz1SAVJJmtea2QB1UsCvUOoX0tYNW+gvqd+Q2egPHCF+Cf5BFUxGnGk/JBHWfx1k8N+5Mkge3dysD00JkiFsNACkkIEzTUsjdztafJfgTjB1axhY3CJoavrM1wqDnLmUvaIhws6J2Wy8ijGVstRIi3kOhlazQ="
Feb 17 17:06:50 volumio go-librespot[25374]: time="2026-02-17T17:06:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:06:50 volumio go-librespot[25374]: time="2026-02-17T17:06:50+07:00" level=debug msg="completed keyexchange"
Feb 17 17:06:50 volumio go-librespot[25374]: time="2026-02-17T17:06:50+07:00" level=debug msg="completed challenge"
Feb 17 17:06:50 volumio go-librespot[25374]: time="2026-02-17T17:06:50+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 17 17:06:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:06:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:06:51 volumio volumio[25028]: info: Initializing connection to go-librespot Websocket
Feb 17 17:06:51 volumio volumio[25028]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 17 17:06:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Feb 17 17:06:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:53 volumio go-librespot[25381]: go-librespot daemon starting...
Feb 17 17:06:53 volumio go-librespot[25382]: time="2026-02-17T17:06:53+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:06:53 volumio go-librespot[25382]: time="2026-02-17T17:06:53+07:00" level=debug msg="app state loaded"
Feb 17 17:06:53 volumio go-librespot[25382]: time="2026-02-17T17:06:53+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:06:53 volumio volumio[25028]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Feb 17 17:06:54 volumio go-librespot[25382]: time="2026-02-17T17:06:54+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 17 17:06:54 volumio go-librespot[25382]: time="2026-02-17T17:06:54+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 17 17:06:54 volumio go-librespot[25382]: time="2026-02-17T17:06:54+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 17 17:06:54 volumio go-librespot[25382]: time="2026-02-17T17:06:54+07:00" level=info msg="zeroconf server listening on port 39455"
Feb 17 17:06:54 volumio go-librespot[25382]: time="2026-02-17T17:06:54+07:00" level=debug msg="obtained new client token: AADvOG4Eb4JZkxxW3CnUvm7H+sUJuhPmSeuy5g4vBUsNsvvXGqwzXWeHRJaNA76ouyN7i9WP1CzVjX9fmkW/vC+UjVT2BhgoY70EvsDe4jxfbEBw9wcBQ+oQid7S5cKtFk/4jJfpKgZpoVx99qx2cxi3JGYu6qqzC8aHtjvwh2NtphIshs/Nn2rU09wSPNLptLJLrddH8Po3IrMNOZv1Xx13hezNSlDrfaCq36s5X2QDCGbBMlSTED3yoQ=="
Feb 17 17:06:54 volumio go-librespot[25382]: time="2026-02-17T17:06:54+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 17 17:06:54 volumio go-librespot[25382]: time="2026-02-17T17:06:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 17 17:06:54 volumio volumio[25028]: info: Initializing connection to go-librespot Websocket
Feb 17 17:06:54 volumio go-librespot[25382]: time="2026-02-17T17:06:54+07:00" level=debug msg="new websocket client"
Feb 17 17:06:54 volumio volumio[25028]: info: Connection to go-librespot Websocket established
Feb 17 17:06:54 volumio go-librespot[25382]: time="2026-02-17T17:06:54+07:00" level=debug msg="completed keyexchange"
Feb 17 17:06:54 volumio go-librespot[25382]: time="2026-02-17T17:06:54+07:00" level=debug msg="completed challenge"
Feb 17 17:06:54 volumio go-librespot[25382]: time="2026-02-17T17:06:54+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 17 17:06:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:06:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:06:54 volumio volumio[25028]: info: Connection to go-librespot Websocket closed
Feb 17 17:06:57 volumio volumio[25028]: info: Getting Spotify volume
Feb 17 17:06:57 volumio volumio[25028]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 17 17:06:57 volumio volumio[25028]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 17 17:06:57 volumio volumio[25028]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 17 17:06:57 volumio volumio[25028]: errno: -111,
Feb 17 17:06:57 volumio volumio[25028]: code: 'ECONNREFUSED',
Feb 17 17:06:57 volumio volumio[25028]: syscall: 'connect',
Feb 17 17:06:57 volumio volumio[25028]: address: '127.0.0.1',
Feb 17 17:06:57 volumio volumio[25028]: port: 9879,
Feb 17 17:06:57 volumio volumio[25028]: response: undefined
Feb 17 17:06:57 volumio volumio[25028]: }
Feb 17 17:06:57 volumio volumio[25028]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 17 17:06:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Feb 17 17:06:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:06:57 volumio go-librespot[25400]: go-librespot daemon starting...
Feb 17 17:06:57 volumio go-librespot[25402]: time="2026-02-17T17:06:57+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:06:57 volumio go-librespot[25402]: time="2026-02-17T17:06:57+07:00" level=debug msg="app state loaded"
Feb 17 17:06:57 volumio go-librespot[25402]: time="2026-02-17T17:06:57+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:06:58 volumio go-librespot[25402]: time="2026-02-17T17:06:58+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 17 17:06:58 volumio go-librespot[25402]: time="2026-02-17T17:06:58+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 17 17:06:58 volumio go-librespot[25402]: time="2026-02-17T17:06:58+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 17 17:06:58 volumio go-librespot[25402]: time="2026-02-17T17:06:58+07:00" level=info msg="zeroconf server listening on port 33007"
Feb 17 17:06:58 volumio go-librespot[25402]: time="2026-02-17T17:06:58+07:00" level=debug msg="obtained new client token: AACF2sK9zJRk/u8JwH4IWwEwfj42sRyoUC3tggAEw6X7BMsP5RrQfBkjGkeyPJ1OsPefHCWalO82XFryXMDvVNvEG0kjEMhV+R4WIAJmXzpg9N68/JPMIhnNi0xDKNzyLt+RYADVR/TSmZJsmqpMhK05qgLoWqzY2hhTwD08dOuzudn0+ClpODO4IHVarCthvOC/B6RDd9N1tsXSAgNqfwxmD6oup4ccoGPvhERyKJqP31lRC14yH1VHpw=="
Feb 17 17:06:58 volumio go-librespot[25402]: time="2026-02-17T17:06:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:06:58 volumio go-librespot[25402]: time="2026-02-17T17:06:58+07:00" level=debug msg="completed keyexchange"
Feb 17 17:06:58 volumio go-librespot[25402]: time="2026-02-17T17:06:58+07:00" level=debug msg="completed challenge"
Feb 17 17:06:58 volumio go-librespot[25402]: time="2026-02-17T17:06: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 17 17:06:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:06:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:06:59 volumio sudo[25425]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 17:05'
Feb 17 17:06:59 volumio sudo[25425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:06:59 volumio sudo[25425]: pam_unix(sudo:session): session closed for user root
Feb 17 17:06:59 volumio volumio-remote-updater[25144]: [2026-02-17 17:06:59] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Feb 17 17:06:59 volumio volumio-remote-updater[25144]: [2026-02-17 17:06:59] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Feb 17 17:06:59 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:06:59 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 17 17:06:59 volumio systemd[1]: volumio.service: Consumed 49.430s CPU time.
Feb 17 17:06:59 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 17 17:06:59 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 17 17:06:59 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 20633.
Feb 17 17:06:59 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 17 17:06:59 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 17 17:06:59 volumio systemd[1]: volumio.service: Consumed 49.430s CPU time.
Feb 17 17:06:59 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 17 17:06:59 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 17 17:07:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Feb 17 17:07:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:02 volumio go-librespot[25453]: go-librespot daemon starting...
Feb 17 17:07:02 volumio go-librespot[25454]: time="2026-02-17T17:07:02+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:07:02 volumio go-librespot[25454]: time="2026-02-17T17:07:02+07:00" level=debug msg="app state loaded"
Feb 17 17:07:02 volumio go-librespot[25454]: time="2026-02-17T17:07:02+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:07:02 volumio go-librespot[25454]: time="2026-02-17T17:07: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 17 17:07:02 volumio go-librespot[25454]: time="2026-02-17T17:07:02+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 17 17:07:02 volumio go-librespot[25454]: time="2026-02-17T17:07:02+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 17 17:07:02 volumio go-librespot[25454]: time="2026-02-17T17:07:02+07:00" level=info msg="zeroconf server listening on port 35725"
Feb 17 17:07:02 volumio go-librespot[25454]: time="2026-02-17T17:07:02+07:00" level=debug msg="obtained new client token: AABRnFDaPiok+ueerENFT31emaez4ZNKbM53UyRsC1mNGp/SHv4RkHE1qr0R6s3vOOpr+Q7tlCjD/+JbBVtHvl4OJZMQdeAnFtbZtt+UWSiYXxdNFLvx0TnsaadpmtZ7LVdBjJj25nUAugJKgVO7kATFhudenA48cOgFs7WUAa/DskZjqviM8CaJzN8GKl3CWRuuJ3JY5PgyTlO/YproJtNX8FbUuHHZWA3t+/6rO/o1Wurwoiun0LDJrQ=="
Feb 17 17:07:02 volumio go-librespot[25454]: time="2026-02-17T17:07:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:07:03 volumio go-librespot[25454]: time="2026-02-17T17:07:03+07:00" level=debug msg="completed keyexchange"
Feb 17 17:07:03 volumio go-librespot[25454]: time="2026-02-17T17:07:03+07:00" level=debug msg="completed challenge"
Feb 17 17:07:03 volumio go-librespot[25454]: time="2026-02-17T17:07: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 17 17:07:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:07:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:07:03 volumio volumio[25437]: info: -------------------------------------------
Feb 17 17:07:03 volumio volumio[25437]: info: ----- Volumio3 ----
Feb 17 17:07:03 volumio volumio[25437]: info: -------------------------------------------
Feb 17 17:07:03 volumio volumio[25437]: info: ----- System startup ----
Feb 17 17:07:03 volumio volumio[25437]: info: -------------------------------------------
Feb 17 17:07:04 volumio volumio-remote-updater[25144]: [2026-02-17 17:07:04] [connect] Successful connection
Feb 17 17:07:04 volumio volumio[25437]: info: MYVOLUMIO Environment detected
Feb 17 17:07:05 volumio volumio[25437]: info: Plugin folders cleanup
Feb 17 17:07:05 volumio volumio[25437]: info: Scanning into folder /volumio/app/plugins/
Feb 17 17:07:05 volumio volumio[25437]: info: Scanning category audio_interface
Feb 17 17:07:05 volumio volumio[25437]: info: Scanning category miscellanea
Feb 17 17:07:05 volumio volumio[25437]: info: Scanning category music_service
Feb 17 17:07:05 volumio volumio[25437]: info: Scanning category plugins.json
Feb 17 17:07:05 volumio volumio[25437]: info: Scanning category system_controller
Feb 17 17:07:05 volumio volumio[25437]: info: Scanning category user_interface
Feb 17 17:07:05 volumio volumio[25437]: info: Scanning into folder /data/plugins/
Feb 17 17:07:05 volumio volumio[25437]: info: Scanning category music_service
Feb 17 17:07:05 volumio volumio[25437]: info: Plugin folders cleanup completed
Feb 17 17:07:05 volumio volumio[25437]: info: -------------------------------------------
Feb 17 17:07:05 volumio volumio[25437]: info: ----- Core plugins startup ----
Feb 17 17:07:05 volumio volumio[25437]: info: -------------------------------------------
Feb 17 17:07:05 volumio volumio[25437]: info: Loading plugins from folder /volumio/app/plugins/
Feb 17 17:07:05 volumio volumio[25437]: info: Adding plugin upnp to MyMusic Plugins
Feb 17 17:07:05 volumio volumio[25437]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 17 17:07:05 volumio volumio[25437]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 17 17:07:05 volumio volumio[25437]: info: Loading plugins from folder /data/plugins/
Feb 17 17:07:05 volumio volumio[25437]: info: Loading plugin "system"...
Feb 17 17:07:05 volumio volumio[25437]: info: Loading plugin "appearance"...
Feb 17 17:07:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Feb 17 17:07:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:06 volumio go-librespot[25473]: go-librespot daemon starting...
Feb 17 17:07:06 volumio go-librespot[25474]: time="2026-02-17T17:07:06+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:07:06 volumio go-librespot[25474]: time="2026-02-17T17:07:06+07:00" level=debug msg="app state loaded"
Feb 17 17:07:06 volumio go-librespot[25474]: time="2026-02-17T17:07:06+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:07:06 volumio go-librespot[25474]: time="2026-02-17T17:07: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 17 17:07:06 volumio go-librespot[25474]: time="2026-02-17T17:07:06+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 17 17:07:06 volumio go-librespot[25474]: time="2026-02-17T17:07:06+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 17 17:07:06 volumio go-librespot[25474]: time="2026-02-17T17:07:06+07:00" level=info msg="zeroconf server listening on port 38447"
Feb 17 17:07:07 volumio volumio[25437]: info: Loading plugin "network"...
Feb 17 17:07:07 volumio volumio[25437]: info: Refreshing Cached IP Addresses
Feb 17 17:07:07 volumio sudo[25482]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 17 17:07:07 volumio go-librespot[25474]: time="2026-02-17T17:07:07+07:00" level=debug msg="obtained new client token: AAD/mfCzrFCumJcnWi3Bc/rVpah66whwmkJILTTB5dVfVrsGN+T1gFf7PA5okLFCZHxA/W/ydUmyes2aeCHc8wU/LCKe08VE/HtcIL4mYG7K3wXOftS7yKGwUx9ff2rMtpMeOQ1fu6dSio8HhNCM1PbfFeosRklArUHln2WJLjwAcXQYmU/xfZe1mbIRzWois7lyf1/gLP6zxGzc3zTN4K42WS7N45g0WekZVpG35Wxjfcsi34/O7gs="
Feb 17 17:07:07 volumio sudo[25482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:07:07 volumio sudo[25484]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 17 17:07:07 volumio volumio[25437]: info: Loading plugin "services"...
Feb 17 17:07:07 volumio sudo[25484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:07:07 volumio sudo[25482]: pam_unix(sudo:session): session closed for user root
Feb 17 17:07:07 volumio volumio[25437]: info: Loading plugin "alsa_controller"...
Feb 17 17:07:07 volumio sudo[25484]: pam_unix(sudo:session): session closed for user root
Feb 17 17:07:07 volumio sudo[25492]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 17 17:07:07 volumio sudo[25492]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:07:07 volumio go-librespot[25474]: time="2026-02-17T17:07:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:07:07 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 17 17:07:07 volumio volumio[25437]: info: Loading plugin "wizard"...
Feb 17 17:07:07 volumio volumio[25437]: info: Loading plugin "networkfs"...
Feb 17 17:07:07 volumio go-librespot[25474]: time="2026-02-17T17:07:07+07:00" level=debug msg="completed keyexchange"
Feb 17 17:07:07 volumio go-librespot[25474]: time="2026-02-17T17:07:07+07:00" level=debug msg="completed challenge"
Feb 17 17:07:07 volumio volumio[25437]: info: Starting Udev Watcher for removable devices
Feb 17 17:07:07 volumio volumio[25437]: info: Ignoring mount for partition: boot
Feb 17 17:07:07 volumio volumio[25437]: info: Ignoring mount for partition: volumio
Feb 17 17:07:07 volumio volumio[25437]: info: Ignoring mount for partition: volumio_data
Feb 17 17:07:07 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 17 17:07:07 volumio volumio[25437]: info: Loading plugin "volumio_command_line_client"...
Feb 17 17:07:07 volumio go-librespot[25474]: time="2026-02-17T17:07: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 17 17:07:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:07:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:07:07 volumio volumio[25437]: info: Loading plugin "upnp"...
Feb 17 17:07:07 volumio volumio[25437]: info: [1771322827522] Starting Upmpd Daemon
Feb 17 17:07:07 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 17 17:07:07 volumio volumio[25437]: info: Loading plugin "my_music"...
Feb 17 17:07:07 volumio volumio[25437]: info: Loading plugin "mpd"...
Feb 17 17:07:08 volumio volumio[25437]: info: Loading plugin "upnp_browser"...
Feb 17 17:07:09 volumio sudo[25492]: pam_unix(sudo:session): session closed for user root
Feb 17 17:07:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Feb 17 17:07:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:10 volumio go-librespot[25515]: go-librespot daemon starting...
Feb 17 17:07:10 volumio go-librespot[25516]: time="2026-02-17T17:07:10+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:07:10 volumio go-librespot[25516]: time="2026-02-17T17:07:10+07:00" level=debug msg="app state loaded"
Feb 17 17:07:10 volumio go-librespot[25516]: time="2026-02-17T17:07:10+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:07:11 volumio volumio[25437]: info: Starting UPNP Browser
Feb 17 17:07:11 volumio volumio[25437]: info: Loading plugin "alarm-clock"...
Feb 17 17:07:11 volumio go-librespot[25516]: time="2026-02-17T17:07: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 17 17:07:11 volumio go-librespot[25516]: time="2026-02-17T17:07:11+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 17 17:07:11 volumio go-librespot[25516]: time="2026-02-17T17:07:11+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 17 17:07:11 volumio go-librespot[25516]: time="2026-02-17T17:07:11+07:00" level=info msg="zeroconf server listening on port 44131"
Feb 17 17:07:11 volumio volumio[25437]: info: Loading plugin "airplay_emulation"...
Feb 17 17:07:11 volumio volumio[25437]: info: Starting Shairport Sync
Feb 17 17:07:11 volumio volumio[25437]: info: Loading plugin "last_100"...
Feb 17 17:07:11 volumio go-librespot[25516]: time="2026-02-17T17:07:11+07:00" level=debug msg="obtained new client token: AABFINJc1dCdzloQZb9I9mwQobK0f/+67lmnGxBKeMTDvNq+gQ0wpeWB8wRB8fMgYm5nxbPeLyk4BQqAlndUnVaQJ/MEZswVW2+IKDGhLIoOxZ4KUIA0gvEmYTCtJ8XlY8cI6a0fgozi4LjqCMnOxgVzOvC9s51ciAnbFniACgmKOO+Ql8L8QZ765yBb7RMDkqJGqDjtTFPYenfCPCFzF4+BqwGQkqNpDNHnP60PARyX93c0Y1Wu7mry9A=="
Feb 17 17:07:11 volumio volumio[25437]: info: Loading plugin "webradio"...
Feb 17 17:07:11 volumio go-librespot[25516]: time="2026-02-17T17:07:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:07:11 volumio volumio[25437]: info: Loading plugin "i2s_dacs"...
Feb 17 17:07:11 volumio volumio[25437]: info: Loading plugin "volumiodiscovery"...
Feb 17 17:07:11 volumio go-librespot[25516]: time="2026-02-17T17:07:11+07:00" level=debug msg="completed keyexchange"
Feb 17 17:07:11 volumio go-librespot[25516]: time="2026-02-17T17:07:11+07:00" level=debug msg="completed challenge"
Feb 17 17:07:11 volumio volumio[25437]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 17 17:07:11 volumio volumio[25437]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 17 17:07:11 volumio volumio[25437]: *** WARNING *** For more information see
Feb 17 17:07:11 volumio volumio[25437]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 17 17:07:11 volumio volumio[25437]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 17 17:07:11 volumio volumio[25437]: *** WARNING *** For more information see
Feb 17 17:07:11 volumio node[25437]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 17 17:07:11 volumio node[25437]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 17 17:07:11 volumio node[25437]: *** WARNING *** For more information see
Feb 17 17:07:11 volumio node[25437]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 17 17:07:11 volumio node[25437]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 17 17:07:11 volumio node[25437]: *** WARNING *** For more information see
Feb 17 17:07:11 volumio volumio[25437]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 17 17:07:11 volumio volumio[25437]: info: Discovery: Started advertising with name: Volumio
Feb 17 17:07:11 volumio go-librespot[25516]: time="2026-02-17T17:07: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 17 17:07:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:07:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:07:11 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 17 17:07:11 volumio volumio[25437]: info: Loading plugin "spop"...
Feb 17 17:07:13 volumio volumio[25437]: info: Loading plugin "ytcr"...
Feb 17 17:07:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Feb 17 17:07:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:15 volumio go-librespot[25528]: go-librespot daemon starting...
Feb 17 17:07:15 volumio go-librespot[25529]: time="2026-02-17T17:07:15+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:07:15 volumio go-librespot[25529]: time="2026-02-17T17:07:15+07:00" level=debug msg="app state loaded"
Feb 17 17:07:15 volumio go-librespot[25529]: time="2026-02-17T17:07:15+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:07:15 volumio go-librespot[25529]: time="2026-02-17T17:07: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 17 17:07:15 volumio go-librespot[25529]: time="2026-02-17T17:07: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 17 17:07:15 volumio go-librespot[25529]: time="2026-02-17T17:07: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 17 17:07:15 volumio go-librespot[25529]: time="2026-02-17T17:07:15+07:00" level=info msg="zeroconf server listening on port 37743"
Feb 17 17:07:15 volumio go-librespot[25529]: time="2026-02-17T17:07:15+07:00" level=debug msg="obtained new client token: AACMdaDjdqEbZFEqCVIedZopBZ00T0PmCT1hy9RZNzR2SW2sxDMFczuXeg2mPqs1TtO4JILaqx8e9UucdSVhLG+9ASDH+wqCNACo0k4sWWIErmynOAVguE6ZOAu2FKSd3VTtmPE37swi3cHYAFMsjCJh+5O0KUo/qpq1v9XfLsxiRAlEuCay3h7egjVXF4B/DPq2mls2+5+1WiY79JCpfxsNStnnXO0Wlx+suL7LsckLzxfzeDCUsqarzg=="
Feb 17 17:07:16 volumio go-librespot[25529]: time="2026-02-17T17:07:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:07:16 volumio go-librespot[25529]: time="2026-02-17T17:07:16+07:00" level=debug msg="completed keyexchange"
Feb 17 17:07:16 volumio go-librespot[25529]: time="2026-02-17T17:07:16+07:00" level=debug msg="completed challenge"
Feb 17 17:07:16 volumio go-librespot[25529]: time="2026-02-17T17:07: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 17 17:07:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:07:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:07:16 volumio volumio[25437]: info: Loading plugin "ytmusic"...
Feb 17 17:07:17 volumio volumio-remote-updater[25144]: [2026-02-17 17:07:17] [connect] Successful connection
Feb 17 17:07:17 volumio volumio[25437]: info: Loading plugin "outputs"...
Feb 17 17:07:17 volumio volumio[25437]: info: Loading plugin "albumart"...
Feb 17 17:07:17 volumio volumio[25437]: info: Plugin example_plugin is not enabled
Feb 17 17:07:17 volumio volumio[25437]: info: Loading plugin "inputs"...
Feb 17 17:07:17 volumio volumio[25437]: info: Loading plugin "updater_comm"...
Feb 17 17:07:17 volumio volumio[25437]: info: Plugin mpdemulation is not enabled
Feb 17 17:07:17 volumio volumio[25437]: info: Loading plugin "rest_api"...
Feb 17 17:07:17 volumio volumio[25437]: info: Loading plugin "websocket"...
Feb 17 17:07:17 volumio volumio[25437]: info: Starting Socket.io Server version 1.7.4
Feb 17 17:07:17 volumio volumio[25437]: info: Loading plugin "RoonBridge"...
Feb 17 17:07:18 volumio volumio[25437]: info: Applying required configuration parameters for plugin RoonBridge
Feb 17 17:07:18 volumio volumio[25437]: info: Loading i18n strings for locale en
Feb 17 17:07:18 volumio volumio[25437]: Updating browse sources language
Feb 17 17:07:18 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 17:07:18 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 17 17:07:18 volumio volumio[25437]: info: CoreCommandRouter::initPlayerControls
Feb 17 17:07:18 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:18 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:18 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:18 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:18 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:18 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:18 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:18 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:18 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 17 17:07:18 volumio volumio[25437]: Express server listening on port 3000
Feb 17 17:07:18 volumio volumio[25437]: [Metrics] WebUI: 16s 99.82ms
Feb 17 17:07:18 volumio volumio[25550]: Forking 3 albumart workers
Feb 17 17:07:18 volumio volumio[25437]: info: CoreStateMachine::resetVolumioState
Feb 17 17:07:18 volumio volumio[25437]: info: CoreStateMachine::getcurrentVolume
Feb 17 17:07:18 volumio volumio[25437]: info: CoreCommandRouter::volumioRetrievevolume
Feb 17 17:07:18 volumio sudo[25586]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 17 17:07:18 volumio sudo[25586]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:07:18 volumio sudo[25586]: pam_unix(sudo:session): session closed for user root
Feb 17 17:07:18 volumio sudo[25584]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 17 17:07:18 volumio sudo[25584]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:07:18 volumio sudo[25584]: pam_unix(sudo:session): session closed for user root
Feb 17 17:07:18 volumio volumio[25437]: info: Volumio Network Manager: Network status updated: 1
Feb 17 17:07:19 volumio volumio[25437]: info: VolumeController:: Volume=100 Mute =false
Feb 17 17:07:19 volumio volumio[25437]: info: CoreStateMachine::pushState
Feb 17 17:07:19 volumio volumio[25437]: info: CorePlayQueue::getTrack 0
Feb 17 17:07:19 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 17 17:07:19 volumio volumio[25437]: info: CoreCommandRouter::volumioPushState
Feb 17 17:07:19 volumio volumio[25437]: info: CoreStateMachine::updateTrackBlock
Feb 17 17:07:19 volumio volumio[25437]: info: CorePlayQueue::getTrackBlock
Feb 17 17:07:19 volumio volumio[25437]: info: CoreCommandRouter::volumioRetrievevolume
Feb 17 17:07:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Feb 17 17:07:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:19 volumio volumio-remote-updater[25144]: [2026-02-17 17:07:19] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771322837 101
Feb 17 17:07:19 volumio volumio[25437]: 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 17 17:07:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:19 volumio go-librespot[25602]: go-librespot daemon starting...
Feb 17 17:07:19 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 17:07:19 volumio go-librespot[25604]: time="2026-02-17T17:07:19+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:07:19 volumio go-librespot[25604]: time="2026-02-17T17:07:19+07:00" level=debug msg="app state loaded"
Feb 17 17:07:19 volumio go-librespot[25604]: time="2026-02-17T17:07:19+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:07:19 volumio volumio[25437]: info: Reloading queue from file
Feb 17 17:07:19 volumio volumio[25437]: info: CoreStateMachine::setRepeat null single undefined
Feb 17 17:07:19 volumio volumio[25437]: info: CoreStateMachine::pushState
Feb 17 17:07:19 volumio volumio[25437]: info: CorePlayQueue::getTrack 0
Feb 17 17:07:19 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 17 17:07:19 volumio volumio[25437]: info: CoreCommandRouter::volumioPushState
Feb 17 17:07:19 volumio volumio[25437]: info: CoreStateMachine::setRandom null
Feb 17 17:07:19 volumio volumio[25437]: info: CoreStateMachine::pushState
Feb 17 17:07:19 volumio volumio[25437]: info: CorePlayQueue::getTrack 0
Feb 17 17:07:19 volumio volumio[25437]: info: CoreCommandRouter::volumioPushState
Feb 17 17:07:19 volumio volumio[25437]: info: Setting Device type: Raspberry PI
Feb 17 17:07:19 volumio volumio[25437]: info: Completed loading Core Plugins
Feb 17 17:07:19 volumio volumio[25437]: info: Preparing to generate the ALSA configuration file
Feb 17 17:07:19 volumio volumio[25437]: info: VolumeController:: Volume=100 Mute =false
Feb 17 17:07:19 volumio volumio[25437]: info: CoreStateMachine::pushState
Feb 17 17:07:19 volumio volumio[25437]: info: CorePlayQueue::getTrack 0
Feb 17 17:07:19 volumio volumio[25437]: info: CoreCommandRouter::volumioPushState
Feb 17 17:07:19 volumio sudo[25618]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 17 17:07:19 volumio sudo[25618]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:07:19 volumio volumio[25437]: info: Asound.conf file unchanged, so no further update is needed
Feb 17 17:07:19 volumio volumio[25437]: info: Output device has changed, restarting MPD
Feb 17 17:07:19 volumio volumio[25437]: info: Output device has changed, restarting Shairport Sync
Feb 17 17:07:20 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:20 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 17:07:20 volumio sudo[25621]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 17 17:07:20 volumio sudo[25618]: pam_unix(sudo:session): session closed for user root
Feb 17 17:07:20 volumio sudo[25621]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:07:20 volumio sudo[25621]: pam_unix(sudo:session): session closed for user root
Feb 17 17:07:20 volumio sudo[25623]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 17 17:07:20 volumio sudo[25623]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:07:20 volumio volumio[25437]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 17 17:07:20 volumio volumio[25437]: info: ___________ START PLUGINS ___________
Feb 17 17:07:20 volumio go-librespot[25604]: time="2026-02-17T17:07: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 17 17:07:20 volumio go-librespot[25604]: time="2026-02-17T17:07:20+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 17 17:07:20 volumio go-librespot[25604]: time="2026-02-17T17:07:20+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 17 17:07:20 volumio volumio[25437]: info: ControllerMpd::onStart: Initializing MPD
Feb 17 17:07:20 volumio volumio[25437]: info: Creating MPD Configuration file
Feb 17 17:07:20 volumio go-librespot[25604]: time="2026-02-17T17:07:20+07:00" level=info msg="zeroconf server listening on port 35655"
Feb 17 17:07:20 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 17 17:07:20 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 17 17:07:20 volumio volumio[25437]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 17:07:20 volumio volumio[25437]: info: [1771322840204] CoreMusicLibrary::Adding element Media Servers
Feb 17 17:07:20 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 17:07:20 volumio volumio[25437]: info: UPNP Browser: Client initialized successfully
Feb 17 17:07:20 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:20 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 17:07:20 volumio sudo[25631]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 17 17:07:20 volumio sudo[25631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:07:20 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 17 17:07:20 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 17 17:07:20 volumio systemd[1]: mpd.service: Consumed 7.145s CPU time.
Feb 17 17:07:20 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 17 17:07:20 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 17 17:07:20 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 17 17:07:20 volumio sudo[25631]: pam_unix(sudo:session): session closed for user root
Feb 17 17:07:20 volumio sudo[25633]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 17 17:07:20 volumio volumio[25437]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 17 17:07:20 volumio sudo[25633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:07:20 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:20 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 17:07:20 volumio go-librespot[25604]: time="2026-02-17T17:07:20+07:00" level=debug msg="obtained new client token: AAD2PejvTSrICnA7Z+BlJmTH6VS1n3q4UFh5XdA2MiTagXMSsWkFm1T4gsCHTCJrU0jJ7c5KjfSp/eWT7FXuNIvSaMefbmhR/DCFRUYPeOnPG3+R2avIKGDGS3DMw6Ht1sTbkquVUa9BtcSic4viG24NB7rWL29r5c1dWoOp0XREj3x3JKZyYI+ra0ppIuPDuz4eNrdO3ym9/tNwWUUK/8J3m/TxWshWQeq9VZapXiLwMWa8OsjtCzFz3w=="
Feb 17 17:07:20 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 17 17:07:20 volumio volumio[25437]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 17 17:07:20 volumio volumio[25437]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 17:07:20 volumio volumio[25437]: info: [1771322840456] CoreMusicLibrary::Adding element Last_100
Feb 17 17:07:20 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 17:07:20 volumio volumio[25437]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 17:07:20 volumio volumio[25437]: info: [1771322840467] CoreMusicLibrary::Adding element Webradio
Feb 17 17:07:20 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 17:07:20 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 17 17:07:20 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 17 17:07:20 volumio volumio[25437]: info: Initializing BBC Radios
Feb 17 17:07:20 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 17 17:07:20 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 17 17:07:20 volumio go-librespot[25604]: time="2026-02-17T17:07:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:07:20 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 17 17:07:20 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 17 17:07:20 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 17 17:07:20 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 17 17:07:20 volumio go-librespot[25604]: time="2026-02-17T17:07:20+07:00" level=debug msg="completed keyexchange"
Feb 17 17:07:20 volumio go-librespot[25604]: time="2026-02-17T17:07:20+07:00" level=debug msg="completed challenge"
Feb 17 17:07:20 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 17 17:07:20 volumio go-librespot[25604]: time="2026-02-17T17:07: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 17 17:07:20 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 17 17:07:20 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 17:07:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:07:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:07:20 volumio volumio[25437]: info: Creating Spotify config file
Feb 17 17:07:20 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:21 volumio sudo[25656]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 17 17:07:21 volumio sudo[25656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 17 17:07:21 volumio sudo[25656]: pam_unix(sudo:session): session closed for user root
Feb 17 17:07:21 volumio volumio[25437]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 17:07:21 volumio volumio[25437]: info: [1771322841887] CoreMusicLibrary::Adding element YouTube Music
Feb 17 17:07:21 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 17:07:21 volumio volumio[25437]: Cannot find translation for source YouTube Music
Feb 17 17:07:21 volumio volumio[25437]: info: Volumio Calling Home
Feb 17 17:07:21 volumio sudo[25665]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 17 17:07:22 volumio sudo[25665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:07:22 volumio sudo[25665]: pam_unix(sudo:session): session closed for user root
Feb 17 17:07:22 volumio volumio[25563]: Starting albumart workers
Feb 17 17:07:22 volumio volumio[25565]: Starting albumart workers
Feb 17 17:07:22 volumio volumio[25564]: Starting albumart workers
Feb 17 17:07:22 volumio volumio[25437]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 17 17:07:22 volumio volumio[25437]: info: Discovery: Found device Volumio
Feb 17 17:07:22 volumio volumio[25437]: info: CoreCommandRouter::volumioGetState
Feb 17 17:07:22 volumio volumio[25437]: info: CorePlayQueue::getTrack 0
Feb 17 17:07:22 volumio volumio[25437]: info: MPD Permissions set
Feb 17 17:07:22 volumio volumio[25437]: info: MPD Permissions set
Feb 17 17:07:22 volumio volumio[25437]: info: Upmpdcli Daemon Started
Feb 17 17:07:22 volumio volumio[25437]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7
Feb 17 17:07:22 volumio volumio[25437]: info: Discovery: Found device Volumio
Feb 17 17:07:22 volumio volumio[25437]: info: CoreCommandRouter::volumioGetState
Feb 17 17:07:22 volumio volumio[25437]: info: CorePlayQueue::getTrack 0
Feb 17 17:07:23 volumio volumio[25437]: info: Spotify config file written
Feb 17 17:07:23 volumio sudo[25671]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 17 17:07:23 volumio sudo[25671]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:07:23 volumio volumio[25437]: 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 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:23 volumio go-librespot[25678]: go-librespot daemon starting...
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 17:07:23 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 17:07:23 volumio sudo[25671]: pam_unix(sudo:session): session closed for user root
Feb 17 17:07:23 volumio volumio[25437]: info: No need to fix Spotify hosts
Feb 17 17:07:23 volumio go-librespot[25684]: time="2026-02-17T17:07:23+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:07:23 volumio go-librespot[25684]: time="2026-02-17T17:07:23+07:00" level=debug msg="app state loaded"
Feb 17 17:07:23 volumio go-librespot[25684]: time="2026-02-17T17:07:23+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:07:24 volumio go-librespot[25684]: time="2026-02-17T17:07:24+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 17 17:07:24 volumio go-librespot[25684]: time="2026-02-17T17:07:24+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 17 17:07:24 volumio go-librespot[25684]: time="2026-02-17T17:07:24+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 17 17:07:24 volumio go-librespot[25684]: time="2026-02-17T17:07:24+07:00" level=info msg="zeroconf server listening on port 43747"
Feb 17 17:07:24 volumio go-librespot[25684]: time="2026-02-17T17:07:24+07:00" level=debug msg="obtained new client token: AAAbNG567Xu98GzPvkJeKcCVSj0M0TDzvhV9K7Mjt25Zp7vk8Y0TPk9VmeriEYpH1UGmn6o9LQIxa8yyRF1MTxTvTCqywFtJVn4sFluhHkVuBuoHaCPcF9xJB5Ym11K4uBaq6S/f4yok14vsydhXCuFhnCOsMZR/0Pw8m5jhcJJxGlRPLBdeYP3Tv/ilrg3OuasCZ/xGheq8tb2xCm4SGLMG4pWH39p+HFiOQR4NTYuOp1sb497ZMhRAIA=="
Feb 17 17:07:24 volumio go-librespot[25684]: time="2026-02-17T17:07:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:07:24 volumio go-librespot[25684]: time="2026-02-17T17:07:24+07:00" level=debug msg="completed keyexchange"
Feb 17 17:07:24 volumio go-librespot[25684]: time="2026-02-17T17:07:24+07:00" level=debug msg="completed challenge"
Feb 17 17:07:24 volumio volumio[25437]: info: Starting Shairport Sync
Feb 17 17:07:24 volumio volumio[25437]: info: Starting Shairport Sync
Feb 17 17:07:24 volumio volumio[25437]: info: Starting Shairport Sync
Feb 17 17:07:24 volumio go-librespot[25684]: time="2026-02-17T17:07:24+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 17 17:07:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:07:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:07:24 volumio sudo[25711]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 17 17:07:24 volumio sudo[25711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:07:25 volumio sudo[25713]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 17 17:07:25 volumio sudo[25713]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:07:25 volumio sudo[25715]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 17 17:07:25 volumio sudo[25715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:07:25 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 17 17:07:25 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 17 17:07:25 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 17 17:07:25 volumio systemd[1]: shairport-sync.service: Consumed 2.208s CPU time.
Feb 17 17:07:25 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 17 17:07:25 volumio volumio[25437]: info: CoreCommandRouter::volumioGetState
Feb 17 17:07:25 volumio volumio[25437]: info: CorePlayQueue::getTrack 0
Feb 17 17:07:25 volumio sudo[25711]: pam_unix(sudo:session): session closed for user root
Feb 17 17:07:25 volumio sudo[25713]: pam_unix(sudo:session): session closed for user root
Feb 17 17:07:25 volumio volumio[25437]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 17 17:07:25 volumio volumio[25437]: SPOTIFY: BQAsPI4j9aKRttRKXmX-y6aJRYn4nBI5ce_P1VviGbQbyXlQ51q643MFkd_Wk7UX-BbJBNqzYSVBO-ndHeoFD3FIwEclvErUOj73XS1LuN0mBCZYzelgq_RLczXBnLXA6gCAVNhaVGjIKTORwV2VpRAwVJHNx9ZcMbCn2PIk2hm8L2cp-zDXFz38_8AkeBgQw4syueSUpfSKa-c08_biQLYcEDpSWYrcxvXp_4HjdczueWMF9_4l_V7HF4ojmbP8mJGb4vtz7OvlmIi7xfR20kHXgGKUKoSyNOHW5GiGbO7NfPnOa1ikG0Gm
Feb 17 17:07:25 volumio volumio[25437]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 17 17:07:25 volumio volumio[25437]: info: New Spotify access token = BQAsPI4j9aKRttRKXmX-y6aJRYn4nBI5ce_P1VviGbQbyXlQ51q643MFkd_Wk7UX-BbJBNqzYSVBO-ndHeoFD3FIwEclvErUOj73XS1LuN0mBCZYzelgq_RLczXBnLXA6gCAVNhaVGjIKTORwV2VpRAwVJHNx9ZcMbCn2PIk2hm8L2cp-zDXFz38_8AkeBgQw4syueSUpfSKa-c08_biQLYcEDpSWYrcxvXp_4HjdczueWMF9_4l_V7HF4ojmbP8mJGb4vtz7OvlmIi7xfR20kHXgGKUKoSyNOHW5GiGbO7NfPnOa1ikG0Gm
Feb 17 17:07:25 volumio volumio[25437]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 17 17:07:25 volumio volumio[25437]: info: Shairport-Sync Started
Feb 17 17:07:25 volumio volumio[25437]: Error adding Membership: Error: addMembership EINVAL
Feb 17 17:07:25 volumio volumio[25437]: info: Shairport-Sync Started
Feb 17 17:07:25 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 17 17:07:25 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 17 17:07:25 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 17 17:07:25 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 17 17:07:25 volumio sudo[25715]: pam_unix(sudo:session): session closed for user root
Feb 17 17:07:25 volumio volumio[25437]: info: Shairport-Sync Started
Feb 17 17:07:25 volumio volumio[25437]: info: Volumio called home
Feb 17 17:07:25 volumio volumio[25437]: 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 17 17:07:25 volumio volumio[25437]: info: Spotify Successfully logged in
Feb 17 17:07:25 volumio volumio[25437]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 17:07:25 volumio volumio[25437]: info: [1771322845819] CoreMusicLibrary::Adding element Spotify
Feb 17 17:07:25 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 17:07:25 volumio volumio[25437]: Cannot find translation for source YouTube Music
Feb 17 17:07:25 volumio volumio[25437]: Cannot find translation for source Spotify
Feb 17 17:07:26 volumio volumio[25437]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 17 17:07:26 volumio volumio[25437]: info: CoreCommandRouter::volumioRetrievevolume
Feb 17 17:07:26 volumio volumio[25437]: info: VolumeController:: Volume=100 Mute =false
Feb 17 17:07:26 volumio volumio[25437]: info: CoreCommandRouter::volumioGetState
Feb 17 17:07:26 volumio volumio[25437]: info: CorePlayQueue::getTrack 0
Feb 17 17:07:26 volumio volumio[25437]: info: CoreStateMachine::pushState
Feb 17 17:07:26 volumio volumio[25437]: info: CorePlayQueue::getTrack 0
Feb 17 17:07:26 volumio volumio[25437]: info: CoreCommandRouter::volumioPushState
Feb 17 17:07:27 volumio volumio[25437]: info: go-librespot daemon successfully initialized
Feb 17 17:07:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Feb 17 17:07:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:28 volumio mpd[25662]: 2026-02-17T17:07:28 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 17 17:07:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:28 volumio go-librespot[25752]: go-librespot daemon starting...
Feb 17 17:07:28 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 17 17:07:28 volumio sudo[25623]: pam_unix(sudo:session): session closed for user root
Feb 17 17:07:28 volumio sudo[25633]: pam_unix(sudo:session): session closed for user root
Feb 17 17:07:28 volumio go-librespot[25755]: time="2026-02-17T17:07:28+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:07:28 volumio go-librespot[25755]: time="2026-02-17T17:07:28+07:00" level=debug msg="app state loaded"
Feb 17 17:07:28 volumio go-librespot[25755]: time="2026-02-17T17:07:28+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:07:28 volumio volumio[25437]: error: MPD error: The expression evaluated to a falsy value:
Feb 17 17:07:28 volumio volumio[25437]: assert.ok(self.idling)
Feb 17 17:07:28 volumio volumio[25437]: error: The expression evaluated to a falsy value:
Feb 17 17:07:28 volumio volumio[25437]: assert.ok(self.idling)
Feb 17 17:07:28 volumio volumio[25437]: error: updateQueue error: null
Feb 17 17:07:28 volumio volumio[25437]: info: MPD running with PID25662
Feb 17 17:07:28 volumio volumio[25437]: ,establishing connection
Feb 17 17:07:28 volumio volumio[25437]: info: Completed starting Core Plugins
Feb 17 17:07:28 volumio volumio[25437]: info: -------------------------------------------
Feb 17 17:07:28 volumio volumio[25437]: info: ----- MyVolumio plugins startup ----
Feb 17 17:07:28 volumio volumio[25437]: info: -------------------------------------------
Feb 17 17:07:28 volumio volumio[25437]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 17 17:07:28 volumio volumio[25437]: error: updateQueue error: null
Feb 17 17:07:28 volumio go-librespot[25755]: time="2026-02-17T17:07:28+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 17 17:07:28 volumio go-librespot[25755]: time="2026-02-17T17:07:28+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 17 17:07:28 volumio go-librespot[25755]: time="2026-02-17T17:07:28+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 17 17:07:28 volumio go-librespot[25755]: time="2026-02-17T17:07:28+07:00" level=info msg="zeroconf server listening on port 37377"
Feb 17 17:07:28 volumio go-librespot[25755]: time="2026-02-17T17:07:28+07:00" level=debug msg="obtained new client token: AADnpnOLmj5UL8qNi5PsZqYSdVgj5Ksz3g57owpV3U9inKJxRDEbPxBnpNsjjkjzhm9oRDXttBWUUVLNyl1CaI7ZDEXSt/NWFzGIGIIihsCeEdDVgGL+qAOgn3fYsNzP/VtG5DL+Qyq8+IeFg9KbHO5lPpPkC7ahwwg/XbYAKbVH9+4aMWOiWE+G5NpjhffefP2NXqv83tLrm92q/RKviglyL9KrTxljRndsDfFIVsrNVPm7PFahOyHZLg=="
Feb 17 17:07:29 volumio go-librespot[25755]: time="2026-02-17T17:07:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:07:29 volumio go-librespot[25755]: time="2026-02-17T17:07:29+07:00" level=debug msg="completed keyexchange"
Feb 17 17:07:29 volumio go-librespot[25755]: time="2026-02-17T17:07:29+07:00" level=debug msg="completed challenge"
Feb 17 17:07:29 volumio go-librespot[25755]: time="2026-02-17T17:07:29+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 17 17:07:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:07:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:07:30 volumio volumio[25437]: info: Initializing connection to go-librespot Websocket
Feb 17 17:07:30 volumio volumio[25437]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 17 17:07:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Feb 17 17:07:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:32 volumio go-librespot[25765]: go-librespot daemon starting...
Feb 17 17:07:32 volumio go-librespot[25766]: time="2026-02-17T17:07:32+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:07:32 volumio go-librespot[25766]: time="2026-02-17T17:07:32+07:00" level=debug msg="app state loaded"
Feb 17 17:07:32 volumio go-librespot[25766]: time="2026-02-17T17:07:32+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:07:32 volumio go-librespot[25766]: time="2026-02-17T17:07:32+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 17 17:07:32 volumio go-librespot[25766]: time="2026-02-17T17:07:32+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 17 17:07:32 volumio go-librespot[25766]: time="2026-02-17T17:07:32+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 17 17:07:32 volumio go-librespot[25766]: time="2026-02-17T17:07:32+07:00" level=info msg="zeroconf server listening on port 33801"
Feb 17 17:07:33 volumio go-librespot[25766]: time="2026-02-17T17:07:33+07:00" level=debug msg="obtained new client token: AABw2uxe00e2I33Rt7ic2P5DaNolTdGe3J81JDv9RFTv4TRWXoPdAthKqOp5K3LlboU2QAau7Ci+ud4dLXyq6JBKBQq7G0LQ4ftFcflMCev2Ns14l358K1hfBgZfcyaeK6n+gMb9/5GSVoscCeYW9wW2el53JrvgfyGCBjjhc3H9xBDDm0fR2ZgH5g44RAiET27kUGyvRift8xwh2Lh/FVaA367lk+n7Ke21pJlprl0gpifHd05FyaI="
Feb 17 17:07:33 volumio volumio[25437]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Feb 17 17:07:33 volumio go-librespot[25766]: time="2026-02-17T17:07:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:07:33 volumio go-librespot[25766]: time="2026-02-17T17:07:33+07:00" level=debug msg="completed keyexchange"
Feb 17 17:07:33 volumio go-librespot[25766]: time="2026-02-17T17:07:33+07:00" level=debug msg="completed challenge"
Feb 17 17:07:33 volumio go-librespot[25766]: time="2026-02-17T17:07:33+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 17 17:07:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:07:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:07:33 volumio volumio[25437]: info: Initializing connection to go-librespot Websocket
Feb 17 17:07:33 volumio volumio[25437]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 17 17:07:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11.
Feb 17 17:07:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:36 volumio go-librespot[25773]: go-librespot daemon starting...
Feb 17 17:07:36 volumio go-librespot[25774]: time="2026-02-17T17:07:36+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:07:36 volumio go-librespot[25774]: time="2026-02-17T17:07:36+07:00" level=debug msg="app state loaded"
Feb 17 17:07:36 volumio go-librespot[25774]: time="2026-02-17T17:07:36+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:07:36 volumio volumio[25437]: info: Initializing connection to go-librespot Websocket
Feb 17 17:07:36 volumio go-librespot[25774]: time="2026-02-17T17:07:36+07:00" level=debug msg="new websocket client"
Feb 17 17:07:36 volumio volumio[25437]: info: Connection to go-librespot Websocket established
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 17 17:07:37 volumio volumio[25437]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 17 17:07:37 volumio volumio[25437]: info: Adding plugin multiroom to MyMusic Plugins
Feb 17 17:07:37 volumio volumio[25437]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 17 17:07:37 volumio volumio[25437]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 17 17:07:37 volumio volumio[25437]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 17 17:07:37 volumio go-librespot[25774]: time="2026-02-17T17:07:37+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 17 17:07:37 volumio go-librespot[25774]: time="2026-02-17T17:07:37+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 17 17:07:37 volumio go-librespot[25774]: time="2026-02-17T17:07:37+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 17 17:07:37 volumio volumio[25437]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 17 17:07:37 volumio volumio[25437]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 17 17:07:37 volumio volumio[25437]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 17 17:07:37 volumio go-librespot[25774]: time="2026-02-17T17:07:37+07:00" level=info msg="zeroconf server listening on port 35889"
Feb 17 17:07:37 volumio go-librespot[25774]: time="2026-02-17T17:07:37+07:00" level=debug msg="obtained new client token: AABDDEPRuOZ/AyQa3qjyaeXNerwj0cZ6mf0XkwUeTSpmDoWNpoePUkAvxymdY9EaLoKq6V5oH1h0MCfEQ4W9hgkgsMMeP1U6iTASvzQcy8Ay5wqp0YDyhOAkWMN6kZ21Td7TOhGyoSMFZtmCbOj+XaHF/3FNfWWV/4QJqhpuTFY6LvMg2mYdhwQb84U8BjFpH4nl3QP/Bpn5ykHhm3BHPPD96eJaOfj9igDbEGY2/F/Vo3tPSJrFwCTfLQ=="
Feb 17 17:07:37 volumio go-librespot[25774]: time="2026-02-17T17:07:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 17:07:37 volumio go-librespot[25774]: time="2026-02-17T17:07:37+07:00" level=debug msg="completed keyexchange"
Feb 17 17:07:37 volumio go-librespot[25774]: time="2026-02-17T17:07:37+07:00" level=debug msg="completed challenge"
Feb 17 17:07:37 volumio go-librespot[25774]: time="2026-02-17T17:07:37+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 17 17:07:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:07:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:07:39 volumio volumio[25437]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 17 17:07:39 volumio volumio[25437]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 17 17:07:39 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 17:07:39 volumio volumio[25437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 17:07:39 volumio volumio[25437]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 17 17:07:39 volumio volumio[25437]: info: MyVolumio login type: Token
Feb 17 17:07:39 volumio volumio[25437]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 17 17:07:39 volumio volumio[25437]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 17 17:07:40 volumio volumio[25437]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 17 17:07:40 volumio volumio[25437]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 17 17:07:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12.
Feb 17 17:07:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:40 volumio volumio[25437]: info: Streaming services startup
Feb 17 17:07:40 volumio volumio[25437]: info: Starting Streaming Daemon
Feb 17 17:07:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 17:07:40 volumio sudo[25798]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 17 17:07:40 volumio sudo[25798]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 17:07:40 volumio go-librespot[25797]: go-librespot daemon starting...
Feb 17 17:07:40 volumio volumio[25437]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 17 17:07:40 volumio go-librespot[25802]: time="2026-02-17T17:07:40+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 17:07:40 volumio go-librespot[25802]: time="2026-02-17T17:07:40+07:00" level=debug msg="app state loaded"
Feb 17 17:07:40 volumio go-librespot[25802]: time="2026-02-17T17:07:40+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 17:07:40 volumio sudo[25798]: pam_unix(sudo:session): session closed for user root
Feb 17 17:07:41 volumio volumio[25437]: info: Getting Spotify volume
Feb 17 17:07:41 volumio volumio[25437]: info: Connection to go-librespot Websocket closed
Feb 17 17:07:41 volumio volumio[25437]: error: Cannot start Volumio Streaming Daemon
Feb 17 17:07:41 volumio volumio[25437]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 17 17:07:41 volumio volumio[25437]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 17 17:07:41 volumio volumio[25437]: 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 17 17:07:41 volumio volumio[25437]: info: CoreCommandRouter::volumioGetState
Feb 17 17:07:41 volumio volumio[25437]: info: CorePlayQueue::getTrack 0
Feb 17 17:07:41 volumio volumio[25437]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 17 17:07:41 volumio volumio[25437]: SPOTIFY: SPOTIFY VOLUME undefined
Feb 17 17:07:41 volumio volumio[25437]: SPOTIFY: VOLUMIO VOLUME 100
Feb 17 17:07:41 volumio volumio[25437]: info: Aligning Spotify Volume to Volumio Volume
Feb 17 17:07:41 volumio volumio[25437]: info: CoreCommandRouter::volumioGetState
Feb 17 17:07:41 volumio volumio[25437]: info: CorePlayQueue::getTrack 0
Feb 17 17:07:41 volumio volumio[25437]: info: Setting Spotify Volume from Volumio: 100
Feb 17 17:07:41 volumio go-librespot[25802]: time="2026-02-17T17:07:41+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 17 17:07:41 volumio go-librespot[25802]: time="2026-02-17T17:07:41+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 17 17:07:41 volumio go-librespot[25802]: time="2026-02-17T17:07:41+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 17 17:07:41 volumio go-librespot[25802]: time="2026-02-17T17:07:41+07:00" level=info msg="zeroconf server listening on port 43431"
Feb 17 17:07:41 volumio go-librespot[25802]: time="2026-02-17T17:07:41+07:00" level=debug msg="obtained new client token: AAAP+FjdbntJRCe2tvNV7cKeNIG8xgw9/4NX7o2dNtY7E158JDuS4cCrcJoUdY6CXUqZiLjDXNXvqL24FMVfxkIrUqHIinwOcZS4P8gLZjyLssFf8MV/ZcaMQ3FTqRxT+gb4EAdaX9w9q84wftsHfM6n8aKoq/f6uoQtrbZ8TyU7n+eAuLv4XOeh/aDmpMqC9By7CmUI5W5ZL6rqMontJU6k3b8Oj64XbqfEYlFKrn0sFcKio4zZHCU4pg=="
Feb 17 17:07:41 volumio go-librespot[25802]: time="2026-02-17T17:07:41+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 17 17:07:41 volumio go-librespot[25802]: time="2026-02-17T17:07:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 17 17:07:42 volumio go-librespot[25802]: time="2026-02-17T17:07:42+07:00" level=debug msg="completed keyexchange"
Feb 17 17:07:42 volumio go-librespot[25802]: time="2026-02-17T17:07:42+07:00" level=debug msg="completed challenge"
Feb 17 17:07:42 volumio go-librespot[25802]: time="2026-02-17T17:07:42+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 17 17:07:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 17:07:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 17:07:42 volumio volumio[25437]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 17 17:07:42 volumio volumio[25437]: Error: socket hang up
Feb 17 17:07:42 volumio volumio[25437]: at connResetException (node:internal/errors:720:14)
Feb 17 17:07:42 volumio volumio[25437]: at Socket.socketOnEnd (node:_http_client:519:23)
Feb 17 17:07:42 volumio volumio[25437]: at Socket.emit (node:events:526:35)
Feb 17 17:07:42 volumio volumio[25437]: at endReadableNT (node:internal/streams/readable:1376:12)
Feb 17 17:07:42 volumio volumio[25437]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Feb 17 17:07:42 volumio volumio[25437]: code: 'ECONNRESET',
Feb 17 17:07:42 volumio volumio[25437]: response: undefined
Feb 17 17:07:42 volumio volumio[25437]: }
Feb 17 17:07:42 volumio volumio[25437]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 17 17:07:43 volumio sudo[25827]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 17:06'
Feb 17 17:07:43 volumio sudo[25827]: 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"