Feb 13 02:08:00 volumio volumio[2672]: info: ------------------------------------------- Feb 13 02:08:00 volumio volumio[2672]: info: ----- Volumio3 ---- Feb 13 02:08:00 volumio volumio[2672]: info: ------------------------------------------- Feb 13 02:08:00 volumio volumio[2672]: info: ----- System startup ---- Feb 13 02:08:00 volumio volumio[2672]: info: ------------------------------------------- Feb 13 02:08:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 13 02:08:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:00 volumio go-librespot[2694]: go-librespot daemon starting... Feb 13 02:08:00 volumio go-librespot[2695]: time="2026-02-13T02:08:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:08:00 volumio go-librespot[2695]: time="2026-02-13T02:08:00+07:00" level=debug msg="app state loaded" Feb 13 02:08:00 volumio go-librespot[2695]: time="2026-02-13T02:08:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:08:01 volumio go-librespot[2695]: time="2026-02-13T02:08:01+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 13 02:08:01 volumio go-librespot[2695]: time="2026-02-13T02:08:01+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 13 02:08:01 volumio go-librespot[2695]: time="2026-02-13T02:08:01+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 13 02:08:01 volumio go-librespot[2695]: time="2026-02-13T02:08:01+07:00" level=info msg="zeroconf server listening on port 43031" Feb 13 02:08:01 volumio go-librespot[2695]: time="2026-02-13T02:08:01+07:00" level=debug msg="obtained new client token: AACE6wEcRW8LGNLMHwpstUX8h/DE0CInswofY5YDL8GQw4UKWQpOvfkKAwvBD269bXyNtcw/gPC6XSKbFUNawnQdGLghN6x+zVy5LWovlcDZ7S0hFfnb1/Cu3EA36tWzZTmKIv4vhlBDSbTy3rud23QLADLpDkSZh85P6dQEVIGlE8PiiaiGoKjwQJl4LFKgEJmoyOKdnOzMO4SyryyqgpvK0/dO+JEygNYdhOmqDQXMKHt37c5iBGeqDg==" Feb 13 02:08:01 volumio volumio-remote-updater[643]: [2026-02-13 02:08:01] [connect] Successful connection Feb 13 02:08:01 volumio go-librespot[2695]: time="2026-02-13T02:08:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 02:08:01 volumio go-librespot[2695]: time="2026-02-13T02:08:01+07:00" level=debug msg="completed keyexchange" Feb 13 02:08:01 volumio go-librespot[2695]: time="2026-02-13T02:08:01+07:00" level=debug msg="completed challenge" Feb 13 02:08:01 volumio volumio[2672]: info: MYVOLUMIO Environment detected Feb 13 02:08:02 volumio go-librespot[2695]: time="2026-02-13T02:08:02+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 13 02:08:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:08:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:08:02 volumio volumio[2672]: info: Plugin folders cleanup Feb 13 02:08:02 volumio volumio[2672]: info: Scanning into folder /volumio/app/plugins/ Feb 13 02:08:02 volumio volumio[2672]: info: Scanning category audio_interface Feb 13 02:08:02 volumio volumio[2672]: info: Scanning category miscellanea Feb 13 02:08:02 volumio volumio[2672]: info: Scanning category music_service Feb 13 02:08:02 volumio volumio[2672]: info: Scanning category plugins.json Feb 13 02:08:02 volumio volumio[2672]: info: Scanning category system_controller Feb 13 02:08:02 volumio volumio[2672]: info: Scanning category user_interface Feb 13 02:08:02 volumio volumio[2672]: info: Scanning into folder /data/plugins/ Feb 13 02:08:02 volumio volumio[2672]: info: Scanning category music_service Feb 13 02:08:02 volumio volumio[2672]: info: Plugin folders cleanup completed Feb 13 02:08:02 volumio volumio[2672]: info: ------------------------------------------- Feb 13 02:08:02 volumio volumio[2672]: info: ----- Core plugins startup ---- Feb 13 02:08:02 volumio volumio[2672]: info: ------------------------------------------- Feb 13 02:08:02 volumio volumio[2672]: info: Loading plugins from folder /volumio/app/plugins/ Feb 13 02:08:02 volumio volumio[2672]: info: Adding plugin upnp to MyMusic Plugins Feb 13 02:08:02 volumio volumio[2672]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 13 02:08:02 volumio volumio[2672]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 13 02:08:02 volumio volumio[2672]: info: Loading plugins from folder /data/plugins/ Feb 13 02:08:02 volumio volumio[2672]: info: Loading plugin "system"... Feb 13 02:08:02 volumio volumio[2672]: info: Loading plugin "appearance"... Feb 13 02:08:04 volumio volumio[2672]: info: Loading plugin "network"... Feb 13 02:08:04 volumio volumio[2672]: info: Refreshing Cached IP Addresses Feb 13 02:08:04 volumio sudo[2709]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 13 02:08:04 volumio sudo[2709]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:04 volumio sudo[2711]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 13 02:08:04 volumio sudo[2711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:04 volumio sudo[2709]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:04 volumio sudo[2711]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:04 volumio volumio[2672]: info: Loading plugin "services"... Feb 13 02:08:04 volumio volumio[2672]: info: Loading plugin "alsa_controller"... Feb 13 02:08:04 volumio sudo[2720]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 13 02:08:04 volumio sudo[2720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:04 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 13 02:08:04 volumio volumio[2672]: info: Loading plugin "wizard"... Feb 13 02:08:04 volumio volumio[2672]: info: Loading plugin "networkfs"... Feb 13 02:08:04 volumio volumio[2672]: info: Starting Udev Watcher for removable devices Feb 13 02:08:04 volumio volumio[2672]: info: Ignoring mount for partition: boot Feb 13 02:08:04 volumio volumio[2672]: info: Ignoring mount for partition: volumio Feb 13 02:08:04 volumio volumio[2672]: info: Ignoring mount for partition: volumio_data Feb 13 02:08:04 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 13 02:08:04 volumio volumio[2672]: info: Loading plugin "volumio_command_line_client"... Feb 13 02:08:04 volumio volumio[2672]: info: Loading plugin "upnp"... Feb 13 02:08:04 volumio volumio[2672]: info: [1770923284490] Starting Upmpd Daemon Feb 13 02:08:04 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 13 02:08:04 volumio volumio[2672]: info: Loading plugin "my_music"... Feb 13 02:08:04 volumio volumio[2672]: info: Loading plugin "mpd"... Feb 13 02:08:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 13 02:08:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:05 volumio volumio[2672]: info: Loading plugin "upnp_browser"... Feb 13 02:08:05 volumio go-librespot[2742]: go-librespot daemon starting... Feb 13 02:08:05 volumio go-librespot[2743]: time="2026-02-13T02:08:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:08:05 volumio go-librespot[2743]: time="2026-02-13T02:08:05+07:00" level=debug msg="app state loaded" Feb 13 02:08:05 volumio go-librespot[2743]: time="2026-02-13T02:08:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:08:05 volumio go-librespot[2743]: time="2026-02-13T02:08:05+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 13 02:08:05 volumio go-librespot[2743]: time="2026-02-13T02:08:05+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 13 02:08:05 volumio go-librespot[2743]: time="2026-02-13T02:08:05+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 13 02:08:05 volumio go-librespot[2743]: time="2026-02-13T02:08:05+07:00" level=info msg="zeroconf server listening on port 46339" Feb 13 02:08:05 volumio go-librespot[2743]: time="2026-02-13T02:08:05+07:00" level=debug msg="obtained new client token: AADnGdk8ul9RXAyh3Ybl34dKN+Yacp2yYk3d2Cg4t/gaGRzrzN74NmWcu1ZGJhOi0v34ggSd+p9478nL2Id8O89AlVqokabDP+7qggK31KnlzLQkYT5yy6hJBmemfAVhaHka2ZEfpYgY1PVRd0lmXT+LcuCA+b9ie1ENh+ugtAJIsuRmIGrSgI1+deLPLHBICEql1TDapFImIxxCJg+vCnq+UGgyVrEcfjCtmk+7ibLdasvdTOCL1BsjZw==" Feb 13 02:08:06 volumio go-librespot[2743]: time="2026-02-13T02:08:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 02:08:06 volumio go-librespot[2743]: time="2026-02-13T02:08:06+07:00" level=debug msg="completed keyexchange" Feb 13 02:08:06 volumio go-librespot[2743]: time="2026-02-13T02:08:06+07:00" level=debug msg="completed challenge" Feb 13 02:08:06 volumio go-librespot[2743]: time="2026-02-13T02:08:06+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 13 02:08:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:08:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:08:06 volumio sudo[2720]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:08 volumio volumio[2672]: info: Starting UPNP Browser Feb 13 02:08:08 volumio volumio[2672]: info: Loading plugin "alarm-clock"... Feb 13 02:08:08 volumio volumio[2672]: info: Loading plugin "airplay_emulation"... Feb 13 02:08:08 volumio volumio[2672]: info: Starting Shairport Sync Feb 13 02:08:08 volumio volumio[2672]: info: Loading plugin "last_100"... Feb 13 02:08:08 volumio volumio[2672]: info: Loading plugin "webradio"... Feb 13 02:08:08 volumio volumio[2672]: info: Loading plugin "i2s_dacs"... Feb 13 02:08:08 volumio volumio[2672]: info: Loading plugin "volumiodiscovery"... Feb 13 02:08:08 volumio volumio[2672]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 13 02:08:08 volumio volumio[2672]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 13 02:08:08 volumio node[2672]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 13 02:08:08 volumio volumio[2672]: *** WARNING *** For more information see Feb 13 02:08:08 volumio volumio[2672]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 13 02:08:08 volumio volumio[2672]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 13 02:08:08 volumio volumio[2672]: *** WARNING *** For more information see Feb 13 02:08:08 volumio node[2672]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 13 02:08:08 volumio node[2672]: *** WARNING *** For more information see Feb 13 02:08:08 volumio node[2672]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 13 02:08:08 volumio node[2672]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 13 02:08:08 volumio node[2672]: *** WARNING *** For more information see Feb 13 02:08:08 volumio volumio[2672]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 13 02:08:08 volumio volumio[2672]: info: Discovery: Started advertising with name: Volumio Feb 13 02:08:08 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 13 02:08:08 volumio volumio[2672]: info: Loading plugin "spop"... Feb 13 02:08:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 13 02:08:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:09 volumio go-librespot[2753]: go-librespot daemon starting... Feb 13 02:08:09 volumio go-librespot[2754]: time="2026-02-13T02:08:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:08:09 volumio go-librespot[2754]: time="2026-02-13T02:08:09+07:00" level=debug msg="app state loaded" Feb 13 02:08:09 volumio go-librespot[2754]: time="2026-02-13T02:08:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:08:10 volumio go-librespot[2754]: time="2026-02-13T02:08:10+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 13 02:08:10 volumio go-librespot[2754]: time="2026-02-13T02:08:10+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 13 02:08:10 volumio go-librespot[2754]: time="2026-02-13T02:08:10+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 13 02:08:10 volumio go-librespot[2754]: time="2026-02-13T02:08:10+07:00" level=info msg="zeroconf server listening on port 39721" Feb 13 02:08:10 volumio go-librespot[2754]: time="2026-02-13T02:08:10+07:00" level=debug msg="obtained new client token: AAClDg0bXvZoqIFdkWahd5N06gYJ6bRE9HJFrlH38Ac7S7CClPBBdEhTFokYenSnzOkgktzrZN5Mzs/G/PARmac1f4bPHm39yVXA6E+29JDIIvE9xw2PgL7wl7UUKbd8b33D34Ghzqk/iezCybkEXwse4bkXpGxEJxO1w1J9B7qEEQhepGSeLGXgJjn7SUxCdeSaBIMj5otK/MKS2G1kb0d9R22vzQmfTRy5SJ1uqH7tFhWc3iZBJcJyMw==" Feb 13 02:08:10 volumio go-librespot[2754]: time="2026-02-13T02:08:10+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 13 02:08:10 volumio go-librespot[2754]: time="2026-02-13T02:08:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 13 02:08:10 volumio volumio[2672]: info: Loading plugin "ytcr"... Feb 13 02:08:10 volumio go-librespot[2754]: time="2026-02-13T02:08:10+07:00" level=debug msg="completed keyexchange" Feb 13 02:08:10 volumio go-librespot[2754]: time="2026-02-13T02:08:10+07:00" level=debug msg="completed challenge" Feb 13 02:08:10 volumio go-librespot[2754]: time="2026-02-13T02:08:10+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 13 02:08:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:08:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:08:13 volumio volumio[2672]: info: Loading plugin "ytmusic"... Feb 13 02:08:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 13 02:08:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:14 volumio go-librespot[2762]: go-librespot daemon starting... Feb 13 02:08:14 volumio go-librespot[2763]: time="2026-02-13T02:08:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:08:14 volumio go-librespot[2763]: time="2026-02-13T02:08:14+07:00" level=debug msg="app state loaded" Feb 13 02:08:14 volumio go-librespot[2763]: time="2026-02-13T02:08:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:08:14 volumio volumio-remote-updater[643]: [2026-02-13 02:08:14] [connect] Successful connection Feb 13 02:08:14 volumio volumio[2672]: info: Loading plugin "outputs"... Feb 13 02:08:14 volumio volumio[2672]: info: Loading plugin "albumart"... Feb 13 02:08:14 volumio volumio[2672]: info: Plugin example_plugin is not enabled Feb 13 02:08:14 volumio volumio[2672]: info: Loading plugin "inputs"... Feb 13 02:08:14 volumio volumio[2672]: info: Loading plugin "updater_comm"... Feb 13 02:08:14 volumio volumio[2672]: info: Plugin mpdemulation is not enabled Feb 13 02:08:14 volumio volumio[2672]: info: Loading plugin "rest_api"... Feb 13 02:08:14 volumio volumio[2672]: info: Loading plugin "websocket"... Feb 13 02:08:14 volumio go-librespot[2763]: time="2026-02-13T02:08:14+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 13 02:08:14 volumio go-librespot[2763]: time="2026-02-13T02:08:14+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 13 02:08:14 volumio go-librespot[2763]: time="2026-02-13T02:08:14+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 13 02:08:14 volumio volumio[2672]: info: Starting Socket.io Server version 1.7.4 Feb 13 02:08:14 volumio go-librespot[2763]: time="2026-02-13T02:08:14+07:00" level=info msg="zeroconf server listening on port 34521" Feb 13 02:08:14 volumio volumio[2672]: info: Loading plugin "RoonBridge"... Feb 13 02:08:14 volumio go-librespot[2763]: time="2026-02-13T02:08:14+07:00" level=debug msg="obtained new client token: AACS2cEdqNyJwRNyOsKJufu98p6WdufGksJLjSHFx8j0Q8y83yab8NQ4jLLNVVG/tzcLrlm0qxLeFl/K5+GHGGy3zmVeOcfWjyawI21UwRh6241NVzpVg4lJ7KTq5tpM/wqUlQhG1G4csjI8OQM00ggTqnUrhmvAWJOCblQVrg2vKvxLzcYMk5fIzE7eaV+7lde6agM73V/uM9FukD8j+sjGdWorQE4n7Rk+sXsHGbXUFANGTTH6gMBDug==" Feb 13 02:08:15 volumio go-librespot[2763]: time="2026-02-13T02:08:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 02:08:15 volumio go-librespot[2763]: time="2026-02-13T02:08:15+07:00" level=debug msg="completed keyexchange" Feb 13 02:08:15 volumio go-librespot[2763]: time="2026-02-13T02:08:15+07:00" level=debug msg="completed challenge" Feb 13 02:08:15 volumio go-librespot[2763]: time="2026-02-13T02:08:15+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 13 02:08:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:08:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:08:15 volumio volumio[2672]: info: Applying required configuration parameters for plugin RoonBridge Feb 13 02:08:15 volumio volumio[2672]: info: Loading i18n strings for locale en Feb 13 02:08:15 volumio volumio[2672]: Updating browse sources language Feb 13 02:08:15 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 02:08:15 volumio volumio[2784]: Forking 3 albumart workers Feb 13 02:08:15 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 13 02:08:15 volumio volumio[2672]: info: CoreCommandRouter::initPlayerControls Feb 13 02:08:15 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:15 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:15 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:15 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:15 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:15 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:15 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:15 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:15 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 13 02:08:15 volumio volumio[2672]: Express server listening on port 3000 Feb 13 02:08:15 volumio volumio[2672]: [Metrics] WebUI: 16s 54.36ms Feb 13 02:08:15 volumio volumio[2672]: info: CoreStateMachine::resetVolumioState Feb 13 02:08:15 volumio volumio[2672]: info: CoreStateMachine::getcurrentVolume Feb 13 02:08:15 volumio volumio[2672]: info: CoreCommandRouter::volumioRetrievevolume Feb 13 02:08:15 volumio sudo[2828]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 13 02:08:15 volumio sudo[2828]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:15 volumio sudo[2831]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 13 02:08:15 volumio sudo[2831]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:16 volumio sudo[2828]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:16 volumio sudo[2831]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:16 volumio volumio[2672]: info: Volumio Network Manager: Network status updated: 1 Feb 13 02:08:16 volumio volumio[2672]: info: VolumeController:: Volume=100 Mute =false Feb 13 02:08:16 volumio volumio[2672]: info: CoreStateMachine::pushState Feb 13 02:08:16 volumio volumio[2672]: info: CorePlayQueue::getTrack 0 Feb 13 02:08:16 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 13 02:08:16 volumio volumio[2672]: info: CoreCommandRouter::volumioPushState Feb 13 02:08:16 volumio volumio[2672]: info: CoreStateMachine::updateTrackBlock Feb 13 02:08:16 volumio volumio[2672]: info: CorePlayQueue::getTrackBlock Feb 13 02:08:16 volumio volumio[2672]: info: CoreCommandRouter::volumioRetrievevolume Feb 13 02:08:16 volumio volumio-remote-updater[643]: [2026-02-13 02:08:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770923294 101 Feb 13 02:08:16 volumio volumio[2672]: 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 13 02:08:16 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 02:08:16 volumio volumio[2672]: info: Reloading queue from file Feb 13 02:08:16 volumio volumio[2672]: info: CoreStateMachine::setRepeat null single undefined Feb 13 02:08:16 volumio volumio[2672]: info: CoreStateMachine::pushState Feb 13 02:08:16 volumio volumio[2672]: info: CorePlayQueue::getTrack 0 Feb 13 02:08:16 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 13 02:08:16 volumio volumio[2672]: info: CoreCommandRouter::volumioPushState Feb 13 02:08:16 volumio volumio[2672]: info: CoreStateMachine::setRandom null Feb 13 02:08:16 volumio volumio[2672]: info: CoreStateMachine::pushState Feb 13 02:08:16 volumio volumio[2672]: info: CorePlayQueue::getTrack 0 Feb 13 02:08:16 volumio volumio[2672]: info: CoreCommandRouter::volumioPushState Feb 13 02:08:16 volumio volumio[2672]: info: Setting Device type: Raspberry PI Feb 13 02:08:16 volumio volumio[2672]: info: Completed loading Core Plugins Feb 13 02:08:16 volumio volumio[2672]: info: Preparing to generate the ALSA configuration file Feb 13 02:08:16 volumio volumio[2672]: info: VolumeController:: Volume=100 Mute =false Feb 13 02:08:16 volumio volumio[2672]: info: CoreStateMachine::pushState Feb 13 02:08:16 volumio volumio[2672]: info: CorePlayQueue::getTrack 0 Feb 13 02:08:16 volumio volumio[2672]: info: CoreCommandRouter::volumioPushState Feb 13 02:08:16 volumio volumio[2672]: info: Asound.conf file unchanged, so no further update is needed Feb 13 02:08:16 volumio volumio[2672]: info: Output device has changed, restarting MPD Feb 13 02:08:16 volumio sudo[2845]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 13 02:08:16 volumio volumio[2672]: info: Output device has changed, restarting Shairport Sync Feb 13 02:08:16 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:16 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 02:08:16 volumio sudo[2845]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:17 volumio sudo[2847]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 13 02:08:17 volumio sudo[2847]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:17 volumio sudo[2847]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:17 volumio volumio[2672]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 13 02:08:17 volumio volumio[2672]: info: ___________ START PLUGINS ___________ Feb 13 02:08:17 volumio sudo[2849]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 13 02:08:17 volumio sudo[2849]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:17 volumio volumio[2672]: info: ControllerMpd::onStart: Initializing MPD Feb 13 02:08:17 volumio volumio[2672]: info: Creating MPD Configuration file Feb 13 02:08:17 volumio sudo[2845]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:17 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 13 02:08:17 volumio sudo[2858]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 13 02:08:17 volumio sudo[2858]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:17 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 13 02:08:17 volumio volumio[2672]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 02:08:17 volumio volumio[2672]: info: [1770923297202] CoreMusicLibrary::Adding element Media Servers Feb 13 02:08:17 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 02:08:17 volumio sudo[2858]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:17 volumio sudo[2860]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 13 02:08:17 volumio sudo[2860]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:17 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 13 02:08:17 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 13 02:08:17 volumio systemd[1]: mpd.service: Consumed 7.133s CPU time. Feb 13 02:08:17 volumio volumio[2672]: info: UPNP Browser: Client initialized successfully Feb 13 02:08:17 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 13 02:08:17 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 13 02:08:17 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 13 02:08:17 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:17 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 02:08:17 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 13 02:08:17 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 13 02:08:17 volumio volumio[2672]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 13 02:08:17 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:17 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 02:08:17 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 13 02:08:17 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 13 02:08:17 volumio volumio[2672]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 13 02:08:17 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 13 02:08:17 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 13 02:08:17 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 13 02:08:17 volumio volumio[2672]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 02:08:17 volumio volumio[2672]: info: [1770923297527] CoreMusicLibrary::Adding element Last_100 Feb 13 02:08:17 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 13 02:08:17 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 02:08:17 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 13 02:08:17 volumio volumio[2672]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 02:08:17 volumio volumio[2672]: info: [1770923297570] CoreMusicLibrary::Adding element Webradio Feb 13 02:08:17 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 02:08:17 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 13 02:08:17 volumio volumio[2672]: info: Initializing BBC Radios Feb 13 02:08:17 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 13 02:08:17 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 02:08:17 volumio volumio[2672]: info: Creating Spotify config file Feb 13 02:08:17 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:18 volumio sudo[2874]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 13 02:08:18 volumio sudo[2874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 13 02:08:18 volumio sudo[2874]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 13 02:08:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:18 volumio go-librespot[2890]: go-librespot daemon starting... Feb 13 02:08:18 volumio go-librespot[2891]: time="2026-02-13T02:08:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:08:18 volumio volumio[2672]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 02:08:18 volumio volumio[2672]: info: [1770923298836] CoreMusicLibrary::Adding element YouTube Music Feb 13 02:08:18 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 02:08:18 volumio volumio[2672]: Cannot find translation for source YouTube Music Feb 13 02:08:18 volumio volumio[2672]: info: Volumio Calling Home Feb 13 02:08:18 volumio sudo[2898]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 13 02:08:18 volumio sudo[2898]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:19 volumio sudo[2898]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:19 volumio volumio[2797]: Starting albumart workers Feb 13 02:08:19 volumio volumio[2796]: Starting albumart workers Feb 13 02:08:19 volumio volumio[2795]: Starting albumart workers Feb 13 02:08:19 volumio go-librespot[2891]: time="2026-02-13T02:08:19+07:00" level=info msg="zeroconf server listening on port 34461" Feb 13 02:08:19 volumio volumio[2672]: info: MPD Permissions set Feb 13 02:08:19 volumio volumio[2672]: info: MPD Permissions set Feb 13 02:08:19 volumio volumio[2672]: info: Upmpdcli Daemon Started Feb 13 02:08:19 volumio volumio[2672]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 13 02:08:19 volumio volumio[2672]: info: Discovery: Found device Volumio Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::volumioGetState Feb 13 02:08:19 volumio volumio[2672]: info: CorePlayQueue::getTrack 0 Feb 13 02:08:19 volumio volumio[2672]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 13 02:08:19 volumio volumio[2672]: info: Discovery: Found device Volumio Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::volumioGetState Feb 13 02:08:19 volumio volumio[2672]: info: CorePlayQueue::getTrack 0 Feb 13 02:08:19 volumio volumio[2672]: info: Spotify config file written Feb 13 02:08:19 volumio volumio[2672]: 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 13 02:08:19 volumio volumio[2672]: info: Volumio called home Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:19 volumio sudo[2906]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 13 02:08:19 volumio sudo[2906]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:19 volumio volumio[2672]: info: No need to fix Spotify hosts Feb 13 02:08:20 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 13 02:08:20 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 13 02:08:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:20 volumio go-librespot[2918]: go-librespot daemon starting... Feb 13 02:08:20 volumio sudo[2906]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:20 volumio go-librespot[2919]: time="2026-02-13T02:08:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:08:20 volumio go-librespot[2919]: time="2026-02-13T02:08:20+07:00" level=debug msg="app state loaded" Feb 13 02:08:20 volumio go-librespot[2919]: time="2026-02-13T02:08:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:08:20 volumio go-librespot[2919]: time="2026-02-13T02:08:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 13 02:08:20 volumio go-librespot[2919]: time="2026-02-13T02:08:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 13 02:08:20 volumio go-librespot[2919]: time="2026-02-13T02:08:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 13 02:08:21 volumio go-librespot[2919]: time="2026-02-13T02:08:21+07:00" level=info msg="zeroconf server listening on port 43201" Feb 13 02:08:21 volumio go-librespot[2919]: time="2026-02-13T02:08:21+07:00" level=debug msg="obtained new client token: AADkC3vvWFYy0mICOmqrMwJtekg/fhEhNuFTl0l52klINek1QMQRrjGweYhTlgcWL01jw2SJNcPciJZnxe1KWnTyz236TtFfMQ759BVXMMXSmo2ggfmq+qXEGpX0vIliWqf2qFCP5w1pmr9OpaKTgc31Wa2hmjXDjdz3to/d1c3L63fYG9fWm0Mcl2HvcOi24n8mSVI0HLBY+V1eYvY9ne+cFiL3UFZyEvtm9I1k3l9+1DxnJcZMkOA=" Feb 13 02:08:21 volumio go-librespot[2919]: time="2026-02-13T02:08:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 02:08:21 volumio go-librespot[2919]: time="2026-02-13T02:08:21+07:00" level=debug msg="completed keyexchange" Feb 13 02:08:21 volumio go-librespot[2919]: time="2026-02-13T02:08:21+07:00" level=debug msg="completed challenge" Feb 13 02:08:21 volumio go-librespot[2919]: time="2026-02-13T02:08:21+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 13 02:08:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:08:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:08:21 volumio volumio[2672]: info: Starting Shairport Sync Feb 13 02:08:21 volumio volumio[2672]: info: Starting Shairport Sync Feb 13 02:08:21 volumio volumio[2672]: info: Starting Shairport Sync Feb 13 02:08:21 volumio sudo[2941]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 13 02:08:21 volumio sudo[2941]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:21 volumio sudo[2939]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 13 02:08:21 volumio sudo[2939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:21 volumio volumio[2672]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 13 02:08:21 volumio volumio[2672]: SPOTIFY: BQDrTwbsGqFqjm585YRgFPiiSccuD8mD_iWNwc1FtqPDBy_xup77s4Vvjobm7sR_7Wm8qCCxVxymr3nbI4_9z91sRd1VH9Qziu6K9rgYlPGBvpKnL3A_jyIhRuliv3FlDKRYFxV5X1XvZnE44o0-Ldel0mzIOb1W2m7v8sc0o3qP5bzEqs3puOlly_ckZdqX5IR7QvvasK405V72_KEzA0A2encp98n0IzEzHxfZ9oMIRpGECqoGMWUoL7ho-uFgeOe5_6nGjVYqr-yfyLcwyhANf0Q0Jb4YNG7v_FucNsHpbgZ-fo2PK--- Feb 13 02:08:21 volumio volumio[2672]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 13 02:08:21 volumio volumio[2672]: info: New Spotify access token = BQDrTwbsGqFqjm585YRgFPiiSccuD8mD_iWNwc1FtqPDBy_xup77s4Vvjobm7sR_7Wm8qCCxVxymr3nbI4_9z91sRd1VH9Qziu6K9rgYlPGBvpKnL3A_jyIhRuliv3FlDKRYFxV5X1XvZnE44o0-Ldel0mzIOb1W2m7v8sc0o3qP5bzEqs3puOlly_ckZdqX5IR7QvvasK405V72_KEzA0A2encp98n0IzEzHxfZ9oMIRpGECqoGMWUoL7ho-uFgeOe5_6nGjVYqr-yfyLcwyhANf0Q0Jb4YNG7v_FucNsHpbgZ-fo2PK--- Feb 13 02:08:21 volumio volumio[2672]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 13 02:08:21 volumio sudo[2946]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 13 02:08:21 volumio sudo[2946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:22 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 13 02:08:22 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 13 02:08:22 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 13 02:08:22 volumio systemd[1]: shairport-sync.service: Consumed 2.322s CPU time. Feb 13 02:08:22 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 13 02:08:22 volumio sudo[2946]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:22 volumio sudo[2941]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:22 volumio sudo[2939]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:22 volumio volumio[2672]: info: Shairport-Sync Started Feb 13 02:08:22 volumio volumio[2672]: Error adding Membership: Error: addMembership EINVAL Feb 13 02:08:22 volumio volumio[2672]: info: Shairport-Sync Started Feb 13 02:08:22 volumio volumio[2672]: info: Shairport-Sync Started Feb 13 02:08:22 volumio volumio[2672]: info: CoreCommandRouter::volumioGetState Feb 13 02:08:22 volumio volumio[2672]: info: CorePlayQueue::getTrack 0 Feb 13 02:08:22 volumio volumio[2672]: 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 13 02:08:22 volumio volumio[2672]: info: Spotify Successfully logged in Feb 13 02:08:22 volumio volumio[2672]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 02:08:22 volumio volumio[2672]: info: [1770923302725] CoreMusicLibrary::Adding element Spotify Feb 13 02:08:22 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 02:08:22 volumio volumio[2672]: Cannot find translation for source YouTube Music Feb 13 02:08:22 volumio volumio[2672]: Cannot find translation for source Spotify Feb 13 02:08:23 volumio volumio[2672]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 13 02:08:23 volumio volumio[2672]: info: CoreCommandRouter::volumioRetrievevolume Feb 13 02:08:23 volumio volumio[2672]: info: VolumeController:: Volume=100 Mute =false Feb 13 02:08:23 volumio volumio[2672]: info: CoreCommandRouter::volumioGetState Feb 13 02:08:23 volumio volumio[2672]: info: CorePlayQueue::getTrack 0 Feb 13 02:08:23 volumio volumio[2672]: info: CoreStateMachine::pushState Feb 13 02:08:23 volumio volumio[2672]: info: CorePlayQueue::getTrack 0 Feb 13 02:08:23 volumio volumio[2672]: info: CoreCommandRouter::volumioPushState Feb 13 02:08:24 volumio volumio[2672]: info: go-librespot daemon successfully initialized Feb 13 02:08:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 13 02:08:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:24 volumio go-librespot[2985]: go-librespot daemon starting... Feb 13 02:08:24 volumio go-librespot[2986]: time="2026-02-13T02:08:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:08:24 volumio go-librespot[2986]: time="2026-02-13T02:08:24+07:00" level=debug msg="app state loaded" Feb 13 02:08:24 volumio go-librespot[2986]: time="2026-02-13T02:08:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:08:25 volumio mpd[2889]: 2026-02-13T02:08:25 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 13 02:08:25 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 13 02:08:25 volumio sudo[2860]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:25 volumio sudo[2849]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:25 volumio volumio[2672]: error: MPD error: The expression evaluated to a falsy value: Feb 13 02:08:25 volumio volumio[2672]: assert.ok(self.idling) Feb 13 02:08:25 volumio volumio[2672]: error: The expression evaluated to a falsy value: Feb 13 02:08:25 volumio volumio[2672]: assert.ok(self.idling) Feb 13 02:08:25 volumio volumio[2672]: info: MPD running with PID2889 Feb 13 02:08:25 volumio volumio[2672]: ,establishing connection Feb 13 02:08:25 volumio volumio[2672]: error: updateQueue error: null Feb 13 02:08:25 volumio go-librespot[2986]: time="2026-02-13T02:08: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 13 02:08:25 volumio go-librespot[2986]: time="2026-02-13T02:08: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 13 02:08:25 volumio go-librespot[2986]: time="2026-02-13T02:08: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 13 02:08:25 volumio go-librespot[2986]: time="2026-02-13T02:08:25+07:00" level=info msg="zeroconf server listening on port 44309" Feb 13 02:08:25 volumio volumio[2672]: info: Completed starting Core Plugins Feb 13 02:08:25 volumio volumio[2672]: info: ------------------------------------------- Feb 13 02:08:25 volumio volumio[2672]: info: ----- MyVolumio plugins startup ---- Feb 13 02:08:25 volumio volumio[2672]: info: ------------------------------------------- Feb 13 02:08:25 volumio volumio[2672]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 13 02:08:25 volumio volumio[2672]: error: updateQueue error: null Feb 13 02:08:25 volumio go-librespot[2986]: time="2026-02-13T02:08:25+07:00" level=debug msg="obtained new client token: AACtPQXUhSLfrl8NfpksVyKh9CLvvoPQCDKcn2WgJ6SQcOIpN53GLu6rmP8NjrMSmBvpuEwbLOHqavXMAAUUaruC1dl00L79a7Lga/FhOxSEHUnN7bocB3fyfMxVSCfY0ok5uc1V/I3a0ovpOy6KSLhdoRq/sJEwHKLq+HMkPXyHYU+7SKxfzrA/2fs0XKvVSsYxi/MZxc/ATWKWpj1624sbkPTHqPq7pFdF9iqF8TGCEHhLEyQ2KUrsDA==" Feb 13 02:08:25 volumio go-librespot[2986]: time="2026-02-13T02:08:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 02:08:25 volumio go-librespot[2986]: time="2026-02-13T02:08:25+07:00" level=debug msg="completed keyexchange" Feb 13 02:08:26 volumio go-librespot[2986]: time="2026-02-13T02:08:26+07:00" level=debug msg="completed challenge" Feb 13 02:08:26 volumio go-librespot[2986]: time="2026-02-13T02:08: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 13 02:08:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:08:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:08:27 volumio volumio[2672]: info: Initializing connection to go-librespot Websocket Feb 13 02:08:27 volumio volumio[2672]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 13 02:08:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 13 02:08:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:29 volumio go-librespot[2998]: go-librespot daemon starting... Feb 13 02:08:29 volumio go-librespot[2999]: time="2026-02-13T02:08:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:08:29 volumio go-librespot[2999]: time="2026-02-13T02:08:29+07:00" level=debug msg="app state loaded" Feb 13 02:08:29 volumio go-librespot[2999]: time="2026-02-13T02:08:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:08:29 volumio go-librespot[2999]: time="2026-02-13T02:08:29+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 13 02:08:29 volumio go-librespot[2999]: time="2026-02-13T02:08:29+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 13 02:08:29 volumio go-librespot[2999]: time="2026-02-13T02:08:29+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 13 02:08:29 volumio go-librespot[2999]: time="2026-02-13T02:08:29+07:00" level=info msg="zeroconf server listening on port 36201" Feb 13 02:08:30 volumio go-librespot[2999]: time="2026-02-13T02:08:30+07:00" level=debug msg="obtained new client token: AABHKGTnUnhf6U5pvJVlDlDJTULCImnKrEEia9TmP3p+4+7DABYGtIJI/32b4zv1/d+Ugwl5bfRkCZZKJ/1ui3qiyUtVDiqKCjsVzHJcHNIt0n3EsoZXVmlbtYGXSU/O61LzY37/KLSAJj/+I3nQTM9gCoh+VqKpguUiVxMNxNarPcA72WBxS08y9HvYd2Rt8UXVcyfkhwMkSb80rglZScewB00nfw/ggR2bT1tLW7jsrt4+zqoB8tQ=" Feb 13 02:08:30 volumio go-librespot[2999]: time="2026-02-13T02:08:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 02:08:30 volumio volumio[2672]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 13 02:08:30 volumio go-librespot[2999]: time="2026-02-13T02:08:30+07:00" level=debug msg="completed keyexchange" Feb 13 02:08:30 volumio go-librespot[2999]: time="2026-02-13T02:08:30+07:00" level=debug msg="completed challenge" Feb 13 02:08:30 volumio go-librespot[2999]: time="2026-02-13T02:08: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 13 02:08:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:08:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:08:30 volumio volumio[2672]: info: Initializing connection to go-librespot Websocket Feb 13 02:08:30 volumio volumio[2672]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 13 02:08:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 13 02:08:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:33 volumio go-librespot[3006]: go-librespot daemon starting... Feb 13 02:08:33 volumio go-librespot[3007]: time="2026-02-13T02:08:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:08:33 volumio go-librespot[3007]: time="2026-02-13T02:08:33+07:00" level=debug msg="app state loaded" Feb 13 02:08:33 volumio go-librespot[3007]: time="2026-02-13T02:08:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:08:33 volumio volumio[2672]: info: Initializing connection to go-librespot Websocket Feb 13 02:08:33 volumio go-librespot[3007]: time="2026-02-13T02:08:33+07:00" level=debug msg="new websocket client" Feb 13 02:08:33 volumio volumio[2672]: info: Connection to go-librespot Websocket established Feb 13 02:08:34 volumio go-librespot[3007]: time="2026-02-13T02:08: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 13 02:08:34 volumio go-librespot[3007]: time="2026-02-13T02:08:34+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 13 02:08:34 volumio go-librespot[3007]: time="2026-02-13T02:08:34+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 13 02:08:34 volumio go-librespot[3007]: time="2026-02-13T02:08:34+07:00" level=info msg="zeroconf server listening on port 42595" Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 13 02:08:34 volumio volumio[2672]: info: Adding plugin bluetooth to MyMusic Plugins Feb 13 02:08:34 volumio volumio[2672]: info: Adding plugin multiroom to MyMusic Plugins Feb 13 02:08:34 volumio volumio[2672]: info: Adding plugin metavolumio to MyMusic Plugins Feb 13 02:08:34 volumio volumio[2672]: info: Adding plugin cd_controller to MyMusic Plugins Feb 13 02:08:34 volumio volumio[2672]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 13 02:08:34 volumio volumio[2672]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 13 02:08:34 volumio volumio[2672]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 13 02:08:34 volumio volumio[2672]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 13 02:08:34 volumio go-librespot[3007]: time="2026-02-13T02:08:34+07:00" level=debug msg="obtained new client token: AABe8MANtCcHDpnujcivrbouS/QqAMxX8/qwg5oVPx/JTb8t1Es7PJ5arHRzM3vKJHRmxYzf+W+eo4QLAmmqgjMrvxdaHsFQCDQTE2C93btIrD29LEybxCpExVT6BAQd1PyHDbD3ANaHl/cFcCd6dEH6U3sttpaVxJI9lCPuozPWM7ApBEQ/UfJvXzQ61q8iA5BL+TvoIbUz0HN0/uNphi+OJphp3FYVk480oUECw00uPqeTpYmAxe9aVA==" Feb 13 02:08:34 volumio go-librespot[3007]: time="2026-02-13T02:08:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 02:08:34 volumio go-librespot[3007]: time="2026-02-13T02:08:34+07:00" level=debug msg="completed keyexchange" Feb 13 02:08:34 volumio go-librespot[3007]: time="2026-02-13T02:08:34+07:00" level=debug msg="completed challenge" Feb 13 02:08:34 volumio go-librespot[3007]: time="2026-02-13T02:08:34+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 13 02:08:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:08:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:08:36 volumio volumio[2672]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 13 02:08:36 volumio volumio[2672]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 13 02:08:36 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 02:08:36 volumio volumio[2672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 02:08:36 volumio volumio[2672]: info: Starting MyVolumio Remote Streaming Endpoints Feb 13 02:08:36 volumio volumio[2672]: info: MyVolumio login type: Token Feb 13 02:08:36 volumio volumio[2672]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 13 02:08:36 volumio volumio[2672]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 13 02:08:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 13 02:08:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:37 volumio volumio[2672]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 13 02:08:37 volumio volumio[2672]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 13 02:08:37 volumio volumio[2672]: info: Streaming services startup Feb 13 02:08:37 volumio volumio[2672]: info: Starting Streaming Daemon Feb 13 02:08:37 volumio go-librespot[3028]: go-librespot daemon starting... Feb 13 02:08:37 volumio go-librespot[3029]: time="2026-02-13T02:08:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:08:37 volumio go-librespot[3029]: time="2026-02-13T02:08:37+07:00" level=debug msg="app state loaded" Feb 13 02:08:37 volumio go-librespot[3029]: time="2026-02-13T02:08:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:08:37 volumio sudo[3036]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 13 02:08:37 volumio sudo[3036]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:37 volumio volumio[2672]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 13 02:08:38 volumio sudo[3036]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:38 volumio volumio[2672]: info: Getting Spotify volume Feb 13 02:08:38 volumio volumio[2672]: info: Connection to go-librespot Websocket closed Feb 13 02:08:38 volumio volumio[2672]: error: Cannot start Volumio Streaming Daemon Feb 13 02:08:38 volumio volumio[2672]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 13 02:08:38 volumio volumio[2672]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 13 02:08:38 volumio volumio[2672]: 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 13 02:08:38 volumio volumio[2672]: info: CoreCommandRouter::volumioGetState Feb 13 02:08:38 volumio volumio[2672]: info: CorePlayQueue::getTrack 0 Feb 13 02:08:38 volumio volumio[2672]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 13 02:08:38 volumio volumio[2672]: SPOTIFY: SPOTIFY VOLUME undefined Feb 13 02:08:38 volumio volumio[2672]: SPOTIFY: VOLUMIO VOLUME 100 Feb 13 02:08:38 volumio volumio[2672]: info: Aligning Spotify Volume to Volumio Volume Feb 13 02:08:38 volumio volumio[2672]: info: CoreCommandRouter::volumioGetState Feb 13 02:08:38 volumio volumio[2672]: info: CorePlayQueue::getTrack 0 Feb 13 02:08:38 volumio volumio[2672]: info: Setting Spotify Volume from Volumio: 100 Feb 13 02:08:38 volumio go-librespot[3029]: time="2026-02-13T02:08:38+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 13 02:08:38 volumio go-librespot[3029]: time="2026-02-13T02:08:38+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 13 02:08:38 volumio go-librespot[3029]: time="2026-02-13T02:08:38+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 13 02:08:38 volumio go-librespot[3029]: time="2026-02-13T02:08:38+07:00" level=info msg="zeroconf server listening on port 39619" Feb 13 02:08:38 volumio go-librespot[3029]: time="2026-02-13T02:08:38+07:00" level=debug msg="obtained new client token: AABEEbvoCJ+uOyqT5VVST6PLD+AMXSo0zYyLb64ctsNBam3FOfVHrnw3+E5+kA/MxLmHUMS737tts57+UFtlHTOkrWNonw1SAQ4zepQKFglVuZi+F0vK8bLo9A63UQfWxE0gnsRQIB77TxQoc3gowBer3Nl15fHeato4gToMNUcyL3y87NVFBahKEvFpHbhk+k3cK1wE/8tfOSbHbm8srJIB/b3sOZ+o+f2JJzs8cEJfV8RyFQp7ySSwSA==" Feb 13 02:08:38 volumio go-librespot[3029]: time="2026-02-13T02:08:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 02:08:38 volumio go-librespot[3029]: time="2026-02-13T02:08:38+07:00" level=debug msg="completed keyexchange" Feb 13 02:08:38 volumio go-librespot[3029]: time="2026-02-13T02:08:38+07:00" level=debug msg="completed challenge" Feb 13 02:08:39 volumio go-librespot[3029]: time="2026-02-13T02:08: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 13 02:08:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:08:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:08:39 volumio volumio[2672]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 13 02:08:39 volumio volumio[2672]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 13 02:08:39 volumio volumio[2672]: Error: socket hang up Feb 13 02:08:39 volumio volumio[2672]: at connResetException (node:internal/errors:720:14) Feb 13 02:08:39 volumio volumio[2672]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 13 02:08:39 volumio volumio[2672]: at Socket.emit (node:events:526:35) Feb 13 02:08:39 volumio volumio[2672]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 13 02:08:39 volumio volumio[2672]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 13 02:08:39 volumio volumio[2672]: code: 'ECONNRESET', Feb 13 02:08:39 volumio volumio[2672]: response: undefined Feb 13 02:08:39 volumio volumio[2672]: } Feb 13 02:08:39 volumio volumio[2672]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 13 02:08:40 volumio sudo[3059]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-13 02:07' Feb 13 02:08:40 volumio sudo[3059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:40 volumio sudo[3059]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:41 volumio volumio-remote-updater[643]: [2026-02-13 02:08:41] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 13 02:08:41 volumio volumio-remote-updater[643]: [2026-02-13 02:08:41] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 13 02:08:41 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:08:41 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 13 02:08:41 volumio systemd[1]: volumio.service: Consumed 55.777s CPU time. Feb 13 02:08:41 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 13 02:08:41 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 13 02:08:41 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 14100. Feb 13 02:08:41 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 13 02:08:41 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 13 02:08:41 volumio systemd[1]: volumio.service: Consumed 55.777s CPU time. Feb 13 02:08:41 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 13 02:08:41 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 13 02:08:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 13 02:08:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:42 volumio go-librespot[3089]: go-librespot daemon starting... Feb 13 02:08:42 volumio go-librespot[3090]: time="2026-02-13T02:08:42+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:08:42 volumio go-librespot[3090]: time="2026-02-13T02:08:42+07:00" level=debug msg="app state loaded" Feb 13 02:08:42 volumio go-librespot[3090]: time="2026-02-13T02:08:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:08:42 volumio go-librespot[3090]: time="2026-02-13T02:08:42+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 13 02:08:42 volumio go-librespot[3090]: time="2026-02-13T02:08:42+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 13 02:08:42 volumio go-librespot[3090]: time="2026-02-13T02:08:42+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 13 02:08:42 volumio go-librespot[3090]: time="2026-02-13T02:08:42+07:00" level=info msg="zeroconf server listening on port 41357" Feb 13 02:08:42 volumio go-librespot[3090]: time="2026-02-13T02:08:42+07:00" level=debug msg="obtained new client token: AADlk+BavttF1GTLRAojRL1jJM5WegV8BSaEgArrk2+9QjUwYQgaQ6x21ONn3Rz7BLFduBSEVBdHINrg0HxqlCo/QZyqusv5GHBMnVb2UCpJEDXcYtHUxuzcmy4CNYKFEQyt8BfWPxzcwP1L5tg697MQsWLkRIgKkT0mVnbcWADLnHSEGrzcoilfqSmbdIoG/v+U6xVxGaM65CHQzl010iHxYqQ3xrHTckYbSfkaGKXIJxHerVhcldLfow==" Feb 13 02:08:43 volumio go-librespot[3090]: time="2026-02-13T02:08:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 02:08:43 volumio go-librespot[3090]: time="2026-02-13T02:08:43+07:00" level=debug msg="completed keyexchange" Feb 13 02:08:43 volumio go-librespot[3090]: time="2026-02-13T02:08:43+07:00" level=debug msg="completed challenge" Feb 13 02:08:43 volumio go-librespot[3090]: time="2026-02-13T02:08:43+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 13 02:08:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:08:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:08:44 volumio volumio[3074]: info: ------------------------------------------- Feb 13 02:08:44 volumio volumio[3074]: info: ----- Volumio3 ---- Feb 13 02:08:44 volumio volumio[3074]: info: ------------------------------------------- Feb 13 02:08:44 volumio volumio[3074]: info: ----- System startup ---- Feb 13 02:08:44 volumio volumio[3074]: info: ------------------------------------------- Feb 13 02:08:46 volumio volumio-remote-updater[643]: [2026-02-13 02:08:46] [connect] Successful connection Feb 13 02:08:46 volumio volumio[3074]: info: MYVOLUMIO Environment detected Feb 13 02:08:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 13 02:08:46 volumio volumio[3074]: info: Plugin folders cleanup Feb 13 02:08:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:46 volumio volumio[3074]: info: Scanning into folder /volumio/app/plugins/ Feb 13 02:08:46 volumio volumio[3074]: info: Scanning category audio_interface Feb 13 02:08:46 volumio volumio[3074]: info: Scanning category miscellanea Feb 13 02:08:46 volumio volumio[3074]: info: Scanning category music_service Feb 13 02:08:46 volumio volumio[3074]: info: Scanning category plugins.json Feb 13 02:08:46 volumio volumio[3074]: info: Scanning category system_controller Feb 13 02:08:46 volumio volumio[3074]: info: Scanning category user_interface Feb 13 02:08:46 volumio volumio[3074]: info: Scanning into folder /data/plugins/ Feb 13 02:08:46 volumio volumio[3074]: info: Scanning category music_service Feb 13 02:08:46 volumio volumio[3074]: info: Plugin folders cleanup completed Feb 13 02:08:46 volumio volumio[3074]: info: ------------------------------------------- Feb 13 02:08:46 volumio volumio[3074]: info: ----- Core plugins startup ---- Feb 13 02:08:46 volumio volumio[3074]: info: ------------------------------------------- Feb 13 02:08:46 volumio volumio[3074]: info: Loading plugins from folder /volumio/app/plugins/ Feb 13 02:08:46 volumio volumio[3074]: info: Adding plugin upnp to MyMusic Plugins Feb 13 02:08:46 volumio volumio[3074]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 13 02:08:46 volumio volumio[3074]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 13 02:08:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:46 volumio volumio[3074]: info: Loading plugins from folder /data/plugins/ Feb 13 02:08:46 volumio go-librespot[3108]: go-librespot daemon starting... Feb 13 02:08:46 volumio volumio[3074]: info: Loading plugin "system"... Feb 13 02:08:46 volumio go-librespot[3109]: time="2026-02-13T02:08:46+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:08:46 volumio go-librespot[3109]: time="2026-02-13T02:08:46+07:00" level=debug msg="app state loaded" Feb 13 02:08:46 volumio go-librespot[3109]: time="2026-02-13T02:08:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:08:46 volumio volumio[3074]: info: Loading plugin "appearance"... Feb 13 02:08:46 volumio go-librespot[3109]: time="2026-02-13T02:08:46+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 13 02:08:46 volumio go-librespot[3109]: time="2026-02-13T02:08:46+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 13 02:08:46 volumio go-librespot[3109]: time="2026-02-13T02:08:46+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 13 02:08:46 volumio go-librespot[3109]: time="2026-02-13T02:08:46+07:00" level=info msg="zeroconf server listening on port 42273" Feb 13 02:08:47 volumio go-librespot[3109]: time="2026-02-13T02:08:47+07:00" level=debug msg="obtained new client token: AABG0QT5ZnagQnyWScllzSqA5sBa8zwQi1xvwsL21ENpa1k64IqCIwCyEy1GliIgNGp6SCnAxWmK84fvMBBAgJyIfSEa5ykk/NlZ26T5bQtQysxnseoD1Qq99iahczWLdza2l0MfraaXDEGd2T03qN+ekacFoDG7WZXJfh3RERoNaX9u5YxcRELrJlLoiGde5EISRVhXJZGOZbRqvm5an8zU14rJS8vbd7MiJn5YZNQaKvJBNF92cY0=" Feb 13 02:08:47 volumio go-librespot[3109]: time="2026-02-13T02:08:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 02:08:47 volumio go-librespot[3109]: time="2026-02-13T02:08:47+07:00" level=debug msg="completed keyexchange" Feb 13 02:08:47 volumio go-librespot[3109]: time="2026-02-13T02:08:47+07:00" level=debug msg="completed challenge" Feb 13 02:08:47 volumio go-librespot[3109]: time="2026-02-13T02:08:47+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 13 02:08:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:08:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:08:48 volumio volumio[3074]: info: Loading plugin "network"... Feb 13 02:08:48 volumio volumio[3074]: info: Refreshing Cached IP Addresses Feb 13 02:08:48 volumio sudo[3120]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 13 02:08:48 volumio sudo[3120]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:48 volumio volumio[3074]: info: Loading plugin "services"... Feb 13 02:08:48 volumio sudo[3122]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 13 02:08:48 volumio sudo[3122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:48 volumio volumio[3074]: info: Loading plugin "alsa_controller"... Feb 13 02:08:48 volumio sudo[3120]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:48 volumio sudo[3122]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:48 volumio sudo[3129]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 13 02:08:48 volumio sudo[3129]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:08:48 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 13 02:08:48 volumio volumio[3074]: info: Loading plugin "wizard"... Feb 13 02:08:48 volumio volumio[3074]: info: Loading plugin "networkfs"... Feb 13 02:08:48 volumio volumio[3074]: info: Starting Udev Watcher for removable devices Feb 13 02:08:48 volumio volumio[3074]: info: Ignoring mount for partition: boot Feb 13 02:08:48 volumio volumio[3074]: info: Ignoring mount for partition: volumio Feb 13 02:08:48 volumio volumio[3074]: info: Ignoring mount for partition: volumio_data Feb 13 02:08:48 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 13 02:08:48 volumio volumio[3074]: info: Loading plugin "volumio_command_line_client"... Feb 13 02:08:48 volumio volumio[3074]: info: Loading plugin "upnp"... Feb 13 02:08:48 volumio volumio[3074]: info: [1770923328794] Starting Upmpd Daemon Feb 13 02:08:48 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 13 02:08:48 volumio volumio[3074]: info: Loading plugin "my_music"... Feb 13 02:08:48 volumio volumio[3074]: info: Loading plugin "mpd"... Feb 13 02:08:49 volumio volumio[3074]: info: Loading plugin "upnp_browser"... Feb 13 02:08:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 13 02:08:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:50 volumio go-librespot[3153]: go-librespot daemon starting... Feb 13 02:08:50 volumio go-librespot[3154]: time="2026-02-13T02:08:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:08:50 volumio go-librespot[3154]: time="2026-02-13T02:08:50+07:00" level=debug msg="app state loaded" Feb 13 02:08:50 volumio go-librespot[3154]: time="2026-02-13T02:08:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:08:51 volumio go-librespot[3154]: time="2026-02-13T02:08:51+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 13 02:08:51 volumio go-librespot[3154]: time="2026-02-13T02:08:51+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 13 02:08:51 volumio go-librespot[3154]: time="2026-02-13T02:08:51+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 13 02:08:51 volumio go-librespot[3154]: time="2026-02-13T02:08:51+07:00" level=info msg="zeroconf server listening on port 45341" Feb 13 02:08:51 volumio sudo[3129]: pam_unix(sudo:session): session closed for user root Feb 13 02:08:51 volumio go-librespot[3154]: time="2026-02-13T02:08:51+07:00" level=debug msg="obtained new client token: AAAbC789U2Kinr6yRB0NFXYi0RXqxZ800sHjQG14zkemXfoIcaFcTkKRBoWGKb+FRcdUuXAlxlrsUG9/UyQrnnuAmgYF1oVTjezt8luDkH6VCkTu9O7puGBtScwIIQn8IRdPiXDdmTAQJY/pYo2OFFMCX5sVgbhD/DKidohveoaRZiI+kJNwVlWRKxfznnbS/c8qJ+8Y/tVWW24efcgOeLyH0xrWQfimztT1w1+vWTMA3fXqtC7BDmAa6Q==" Feb 13 02:08:51 volumio go-librespot[3154]: time="2026-02-13T02:08:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 02:08:51 volumio go-librespot[3154]: time="2026-02-13T02:08:51+07:00" level=debug msg="completed keyexchange" Feb 13 02:08:51 volumio go-librespot[3154]: time="2026-02-13T02:08:51+07:00" level=debug msg="completed challenge" Feb 13 02:08:51 volumio go-librespot[3154]: time="2026-02-13T02:08:51+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 13 02:08:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:08:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:08:52 volumio volumio[3074]: info: Starting UPNP Browser Feb 13 02:08:52 volumio volumio[3074]: info: Loading plugin "alarm-clock"... Feb 13 02:08:52 volumio volumio[3074]: info: Loading plugin "airplay_emulation"... Feb 13 02:08:52 volumio volumio[3074]: info: Starting Shairport Sync Feb 13 02:08:52 volumio volumio[3074]: info: Loading plugin "last_100"... Feb 13 02:08:52 volumio volumio[3074]: info: Loading plugin "webradio"... Feb 13 02:08:52 volumio volumio[3074]: info: Loading plugin "i2s_dacs"... Feb 13 02:08:52 volumio volumio[3074]: info: Loading plugin "volumiodiscovery"... Feb 13 02:08:53 volumio volumio[3074]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 13 02:08:53 volumio volumio[3074]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 13 02:08:53 volumio node[3074]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 13 02:08:53 volumio volumio[3074]: *** WARNING *** For more information see Feb 13 02:08:53 volumio volumio[3074]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 13 02:08:53 volumio volumio[3074]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 13 02:08:53 volumio volumio[3074]: *** WARNING *** For more information see Feb 13 02:08:53 volumio node[3074]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 13 02:08:53 volumio node[3074]: *** WARNING *** For more information see Feb 13 02:08:53 volumio node[3074]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 13 02:08:53 volumio node[3074]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 13 02:08:53 volumio node[3074]: *** WARNING *** For more information see Feb 13 02:08:53 volumio volumio[3074]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 13 02:08:53 volumio volumio[3074]: info: Discovery: Started advertising with name: Volumio Feb 13 02:08:53 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 13 02:08:53 volumio volumio[3074]: info: Loading plugin "spop"... Feb 13 02:08:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 13 02:08:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:54 volumio go-librespot[3164]: go-librespot daemon starting... Feb 13 02:08:54 volumio volumio[3074]: info: Loading plugin "ytcr"... Feb 13 02:08:54 volumio go-librespot[3165]: time="2026-02-13T02:08:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:08:55 volumio go-librespot[3165]: time="2026-02-13T02:08:54+07:00" level=debug msg="app state loaded" Feb 13 02:08:55 volumio go-librespot[3165]: time="2026-02-13T02:08:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:08:55 volumio go-librespot[3165]: time="2026-02-13T02:08:55+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 13 02:08:55 volumio go-librespot[3165]: time="2026-02-13T02:08:55+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 13 02:08:55 volumio go-librespot[3165]: time="2026-02-13T02:08:55+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 13 02:08:55 volumio go-librespot[3165]: time="2026-02-13T02:08:55+07:00" level=info msg="zeroconf server listening on port 42881" Feb 13 02:08:55 volumio go-librespot[3165]: time="2026-02-13T02:08:55+07:00" level=debug msg="obtained new client token: AAAuYPRwyxXLypY/t4c8GjX/2v2H60Kv1b1htJYNxNLpO4mgMohRd5VyCFkj2rsGYVsh/YwVJ82yG0/TPY22M/SxLmMBKMImO1spfNwWx9taXtK3eaLFKgcfLaOU6xJ6MMF4JJnToGdR+cNoU9PFrC2LcUFOew77TRtDF7Do42TReeFEasC3Qkrh/3N7TxGAqLGwC4O9kd7EOsFMrsRk+tkkOuPQmIO/TnN68ZDkCQ8JuAYdnP9cNtodDA==" Feb 13 02:08:55 volumio go-librespot[3165]: time="2026-02-13T02:08:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 02:08:56 volumio go-librespot[3165]: time="2026-02-13T02:08:56+07:00" level=debug msg="completed keyexchange" Feb 13 02:08:56 volumio go-librespot[3165]: time="2026-02-13T02:08:56+07:00" level=debug msg="completed challenge" Feb 13 02:08:56 volumio go-librespot[3165]: time="2026-02-13T02:08:56+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 13 02:08:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:08:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:08:57 volumio volumio[3074]: info: Loading plugin "ytmusic"... Feb 13 02:08:58 volumio volumio-remote-updater[643]: [2026-02-13 02:08:58] [connect] Successful connection Feb 13 02:08:58 volumio volumio[3074]: info: Loading plugin "outputs"... Feb 13 02:08:58 volumio volumio[3074]: info: Loading plugin "albumart"... Feb 13 02:08:58 volumio volumio[3074]: info: Plugin example_plugin is not enabled Feb 13 02:08:58 volumio volumio[3074]: info: Loading plugin "inputs"... Feb 13 02:08:58 volumio volumio[3074]: info: Loading plugin "updater_comm"... Feb 13 02:08:58 volumio volumio[3074]: info: Plugin mpdemulation is not enabled Feb 13 02:08:58 volumio volumio[3074]: info: Loading plugin "rest_api"... Feb 13 02:08:58 volumio volumio[3074]: info: Loading plugin "websocket"... Feb 13 02:08:59 volumio volumio[3074]: info: Starting Socket.io Server version 1.7.4 Feb 13 02:08:59 volumio volumio[3074]: info: Loading plugin "RoonBridge"... Feb 13 02:08:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 13 02:08:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:08:59 volumio go-librespot[3197]: go-librespot daemon starting... Feb 13 02:08:59 volumio go-librespot[3198]: time="2026-02-13T02:08:59+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:08:59 volumio go-librespot[3198]: time="2026-02-13T02:08:59+07:00" level=debug msg="app state loaded" Feb 13 02:08:59 volumio go-librespot[3198]: time="2026-02-13T02:08:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:08:59 volumio volumio[3074]: info: Applying required configuration parameters for plugin RoonBridge Feb 13 02:08:59 volumio volumio[3074]: info: Loading i18n strings for locale en Feb 13 02:08:59 volumio volumio[3074]: Updating browse sources language Feb 13 02:08:59 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 02:08:59 volumio volumio[3187]: Forking 3 albumart workers Feb 13 02:08:59 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 13 02:08:59 volumio volumio[3074]: info: CoreCommandRouter::initPlayerControls Feb 13 02:08:59 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:59 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:59 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:59 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:59 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:59 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:59 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:59 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:08:59 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 13 02:08:59 volumio volumio[3074]: Express server listening on port 3000 Feb 13 02:08:59 volumio volumio[3074]: [Metrics] WebUI: 16s 7.70ms Feb 13 02:08:59 volumio volumio[3074]: info: CoreStateMachine::resetVolumioState Feb 13 02:08:59 volumio volumio[3074]: info: CoreStateMachine::getcurrentVolume Feb 13 02:08:59 volumio volumio[3074]: info: CoreCommandRouter::volumioRetrievevolume Feb 13 02:09:00 volumio go-librespot[3198]: time="2026-02-13T02:09: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 13 02:09:00 volumio go-librespot[3198]: time="2026-02-13T02:09:00+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 13 02:09:00 volumio go-librespot[3198]: time="2026-02-13T02:09:00+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 13 02:09:00 volumio go-librespot[3198]: time="2026-02-13T02:09:00+07:00" level=info msg="zeroconf server listening on port 45331" Feb 13 02:09:00 volumio sudo[3238]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 13 02:09:00 volumio sudo[3238]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:09:00 volumio sudo[3240]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 13 02:09:00 volumio sudo[3240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:09:00 volumio sudo[3238]: pam_unix(sudo:session): session closed for user root Feb 13 02:09:00 volumio sudo[3240]: pam_unix(sudo:session): session closed for user root Feb 13 02:09:00 volumio volumio[3074]: info: Volumio Network Manager: Network status updated: 1 Feb 13 02:09:00 volumio go-librespot[3198]: time="2026-02-13T02:09:00+07:00" level=debug msg="obtained new client token: AACtk/EN9kzivwDhbbdBui2ZovQ0uRLXUNBmepyek+wb41eFQkbue8BtCkt2GhzMUvplN//VfV+sWeVIuicf69geoRN5Eew/CTAk6HA1vJgOZj5br1dgaBOU5qf0BHTTKNmIjDdETWLwCt9uiii9HXfCbmCe5y1Oj6lQFFgm7UEbjwPP+p6O5jpKzDj840KnwxdSMUxK1NGdW5zBsjZ02QcODX3U94PlQMPWEbOuGKNVjJkH3HTc7ch7Cg==" Feb 13 02:09:00 volumio go-librespot[3198]: time="2026-02-13T02:09:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 02:09:00 volumio go-librespot[3198]: time="2026-02-13T02:09:00+07:00" level=debug msg="completed keyexchange" Feb 13 02:09:00 volumio go-librespot[3198]: time="2026-02-13T02:09:00+07:00" level=debug msg="completed challenge" Feb 13 02:09:00 volumio volumio[3074]: info: VolumeController:: Volume=100 Mute =false Feb 13 02:09:00 volumio go-librespot[3198]: time="2026-02-13T02:09: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 13 02:09:00 volumio volumio[3074]: info: CoreStateMachine::pushState Feb 13 02:09:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:09:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:09:00 volumio volumio[3074]: info: CorePlayQueue::getTrack 0 Feb 13 02:09:00 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 13 02:09:00 volumio volumio[3074]: info: CoreCommandRouter::volumioPushState Feb 13 02:09:00 volumio volumio[3074]: info: CoreStateMachine::updateTrackBlock Feb 13 02:09:00 volumio volumio[3074]: info: CorePlayQueue::getTrackBlock Feb 13 02:09:00 volumio volumio[3074]: info: CoreCommandRouter::volumioRetrievevolume Feb 13 02:09:00 volumio volumio-remote-updater[643]: [2026-02-13 02:09:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770923338 101 Feb 13 02:09:00 volumio volumio[3074]: 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 13 02:09:00 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 02:09:00 volumio volumio[3074]: info: Reloading queue from file Feb 13 02:09:00 volumio volumio[3074]: info: CoreStateMachine::setRepeat null single undefined Feb 13 02:09:00 volumio volumio[3074]: info: CoreStateMachine::pushState Feb 13 02:09:00 volumio volumio[3074]: info: CorePlayQueue::getTrack 0 Feb 13 02:09:00 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 13 02:09:00 volumio volumio[3074]: info: CoreCommandRouter::volumioPushState Feb 13 02:09:00 volumio volumio[3074]: info: CoreStateMachine::setRandom null Feb 13 02:09:00 volumio volumio[3074]: info: CoreStateMachine::pushState Feb 13 02:09:00 volumio volumio[3074]: info: CorePlayQueue::getTrack 0 Feb 13 02:09:00 volumio volumio[3074]: info: CoreCommandRouter::volumioPushState Feb 13 02:09:00 volumio volumio[3074]: info: Setting Device type: Raspberry PI Feb 13 02:09:01 volumio volumio[3074]: info: Completed loading Core Plugins Feb 13 02:09:01 volumio volumio[3074]: info: Preparing to generate the ALSA configuration file Feb 13 02:09:01 volumio volumio[3074]: info: VolumeController:: Volume=100 Mute =false Feb 13 02:09:01 volumio volumio[3074]: info: CoreStateMachine::pushState Feb 13 02:09:01 volumio volumio[3074]: info: CorePlayQueue::getTrack 0 Feb 13 02:09:01 volumio volumio[3074]: info: CoreCommandRouter::volumioPushState Feb 13 02:09:01 volumio volumio[3074]: info: Asound.conf file unchanged, so no further update is needed Feb 13 02:09:01 volumio volumio[3074]: info: Output device has changed, restarting MPD Feb 13 02:09:01 volumio sudo[3257]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 13 02:09:01 volumio sudo[3257]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:09:01 volumio volumio[3074]: info: Output device has changed, restarting Shairport Sync Feb 13 02:09:01 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:01 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 02:09:01 volumio sudo[3259]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 13 02:09:01 volumio sudo[3259]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:09:01 volumio sudo[3259]: pam_unix(sudo:session): session closed for user root Feb 13 02:09:01 volumio sudo[3262]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 13 02:09:01 volumio sudo[3262]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:09:01 volumio sudo[3257]: pam_unix(sudo:session): session closed for user root Feb 13 02:09:01 volumio volumio[3074]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 13 02:09:01 volumio volumio[3074]: info: ___________ START PLUGINS ___________ Feb 13 02:09:01 volumio volumio[3074]: info: ControllerMpd::onStart: Initializing MPD Feb 13 02:09:01 volumio volumio[3074]: info: Creating MPD Configuration file Feb 13 02:09:01 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 13 02:09:01 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 13 02:09:01 volumio volumio[3074]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 02:09:01 volumio volumio[3074]: info: [1770923341572] CoreMusicLibrary::Adding element Media Servers Feb 13 02:09:01 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 02:09:01 volumio sudo[3270]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 13 02:09:01 volumio sudo[3270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:09:01 volumio sudo[3272]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 13 02:09:01 volumio sudo[3272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:09:01 volumio sudo[3270]: pam_unix(sudo:session): session closed for user root Feb 13 02:09:01 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 13 02:09:01 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 13 02:09:01 volumio systemd[1]: mpd.service: Consumed 7.217s CPU time. Feb 13 02:09:01 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 13 02:09:01 volumio volumio[3074]: info: UPNP Browser: Client initialized successfully Feb 13 02:09:01 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 13 02:09:01 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 13 02:09:01 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:01 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 02:09:01 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 13 02:09:01 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 13 02:09:01 volumio volumio[3074]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 13 02:09:01 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:01 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 02:09:01 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 13 02:09:01 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 13 02:09:01 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 13 02:09:01 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 13 02:09:01 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 13 02:09:01 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 13 02:09:01 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 13 02:09:01 volumio volumio[3074]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 13 02:09:01 volumio volumio[3074]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 02:09:01 volumio volumio[3074]: info: [1770923341989] CoreMusicLibrary::Adding element Last_100 Feb 13 02:09:01 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 02:09:01 volumio volumio[3074]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 02:09:02 volumio volumio[3074]: info: [1770923342000] CoreMusicLibrary::Adding element Webradio Feb 13 02:09:02 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 02:09:02 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 13 02:09:02 volumio volumio[3074]: info: Initializing BBC Radios Feb 13 02:09:02 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 13 02:09:02 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 02:09:02 volumio volumio[3074]: info: Creating Spotify config file Feb 13 02:09:02 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:02 volumio sudo[3286]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 13 02:09:02 volumio sudo[3286]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 13 02:09:02 volumio sudo[3286]: pam_unix(sudo:session): session closed for user root Feb 13 02:09:03 volumio volumio[3206]: Starting albumart workers Feb 13 02:09:03 volumio volumio[3074]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 02:09:03 volumio volumio[3074]: info: [1770923343152] CoreMusicLibrary::Adding element YouTube Music Feb 13 02:09:03 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 02:09:03 volumio volumio[3074]: Cannot find translation for source YouTube Music Feb 13 02:09:03 volumio volumio[3074]: info: Volumio Calling Home Feb 13 02:09:03 volumio volumio[3208]: Starting albumart workers Feb 13 02:09:03 volumio sudo[3303]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 13 02:09:03 volumio sudo[3303]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:09:03 volumio sudo[3303]: pam_unix(sudo:session): session closed for user root Feb 13 02:09:03 volumio volumio[3207]: Starting albumart workers Feb 13 02:09:03 volumio volumio[3074]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 13 02:09:03 volumio volumio[3074]: info: Discovery: Found device Volumio Feb 13 02:09:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 13 02:09:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:09:03 volumio volumio[3074]: info: CoreCommandRouter::volumioGetState Feb 13 02:09:03 volumio volumio[3074]: info: CorePlayQueue::getTrack 0 Feb 13 02:09:03 volumio volumio[3074]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 13 02:09:03 volumio volumio[3074]: info: Discovery: Found device Volumio Feb 13 02:09:03 volumio volumio[3074]: info: CoreCommandRouter::volumioGetState Feb 13 02:09:03 volumio volumio[3074]: info: CorePlayQueue::getTrack 0 Feb 13 02:09:03 volumio go-librespot[3310]: go-librespot daemon starting... Feb 13 02:09:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:09:04 volumio go-librespot[3311]: time="2026-02-13T02:09:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:09:04 volumio go-librespot[3311]: time="2026-02-13T02:09:04+07:00" level=debug msg="app state loaded" Feb 13 02:09:04 volumio go-librespot[3311]: time="2026-02-13T02:09:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:09:04 volumio volumio[3074]: info: MPD Permissions set Feb 13 02:09:04 volumio volumio[3074]: info: MPD Permissions set Feb 13 02:09:04 volumio volumio[3074]: info: Upmpdcli Daemon Started Feb 13 02:09:04 volumio volumio[3074]: info: Volumio called home Feb 13 02:09:04 volumio volumio[3074]: info: Spotify config file written Feb 13 02:09:04 volumio sudo[3319]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 13 02:09:04 volumio sudo[3319]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:09:04 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 13 02:09:04 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 13 02:09:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:09:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:09:04 volumio go-librespot[3321]: go-librespot daemon starting... Feb 13 02:09:04 volumio sudo[3319]: pam_unix(sudo:session): session closed for user root Feb 13 02:09:04 volumio go-librespot[3322]: time="2026-02-13T02:09:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:09:04 volumio go-librespot[3322]: time="2026-02-13T02:09:04+07:00" level=debug msg="app state loaded" Feb 13 02:09:04 volumio go-librespot[3322]: time="2026-02-13T02:09:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:09:05 volumio volumio[3074]: 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 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:05 volumio go-librespot[3322]: time="2026-02-13T02:09:05+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 13 02:09:05 volumio go-librespot[3322]: time="2026-02-13T02:09:05+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 13 02:09:05 volumio go-librespot[3322]: time="2026-02-13T02:09:05+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 13 02:09:05 volumio go-librespot[3322]: time="2026-02-13T02:09:05+07:00" level=info msg="zeroconf server listening on port 35969" Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 02:09:05 volumio volumio[3074]: info: No need to fix Spotify hosts Feb 13 02:09:05 volumio go-librespot[3322]: time="2026-02-13T02:09:05+07:00" level=debug msg="obtained new client token: AAAN2yHq5ca/MtBLx87Z9yIedM/AgcxAUrZXv4Rrdg5ZjKg1/XYHt3bMSSKzs5XhJIjkAOiof/tkensmKTW1lFqE2Z4dLpLlXkkF8YKvTDy2PpKNsCA41MVB600LsI4siw8O4Ju9HeeUOUPUjSfA73Hh4Agh0dl4htlbTA+41y4DRwNNkIzaIA9yLD8zoogNUqgoO8zgO4mHdNRWgWGtCWRjvxHlVPFwbNIbbN+v4CZ50Se3KPbly1e4BQ==" Feb 13 02:09:05 volumio go-librespot[3322]: time="2026-02-13T02:09:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 02:09:05 volumio go-librespot[3322]: time="2026-02-13T02:09:05+07:00" level=debug msg="completed keyexchange" Feb 13 02:09:05 volumio go-librespot[3322]: time="2026-02-13T02:09:05+07:00" level=debug msg="completed challenge" Feb 13 02:09:05 volumio go-librespot[3322]: time="2026-02-13T02:09:05+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 13 02:09:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:09:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:09:06 volumio volumio[3074]: info: Starting Shairport Sync Feb 13 02:09:06 volumio volumio[3074]: info: Starting Shairport Sync Feb 13 02:09:06 volumio volumio[3074]: info: Starting Shairport Sync Feb 13 02:09:06 volumio sudo[3359]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 13 02:09:06 volumio sudo[3359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:09:06 volumio sudo[3363]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 13 02:09:06 volumio sudo[3363]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:09:06 volumio sudo[3361]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 13 02:09:06 volumio sudo[3361]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:09:06 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 13 02:09:06 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 13 02:09:06 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 13 02:09:06 volumio systemd[1]: shairport-sync.service: Consumed 2.291s CPU time. Feb 13 02:09:06 volumio volumio[3074]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 13 02:09:06 volumio volumio[3074]: SPOTIFY: BQCcfhGTNUKAP4WpgcE24x_S2LWAGu-eVWdsfKE-9SB2lAmx4R9w-RldAhW8fVWwBKfeVj3GjZrr5gHMFH_QOZ3cqLtXUcrIgBFzB3tISxUpbpmQABUz_8JILfSSnHGZiLxzxDi2qyc6SbnZ47Sae98s2wc67RqFaG-ERe8-RL-chM2V5Rso8geVQ9mArDH8A4eGlDZ9i5H9-TICu86xyYWXtMWhg4X0SWJmsc4obj1fbPlOd28br1vk8THcFKU5Ith4Yl6lGlZMwWfy3a4RUa40pRVRycK5IlcEtHicU5Ivk-tDqzxBMaQP Feb 13 02:09:06 volumio volumio[3074]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 13 02:09:06 volumio volumio[3074]: info: New Spotify access token = BQCcfhGTNUKAP4WpgcE24x_S2LWAGu-eVWdsfKE-9SB2lAmx4R9w-RldAhW8fVWwBKfeVj3GjZrr5gHMFH_QOZ3cqLtXUcrIgBFzB3tISxUpbpmQABUz_8JILfSSnHGZiLxzxDi2qyc6SbnZ47Sae98s2wc67RqFaG-ERe8-RL-chM2V5Rso8geVQ9mArDH8A4eGlDZ9i5H9-TICu86xyYWXtMWhg4X0SWJmsc4obj1fbPlOd28br1vk8THcFKU5Ith4Yl6lGlZMwWfy3a4RUa40pRVRycK5IlcEtHicU5Ivk-tDqzxBMaQP Feb 13 02:09:06 volumio volumio[3074]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 13 02:09:06 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 13 02:09:06 volumio sudo[3363]: pam_unix(sudo:session): session closed for user root Feb 13 02:09:06 volumio sudo[3359]: pam_unix(sudo:session): session closed for user root Feb 13 02:09:06 volumio sudo[3361]: pam_unix(sudo:session): session closed for user root Feb 13 02:09:06 volumio volumio[3074]: info: CoreCommandRouter::volumioGetState Feb 13 02:09:06 volumio volumio[3074]: info: CorePlayQueue::getTrack 0 Feb 13 02:09:06 volumio volumio[3074]: info: Shairport-Sync Started Feb 13 02:09:06 volumio volumio[3074]: Error adding Membership: Error: addMembership EINVAL Feb 13 02:09:06 volumio volumio[3074]: info: Shairport-Sync Started Feb 13 02:09:06 volumio volumio[3074]: info: Shairport-Sync Started Feb 13 02:09:07 volumio volumio[3074]: 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 13 02:09:07 volumio volumio[3074]: info: Spotify Successfully logged in Feb 13 02:09:07 volumio volumio[3074]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 02:09:07 volumio volumio[3074]: info: [1770923347217] CoreMusicLibrary::Adding element Spotify Feb 13 02:09:07 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 02:09:07 volumio volumio[3074]: Cannot find translation for source YouTube Music Feb 13 02:09:07 volumio volumio[3074]: Cannot find translation for source Spotify Feb 13 02:09:07 volumio volumio[3074]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 13 02:09:07 volumio volumio[3074]: info: CoreCommandRouter::volumioRetrievevolume Feb 13 02:09:07 volumio volumio[3074]: info: VolumeController:: Volume=100 Mute =false Feb 13 02:09:07 volumio volumio[3074]: info: CoreCommandRouter::volumioGetState Feb 13 02:09:07 volumio volumio[3074]: info: CorePlayQueue::getTrack 0 Feb 13 02:09:07 volumio volumio[3074]: info: CoreStateMachine::pushState Feb 13 02:09:07 volumio volumio[3074]: info: CorePlayQueue::getTrack 0 Feb 13 02:09:07 volumio volumio[3074]: info: CoreCommandRouter::volumioPushState Feb 13 02:09:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 13 02:09:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:09:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:09:09 volumio go-librespot[3399]: go-librespot daemon starting... Feb 13 02:09:09 volumio volumio[3074]: info: go-librespot daemon successfully initialized Feb 13 02:09:09 volumio go-librespot[3400]: time="2026-02-13T02:09:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:09:09 volumio go-librespot[3400]: time="2026-02-13T02:09:09+07:00" level=debug msg="app state loaded" Feb 13 02:09:09 volumio go-librespot[3400]: time="2026-02-13T02:09:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:09:09 volumio mpd[3301]: 2026-02-13T02:09:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 13 02:09:09 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 13 02:09:09 volumio sudo[3262]: pam_unix(sudo:session): session closed for user root Feb 13 02:09:09 volumio sudo[3272]: pam_unix(sudo:session): session closed for user root Feb 13 02:09:09 volumio volumio[3074]: error: MPD error: The expression evaluated to a falsy value: Feb 13 02:09:09 volumio volumio[3074]: assert.ok(self.idling) Feb 13 02:09:09 volumio volumio[3074]: error: The expression evaluated to a falsy value: Feb 13 02:09:09 volumio volumio[3074]: assert.ok(self.idling) Feb 13 02:09:09 volumio volumio[3074]: info: MPD running with PID3301 Feb 13 02:09:09 volumio volumio[3074]: ,establishing connection Feb 13 02:09:09 volumio volumio[3074]: error: updateQueue error: null Feb 13 02:09:09 volumio volumio[3074]: info: Completed starting Core Plugins Feb 13 02:09:09 volumio volumio[3074]: info: ------------------------------------------- Feb 13 02:09:09 volumio volumio[3074]: info: ----- MyVolumio plugins startup ---- Feb 13 02:09:09 volumio volumio[3074]: info: ------------------------------------------- Feb 13 02:09:09 volumio volumio[3074]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 13 02:09:09 volumio volumio[3074]: error: updateQueue error: null Feb 13 02:09:09 volumio go-librespot[3400]: time="2026-02-13T02:09:09+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 13 02:09:09 volumio go-librespot[3400]: time="2026-02-13T02:09:09+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 13 02:09:09 volumio go-librespot[3400]: time="2026-02-13T02:09:09+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 13 02:09:09 volumio go-librespot[3400]: time="2026-02-13T02:09:09+07:00" level=info msg="zeroconf server listening on port 44499" Feb 13 02:09:09 volumio go-librespot[3400]: time="2026-02-13T02:09:09+07:00" level=debug msg="obtained new client token: AAA0ATdM2H/e4oAB9fVXaJ4ZKj+1ZNsV8T977qsJ2z6emLkEeGqQYKBmpBykAxF1E/YeTN5Yiqvs6AJwfXlej1mliwGtKenWXIOokDZGJ8vXc+sfO6zvvGir1RMA5YyuwNrJc0ZdPclIj5tS/Binx4a65CXTU3rnbrcYScs6p9QUWO8IKgA7VtlDrlojmE4QvoUqJKT9PJVFtD6uPW2LCv9DMnmun0ED7qV3FJiGGXMbpb//+QpVW8vCtA==" Feb 13 02:09:10 volumio go-librespot[3400]: time="2026-02-13T02:09:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 02:09:10 volumio go-librespot[3400]: time="2026-02-13T02:09:10+07:00" level=debug msg="completed keyexchange" Feb 13 02:09:10 volumio go-librespot[3400]: time="2026-02-13T02:09:10+07:00" level=debug msg="completed challenge" Feb 13 02:09:10 volumio go-librespot[3400]: time="2026-02-13T02:09:10+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 13 02:09:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:09:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:09:12 volumio volumio[3074]: info: Initializing connection to go-librespot Websocket Feb 13 02:09:12 volumio volumio[3074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 13 02:09:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 13 02:09:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:09:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:09:13 volumio go-librespot[3412]: go-librespot daemon starting... Feb 13 02:09:13 volumio go-librespot[3413]: time="2026-02-13T02:09:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:09:13 volumio go-librespot[3413]: time="2026-02-13T02:09:13+07:00" level=debug msg="app state loaded" Feb 13 02:09:13 volumio go-librespot[3413]: time="2026-02-13T02:09:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:09:14 volumio go-librespot[3413]: time="2026-02-13T02:09:14+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 13 02:09:14 volumio go-librespot[3413]: time="2026-02-13T02:09:14+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 13 02:09:14 volumio go-librespot[3413]: time="2026-02-13T02:09:14+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 13 02:09:14 volumio go-librespot[3413]: time="2026-02-13T02:09:14+07:00" level=info msg="zeroconf server listening on port 36723" Feb 13 02:09:14 volumio go-librespot[3413]: time="2026-02-13T02:09:14+07:00" level=debug msg="obtained new client token: AADoEFZ/WA9cABg+r3dtQI0yOrPBRExXs1JludtonFD7rBdZhonQyZecjrJ/v98c/O1VyTDUR9xR4hpe9ZvQWd5+GpOSFFOlTqoNh/srZ/uGlfh+g1Ey/Clb5dZQn+g2t3tln/JMD7TrV5RltUwqZ3V5ROQoRYP0rQBuj9LMHvC+GUqMP9ollNa1SNnOjY9FoP8OdHYBNpx44nHjrIHapIb66uqVS+HKTULDLqktffNczHYHf+m8RutgSw==" Feb 13 02:09:14 volumio volumio[3074]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 13 02:09:14 volumio go-librespot[3413]: time="2026-02-13T02:09:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 02:09:14 volumio go-librespot[3413]: time="2026-02-13T02:09:14+07:00" level=debug msg="completed keyexchange" Feb 13 02:09:14 volumio go-librespot[3413]: time="2026-02-13T02:09:14+07:00" level=debug msg="completed challenge" Feb 13 02:09:14 volumio go-librespot[3413]: time="2026-02-13T02:09:14+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 13 02:09:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:09:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:09:15 volumio volumio[3074]: info: Initializing connection to go-librespot Websocket Feb 13 02:09:15 volumio volumio[3074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 13 02:09:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 13 02:09:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:09:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:09:17 volumio go-librespot[3420]: go-librespot daemon starting... Feb 13 02:09:17 volumio go-librespot[3421]: time="2026-02-13T02:09:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:09:17 volumio go-librespot[3421]: time="2026-02-13T02:09:17+07:00" level=debug msg="app state loaded" Feb 13 02:09:17 volumio go-librespot[3421]: time="2026-02-13T02:09:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:09:18 volumio volumio[3074]: info: Initializing connection to go-librespot Websocket Feb 13 02:09:18 volumio go-librespot[3421]: time="2026-02-13T02:09:18+07:00" level=debug msg="new websocket client" Feb 13 02:09:18 volumio volumio[3074]: info: Connection to go-librespot Websocket established Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 13 02:09:18 volumio volumio[3074]: info: Adding plugin bluetooth to MyMusic Plugins Feb 13 02:09:18 volumio volumio[3074]: info: Adding plugin multiroom to MyMusic Plugins Feb 13 02:09:18 volumio volumio[3074]: info: Adding plugin metavolumio to MyMusic Plugins Feb 13 02:09:18 volumio volumio[3074]: info: Adding plugin cd_controller to MyMusic Plugins Feb 13 02:09:18 volumio volumio[3074]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 13 02:09:18 volumio volumio[3074]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 13 02:09:18 volumio volumio[3074]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 13 02:09:18 volumio go-librespot[3421]: time="2026-02-13T02:09:18+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 13 02:09:18 volumio go-librespot[3421]: time="2026-02-13T02:09:18+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 13 02:09:18 volumio volumio[3074]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 13 02:09:18 volumio go-librespot[3421]: time="2026-02-13T02:09:18+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 13 02:09:18 volumio go-librespot[3421]: time="2026-02-13T02:09:18+07:00" level=info msg="zeroconf server listening on port 41565" Feb 13 02:09:18 volumio go-librespot[3421]: time="2026-02-13T02:09:18+07:00" level=debug msg="obtained new client token: AAAldnlDTH1hW9rJdOOjLd+GGa6jCRnujFFpySTi5zBq4w3tarHr78W/nFh2GkYVFncB9vyuR1TbKlxwUiBHGqwmcKPnxmuv9CiNvekYe0ewqMovvTuJE/VrDxsOPPTk5lB2p6cHHY9OjiVmFDDgbQAKelpDdaqO6SaMaIgpj+A13bCNHzOUGW5OvGT5Bj8lgYkxFHsfqDjQOyPbRjkAwuu0IXz4rG/BjHydNAaLYB6wz4yTLBCHb4g9Uw==" Feb 13 02:09:18 volumio go-librespot[3421]: time="2026-02-13T02:09:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 02:09:18 volumio go-librespot[3421]: time="2026-02-13T02:09:18+07:00" level=debug msg="completed keyexchange" Feb 13 02:09:18 volumio go-librespot[3421]: time="2026-02-13T02:09:18+07:00" level=debug msg="completed challenge" Feb 13 02:09:19 volumio go-librespot[3421]: time="2026-02-13T02:09:19+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 13 02:09:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:09:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:09:20 volumio volumio[3074]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 13 02:09:20 volumio volumio[3074]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 13 02:09:20 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 02:09:20 volumio volumio[3074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 02:09:20 volumio volumio[3074]: info: Starting MyVolumio Remote Streaming Endpoints Feb 13 02:09:20 volumio volumio[3074]: info: MyVolumio login type: Token Feb 13 02:09:20 volumio volumio[3074]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 13 02:09:20 volumio volumio[3074]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 13 02:09:22 volumio volumio[3074]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 13 02:09:22 volumio volumio[3074]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 13 02:09:22 volumio volumio[3074]: info: Streaming services startup Feb 13 02:09:22 volumio volumio[3074]: info: Starting Streaming Daemon Feb 13 02:09:22 volumio sudo[3443]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 13 02:09:22 volumio sudo[3443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 02:09:22 volumio volumio[3074]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 13 02:09:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 13 02:09:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:09:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 02:09:22 volumio go-librespot[3449]: go-librespot daemon starting... Feb 13 02:09:22 volumio sudo[3443]: pam_unix(sudo:session): session closed for user root Feb 13 02:09:22 volumio volumio[3074]: info: Getting Spotify volume Feb 13 02:09:22 volumio volumio[3074]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 13 02:09:22 volumio go-librespot[3450]: time="2026-02-13T02:09:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 02:09:22 volumio go-librespot[3450]: time="2026-02-13T02:09:22+07:00" level=debug msg="app state loaded" Feb 13 02:09:22 volumio go-librespot[3450]: time="2026-02-13T02:09:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 02:09:22 volumio volumio[3074]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 13 02:09:22 volumio volumio[3074]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 13 02:09:22 volumio volumio[3074]: errno: -111, Feb 13 02:09:22 volumio volumio[3074]: code: 'ECONNREFUSED', Feb 13 02:09:22 volumio volumio[3074]: syscall: 'connect', Feb 13 02:09:22 volumio volumio[3074]: address: '127.0.0.1', Feb 13 02:09:22 volumio volumio[3074]: port: 9879, Feb 13 02:09:22 volumio volumio[3074]: response: undefined Feb 13 02:09:22 volumio volumio[3074]: } Feb 13 02:09:22 volumio volumio[3074]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 13 02:09:22 volumio go-librespot[3450]: time="2026-02-13T02:09:22+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 13 02:09:22 volumio go-librespot[3450]: time="2026-02-13T02:09:22+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 13 02:09:22 volumio go-librespot[3450]: time="2026-02-13T02:09:22+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 13 02:09:22 volumio go-librespot[3450]: time="2026-02-13T02:09:22+07:00" level=info msg="zeroconf server listening on port 33973" Feb 13 02:09:23 volumio go-librespot[3450]: time="2026-02-13T02:09:23+07:00" level=debug msg="obtained new client token: AADgO8tNvFVPHPJrjmYe/fwmHTDy99AZxFrD/KKLebggn3lAb4GGMjwg6A74b0Hhhudu9sd++Xm6aI+1+7W6YWF7abf8yEps4bF2Knp5jcWNkNsrQDcKSLMBdNHHUGnm08G+MP4NuXBqcGgWybVS+YqlBSz8X1PRkjqTf+RP8n0Y02RSGabLO9C0iURmkPtk6FGFVbUQ8NycCMloI98YyxLAZfLADWg+Z7GioAbPnl39V99ewiRK+ek=" Feb 13 02:09:23 volumio go-librespot[3450]: time="2026-02-13T02:09:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 02:09:23 volumio go-librespot[3450]: time="2026-02-13T02:09:23+07:00" level=debug msg="completed keyexchange" Feb 13 02:09:23 volumio go-librespot[3450]: time="2026-02-13T02:09:23+07:00" level=debug msg="completed challenge" Feb 13 02:09:23 volumio go-librespot[3450]: time="2026-02-13T02:09:23+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 13 02:09:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 02:09:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 02:09:23 volumio sudo[3471]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-13 02:08' Feb 13 02:09:23 volumio sudo[3471]: 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"