Feb 18 07:07:00 volumio sudo[14873]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 07:06' Feb 18 07:07:00 volumio sudo[14873]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:01 volumio sudo[14873]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:02 volumio volumio-remote-updater[25144]: [2026-02-18 07:07:02] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 18 07:07:02 volumio volumio-remote-updater[25144]: [2026-02-18 07:07:02] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 18 07:07:02 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:07:02 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 07:07:02 volumio systemd[1]: volumio.service: Consumed 55.390s CPU time. Feb 18 07:07:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 07:07:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 07:07:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:02 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 21542. Feb 18 07:07:02 volumio go-librespot[14884]: go-librespot daemon starting... Feb 18 07:07:02 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 07:07:02 volumio systemd[1]: volumio.service: Consumed 55.390s CPU time. Feb 18 07:07:02 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 07:07:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 07:07:02 volumio go-librespot[14888]: time="2026-02-18T07:07:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:07:02 volumio go-librespot[14888]: time="2026-02-18T07:07:02+07:00" level=debug msg="app state loaded" Feb 18 07:07:02 volumio go-librespot[14888]: time="2026-02-18T07:07:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:07:03 volumio go-librespot[14888]: time="2026-02-18T07:07:03+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 18 07:07:03 volumio go-librespot[14888]: time="2026-02-18T07:07:03+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 18 07:07:03 volumio go-librespot[14888]: time="2026-02-18T07:07:03+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 18 07:07:03 volumio go-librespot[14888]: time="2026-02-18T07:07:03+07:00" level=info msg="zeroconf server listening on port 41565" Feb 18 07:07:03 volumio go-librespot[14888]: time="2026-02-18T07:07:03+07:00" level=debug msg="obtained new client token: AAB0U+3afhhPVvGA2endu0IZRslEpLd4E21/RjgBuDOcgyTyP8dIoN0GXMEZZmWkVFwNSIptJBp0BDgN93mLp6wi4nxijz6bMI3AZzWwgHlksZYGU1pLL1zusXT+Nv4fNRKVWM0RS8SzpAFj7YBQwFKhZePAeKSxyG+1SfhDLEymyK/GF6dhLfZ1M2XT2eg/L122cxyOJfo7V0XcQrdmf8H624h6NzDp+UPymL/cb5ueoqxD58F+wKo=" Feb 18 07:07:03 volumio go-librespot[14888]: time="2026-02-18T07:07:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:07:03 volumio go-librespot[14888]: time="2026-02-18T07:07:03+07:00" level=debug msg="completed keyexchange" Feb 18 07:07:03 volumio go-librespot[14888]: time="2026-02-18T07:07:03+07:00" level=debug msg="completed challenge" Feb 18 07:07:03 volumio go-librespot[14888]: time="2026-02-18T07:07:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 07:07:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:07:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:07:06 volumio volumio[14889]: info: ------------------------------------------- Feb 18 07:07:06 volumio volumio[14889]: info: ----- Volumio3 ---- Feb 18 07:07:06 volumio volumio[14889]: info: ------------------------------------------- Feb 18 07:07:06 volumio volumio[14889]: info: ----- System startup ---- Feb 18 07:07:06 volumio volumio[14889]: info: ------------------------------------------- Feb 18 07:07:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 07:07:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:06 volumio go-librespot[14912]: go-librespot daemon starting... Feb 18 07:07:06 volumio go-librespot[14913]: time="2026-02-18T07:07:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:07:06 volumio go-librespot[14913]: time="2026-02-18T07:07:06+07:00" level=debug msg="app state loaded" Feb 18 07:07:06 volumio go-librespot[14913]: time="2026-02-18T07:07:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:07:07 volumio volumio-remote-updater[25144]: [2026-02-18 07:07:07] [connect] Successful connection Feb 18 07:07:07 volumio go-librespot[14913]: time="2026-02-18T07:07:07+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 18 07:07:07 volumio go-librespot[14913]: time="2026-02-18T07:07:07+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 18 07:07:07 volumio go-librespot[14913]: time="2026-02-18T07:07:07+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 18 07:07:07 volumio volumio[14889]: info: MYVOLUMIO Environment detected Feb 18 07:07:07 volumio go-librespot[14913]: time="2026-02-18T07:07:07+07:00" level=info msg="zeroconf server listening on port 41471" Feb 18 07:07:07 volumio volumio[14889]: info: Plugin folders cleanup Feb 18 07:07:07 volumio volumio[14889]: info: Scanning into folder /volumio/app/plugins/ Feb 18 07:07:07 volumio volumio[14889]: info: Scanning category audio_interface Feb 18 07:07:07 volumio volumio[14889]: info: Scanning category miscellanea Feb 18 07:07:07 volumio volumio[14889]: info: Scanning category music_service Feb 18 07:07:07 volumio volumio[14889]: info: Scanning category plugins.json Feb 18 07:07:07 volumio volumio[14889]: info: Scanning category system_controller Feb 18 07:07:07 volumio volumio[14889]: info: Scanning category user_interface Feb 18 07:07:07 volumio volumio[14889]: info: Scanning into folder /data/plugins/ Feb 18 07:07:07 volumio volumio[14889]: info: Scanning category music_service Feb 18 07:07:07 volumio volumio[14889]: info: Plugin folders cleanup completed Feb 18 07:07:07 volumio volumio[14889]: info: ------------------------------------------- Feb 18 07:07:07 volumio volumio[14889]: info: ----- Core plugins startup ---- Feb 18 07:07:07 volumio volumio[14889]: info: ------------------------------------------- Feb 18 07:07:07 volumio volumio[14889]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 07:07:07 volumio volumio[14889]: info: Adding plugin upnp to MyMusic Plugins Feb 18 07:07:07 volumio volumio[14889]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 07:07:07 volumio volumio[14889]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 07:07:07 volumio volumio[14889]: info: Loading plugins from folder /data/plugins/ Feb 18 07:07:07 volumio volumio[14889]: info: Loading plugin "system"... Feb 18 07:07:07 volumio go-librespot[14913]: time="2026-02-18T07:07:07+07:00" level=debug msg="obtained new client token: AADe4jcl22zsIiSsideXiqOmVuqzWEy8DD41oJTlh0P0ZRpFm/pAijRlOgKCFYTGBQBVSkls5rwGRLyTQS26OLug0SNptW/KF02ekLG2J06bNbuUex2sjSRSykNK0YlWt4BNL8SFRaYV+pAlCO2P3d1tC1hDh/Fv4YC9zPXYE32pKA7BPiknbSGfz8Rids3XKhnA2WrdyO/wlOBqs6MXVVnVsX7We8n3XiaTEmCdqyQe0hRKktyaw+DcDA==" Feb 18 07:07:07 volumio volumio[14889]: info: Loading plugin "appearance"... Feb 18 07:07:07 volumio go-librespot[14913]: time="2026-02-18T07:07:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:07:07 volumio go-librespot[14913]: time="2026-02-18T07:07:07+07:00" level=debug msg="completed keyexchange" Feb 18 07:07:07 volumio go-librespot[14913]: time="2026-02-18T07:07:07+07:00" level=debug msg="completed challenge" Feb 18 07:07:07 volumio go-librespot[14913]: time="2026-02-18T07:07:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 07:07:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:07:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:07:09 volumio volumio[14889]: info: Loading plugin "network"... Feb 18 07:07:09 volumio volumio[14889]: info: Refreshing Cached IP Addresses Feb 18 07:07:09 volumio sudo[14928]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 07:07:09 volumio sudo[14928]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:09 volumio sudo[14930]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 07:07:09 volumio sudo[14930]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:09 volumio sudo[14928]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:09 volumio volumio[14889]: info: Loading plugin "services"... Feb 18 07:07:09 volumio volumio[14889]: info: Loading plugin "alsa_controller"... Feb 18 07:07:09 volumio sudo[14930]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:09 volumio sudo[14937]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 07:07:09 volumio sudo[14937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:09 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 07:07:09 volumio volumio[14889]: info: Loading plugin "wizard"... Feb 18 07:07:09 volumio volumio[14889]: info: Loading plugin "networkfs"... Feb 18 07:07:09 volumio volumio[14889]: info: Starting Udev Watcher for removable devices Feb 18 07:07:10 volumio volumio[14889]: info: Ignoring mount for partition: boot Feb 18 07:07:10 volumio volumio[14889]: info: Ignoring mount for partition: volumio Feb 18 07:07:10 volumio volumio[14889]: info: Ignoring mount for partition: volumio_data Feb 18 07:07:10 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 07:07:10 volumio volumio[14889]: info: Loading plugin "volumio_command_line_client"... Feb 18 07:07:10 volumio volumio[14889]: info: Loading plugin "upnp"... Feb 18 07:07:10 volumio volumio[14889]: info: [1771373230055] Starting Upmpd Daemon Feb 18 07:07:10 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 07:07:10 volumio volumio[14889]: info: Loading plugin "my_music"... Feb 18 07:07:10 volumio volumio[14889]: info: Loading plugin "mpd"... Feb 18 07:07:10 volumio volumio[14889]: info: Loading plugin "upnp_browser"... Feb 18 07:07:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 07:07:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:11 volumio go-librespot[14961]: go-librespot daemon starting... Feb 18 07:07:11 volumio go-librespot[14962]: time="2026-02-18T07:07:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:07:11 volumio go-librespot[14962]: time="2026-02-18T07:07:11+07:00" level=debug msg="app state loaded" Feb 18 07:07:11 volumio go-librespot[14962]: time="2026-02-18T07:07:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:07:11 volumio go-librespot[14962]: time="2026-02-18T07:07:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 07:07:11 volumio go-librespot[14962]: time="2026-02-18T07:07:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 07:07:11 volumio go-librespot[14962]: time="2026-02-18T07:07:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 07:07:11 volumio go-librespot[14962]: time="2026-02-18T07:07:11+07:00" level=info msg="zeroconf server listening on port 38667" Feb 18 07:07:12 volumio go-librespot[14962]: time="2026-02-18T07:07:12+07:00" level=debug msg="obtained new client token: AADX335wEjiYoqLLKkdACCeymUTrSrGC4kq1hhi46DKnmw+JO3QY80jmAGUj+wxWFzd+aCZOUM+rhedH6UCZtmKiuMBY70sJJQC+O8/+8oC2iM95jYyJmdYmxn0aMkTfNTMAlS0SI6OwnTGNADR4uIZ2xpi7wrcnuVT1qW71cqsIWm2dARyZ8PdJstbi2I2ceDCm9tjFN4GAmoLW5NnueC7ORlHN59ENee3b8KZdCJtI1iRjb0cHoVTAlw==" Feb 18 07:07:12 volumio go-librespot[14962]: time="2026-02-18T07:07:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:07:12 volumio go-librespot[14962]: time="2026-02-18T07:07:12+07:00" level=debug msg="completed keyexchange" Feb 18 07:07:12 volumio go-librespot[14962]: time="2026-02-18T07:07:12+07:00" level=debug msg="completed challenge" Feb 18 07:07:12 volumio go-librespot[14962]: time="2026-02-18T07:07:12+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 18 07:07:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:07:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:07:12 volumio sudo[14937]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:13 volumio volumio[14889]: info: Starting UPNP Browser Feb 18 07:07:13 volumio volumio[14889]: info: Loading plugin "alarm-clock"... Feb 18 07:07:13 volumio volumio[14889]: info: Loading plugin "airplay_emulation"... Feb 18 07:07:14 volumio volumio[14889]: info: Starting Shairport Sync Feb 18 07:07:14 volumio volumio[14889]: info: Loading plugin "last_100"... Feb 18 07:07:14 volumio volumio[14889]: info: Loading plugin "webradio"... Feb 18 07:07:14 volumio volumio[14889]: info: Loading plugin "i2s_dacs"... Feb 18 07:07:14 volumio volumio[14889]: info: Loading plugin "volumiodiscovery"... Feb 18 07:07:14 volumio volumio[14889]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 07:07:14 volumio volumio[14889]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 07:07:14 volumio volumio[14889]: *** WARNING *** For more information see Feb 18 07:07:14 volumio volumio[14889]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 07:07:14 volumio volumio[14889]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 07:07:14 volumio volumio[14889]: *** WARNING *** For more information see Feb 18 07:07:14 volumio node[14889]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 07:07:14 volumio node[14889]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 07:07:14 volumio volumio[14889]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 07:07:14 volumio node[14889]: *** WARNING *** For more information see Feb 18 07:07:14 volumio node[14889]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 07:07:14 volumio node[14889]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 07:07:14 volumio node[14889]: *** WARNING *** For more information see Feb 18 07:07:14 volumio volumio[14889]: info: Discovery: Started advertising with name: Volumio Feb 18 07:07:14 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 07:07:14 volumio volumio[14889]: info: Loading plugin "spop"... Feb 18 07:07:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 07:07:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:15 volumio go-librespot[14971]: go-librespot daemon starting... Feb 18 07:07:15 volumio go-librespot[14972]: time="2026-02-18T07:07:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:07:15 volumio go-librespot[14972]: time="2026-02-18T07:07:15+07:00" level=debug msg="app state loaded" Feb 18 07:07:15 volumio go-librespot[14972]: time="2026-02-18T07:07:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:07:16 volumio go-librespot[14972]: time="2026-02-18T07:07:16+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 18 07:07:16 volumio go-librespot[14972]: time="2026-02-18T07:07:16+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 18 07:07:16 volumio go-librespot[14972]: time="2026-02-18T07:07:16+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 18 07:07:16 volumio go-librespot[14972]: time="2026-02-18T07:07:16+07:00" level=info msg="zeroconf server listening on port 34681" Feb 18 07:07:16 volumio volumio[14889]: info: Loading plugin "ytcr"... Feb 18 07:07:16 volumio go-librespot[14972]: time="2026-02-18T07:07:16+07:00" level=debug msg="obtained new client token: AADSh9AAsA2TsJCJh3o43+5sbO04obf9q2akQ7VRD3vscedy0r9ikZYmLltnKGL5c723Huyj7y2cWMXpjZeigUbWnXTfICE39PB8pDptR8pEBarssRMvBDljeJVMs4hA5PQzZCXSpoy2gGhqimMv2Z/lLO+JnOthiZF8YftcUmILNFLQnZd2pujUE3rFfnT7K9nrgEtaWRAF3n21lPxi3Jra8nRxojkv1WB9e0/EN2jKsG/kvRi7FRwgkw==" Feb 18 07:07:16 volumio go-librespot[14972]: time="2026-02-18T07:07:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:07:16 volumio go-librespot[14972]: time="2026-02-18T07:07:16+07:00" level=debug msg="completed keyexchange" Feb 18 07:07:16 volumio go-librespot[14972]: time="2026-02-18T07:07:16+07:00" level=debug msg="completed challenge" Feb 18 07:07:16 volumio go-librespot[14972]: time="2026-02-18T07:07:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 07:07:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:07:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:07:18 volumio volumio[14889]: info: Loading plugin "ytmusic"... Feb 18 07:07:19 volumio volumio-remote-updater[25144]: [2026-02-18 07:07:19] [connect] Successful connection Feb 18 07:07:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 07:07:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:19 volumio go-librespot[14984]: go-librespot daemon starting... Feb 18 07:07:19 volumio go-librespot[14986]: time="2026-02-18T07:07:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:07:19 volumio go-librespot[14986]: time="2026-02-18T07:07:19+07:00" level=debug msg="app state loaded" Feb 18 07:07:19 volumio go-librespot[14986]: time="2026-02-18T07:07:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:07:20 volumio volumio[14889]: info: Loading plugin "outputs"... Feb 18 07:07:20 volumio volumio[14889]: info: Loading plugin "albumart"... Feb 18 07:07:20 volumio volumio[14889]: info: Plugin example_plugin is not enabled Feb 18 07:07:20 volumio volumio[14889]: info: Loading plugin "inputs"... Feb 18 07:07:20 volumio volumio[14889]: info: Loading plugin "updater_comm"... Feb 18 07:07:20 volumio volumio[14889]: info: Plugin mpdemulation is not enabled Feb 18 07:07:20 volumio volumio[14889]: info: Loading plugin "rest_api"... Feb 18 07:07:20 volumio volumio[14889]: info: Loading plugin "websocket"... Feb 18 07:07:20 volumio volumio[14889]: info: Starting Socket.io Server version 1.7.4 Feb 18 07:07:20 volumio volumio[14889]: info: Loading plugin "RoonBridge"... Feb 18 07:07:20 volumio go-librespot[14986]: time="2026-02-18T07:07:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 07:07:20 volumio go-librespot[14986]: time="2026-02-18T07:07: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 18 07:07:20 volumio go-librespot[14986]: time="2026-02-18T07:07: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 18 07:07:20 volumio go-librespot[14986]: time="2026-02-18T07:07:20+07:00" level=info msg="zeroconf server listening on port 38043" Feb 18 07:07:20 volumio go-librespot[14986]: time="2026-02-18T07:07:20+07:00" level=debug msg="obtained new client token: AADtOCHR8uoCxAb6sd62Qmr+nIC1bMXhTPufSt87ORAsXXThAM0SA0ZTsXzDd8DzeqiGSH+E8IUi6o4ocfAPrc2QGUVIruDBJ3woqC+41Ik3LGIz+8KjfjhIMjrsRmq4HWvOYH/HJZHD3WuXV0T4zAdL5uEzhWnCi02lch35rZEGSCTJCxy2NjUye5B6mJOeH8Bay1i0FKd+6MOnapmQ4GmJbxqsItWpThXGCHVSwLtcuo2ZnI+BrMaREg==" Feb 18 07:07:20 volumio volumio[14889]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 07:07:20 volumio volumio[14889]: info: Loading i18n strings for locale en Feb 18 07:07:20 volumio go-librespot[14986]: time="2026-02-18T07:07:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:07:20 volumio volumio[14889]: Updating browse sources language Feb 18 07:07:20 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 07:07:21 volumio go-librespot[14986]: time="2026-02-18T07:07:21+07:00" level=debug msg="completed keyexchange" Feb 18 07:07:21 volumio go-librespot[14986]: time="2026-02-18T07:07:21+07:00" level=debug msg="completed challenge" Feb 18 07:07:21 volumio go-librespot[14986]: time="2026-02-18T07:07: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 18 07:07:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:07:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::initPlayerControls Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:21 volumio volumio[15001]: Forking 3 albumart workers Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 07:07:21 volumio volumio[14889]: Express server listening on port 3000 Feb 18 07:07:21 volumio volumio[14889]: [Metrics] WebUI: 16s 189.39ms Feb 18 07:07:21 volumio volumio[14889]: info: CoreStateMachine::resetVolumioState Feb 18 07:07:21 volumio volumio[14889]: info: CoreStateMachine::getcurrentVolume Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 07:07:21 volumio sudo[15044]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 07:07:21 volumio sudo[15044]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:21 volumio sudo[15044]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:21 volumio sudo[15046]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 07:07:21 volumio sudo[15046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:21 volumio sudo[15046]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:21 volumio volumio[14889]: info: Volumio Network Manager: Network status updated: 1 Feb 18 07:07:21 volumio volumio[14889]: info: VolumeController:: Volume=100 Mute =false Feb 18 07:07:21 volumio volumio[14889]: info: CoreStateMachine::pushState Feb 18 07:07:21 volumio volumio[14889]: info: CorePlayQueue::getTrack 0 Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::volumioPushState Feb 18 07:07:21 volumio volumio[14889]: info: CoreStateMachine::updateTrackBlock Feb 18 07:07:21 volumio volumio[14889]: info: CorePlayQueue::getTrackBlock Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 07:07:21 volumio volumio-remote-updater[25144]: [2026-02-18 07:07:21] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771373239 101 Feb 18 07:07:22 volumio volumio[14889]: 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 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:07:22 volumio volumio[14889]: info: Reloading queue from file Feb 18 07:07:22 volumio volumio[14889]: info: CoreStateMachine::setRepeat null single undefined Feb 18 07:07:22 volumio volumio[14889]: info: CoreStateMachine::pushState Feb 18 07:07:22 volumio volumio[14889]: info: CorePlayQueue::getTrack 0 Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::volumioPushState Feb 18 07:07:22 volumio volumio[14889]: info: CoreStateMachine::setRandom null Feb 18 07:07:22 volumio volumio[14889]: info: CoreStateMachine::pushState Feb 18 07:07:22 volumio volumio[14889]: info: CorePlayQueue::getTrack 0 Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::volumioPushState Feb 18 07:07:22 volumio volumio[14889]: info: Setting Device type: Raspberry PI Feb 18 07:07:22 volumio volumio[14889]: info: Completed loading Core Plugins Feb 18 07:07:22 volumio volumio[14889]: info: Preparing to generate the ALSA configuration file Feb 18 07:07:22 volumio volumio[14889]: info: VolumeController:: Volume=100 Mute =false Feb 18 07:07:22 volumio volumio[14889]: info: CoreStateMachine::pushState Feb 18 07:07:22 volumio volumio[14889]: info: CorePlayQueue::getTrack 0 Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::volumioPushState Feb 18 07:07:22 volumio volumio[14889]: info: Asound.conf file unchanged, so no further update is needed Feb 18 07:07:22 volumio volumio[14889]: info: Output device has changed, restarting MPD Feb 18 07:07:22 volumio volumio[14889]: info: Output device has changed, restarting Shairport Sync Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:07:22 volumio sudo[15063]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 07:07:22 volumio sudo[15063]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:22 volumio sudo[15065]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 07:07:22 volumio volumio[14889]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 07:07:22 volumio sudo[15065]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:22 volumio volumio[14889]: info: ___________ START PLUGINS ___________ Feb 18 07:07:22 volumio sudo[15067]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 07:07:22 volumio sudo[15067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:22 volumio sudo[15065]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:22 volumio volumio[14889]: info: ControllerMpd::onStart: Initializing MPD Feb 18 07:07:22 volumio volumio[14889]: info: Creating MPD Configuration file Feb 18 07:07:22 volumio sudo[15063]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:22 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 07:07:22 volumio volumio[14889]: info: [1771373242678] CoreMusicLibrary::Adding element Media Servers Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 07:07:22 volumio sudo[15076]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 07:07:22 volumio sudo[15076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:22 volumio sudo[15076]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:22 volumio volumio[14889]: info: UPNP Browser: Client initialized successfully Feb 18 07:07:22 volumio sudo[15078]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 07:07:22 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 07:07:22 volumio sudo[15078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:22 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 07:07:22 volumio systemd[1]: mpd.service: Consumed 7.142s CPU time. Feb 18 07:07:22 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 07:07:22 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 07:07:22 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:07:22 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 07:07:22 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 07:07:22 volumio volumio[14889]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:07:22 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 07:07:22 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 07:07:22 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 07:07:22 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 07:07:22 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 07:07:23 volumio volumio[14889]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 07:07:23 volumio volumio[14889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 07:07:23 volumio volumio[14889]: info: [1771373243042] CoreMusicLibrary::Adding element Last_100 Feb 18 07:07:23 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 07:07:23 volumio volumio[14889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 07:07:23 volumio volumio[14889]: info: [1771373243062] CoreMusicLibrary::Adding element Webradio Feb 18 07:07:23 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 07:07:23 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 07:07:23 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 07:07:23 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 07:07:23 volumio volumio[14889]: info: Initializing BBC Radios Feb 18 07:07:23 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 07:07:23 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:07:23 volumio volumio[14889]: info: Creating Spotify config file Feb 18 07:07:23 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:23 volumio sudo[15092]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 07:07:23 volumio sudo[15092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 07:07:23 volumio sudo[15092]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 07:07:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:24 volumio go-librespot[15108]: go-librespot daemon starting... Feb 18 07:07:24 volumio volumio[14889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 07:07:24 volumio volumio[14889]: info: [1771373244459] CoreMusicLibrary::Adding element YouTube Music Feb 18 07:07:24 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 07:07:24 volumio volumio[14889]: Cannot find translation for source YouTube Music Feb 18 07:07:24 volumio go-librespot[15109]: time="2026-02-18T07:07:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:07:24 volumio volumio[14889]: info: Volumio Calling Home Feb 18 07:07:24 volumio volumio[15012]: Starting albumart workers Feb 18 07:07:24 volumio sudo[15116]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 07:07:24 volumio sudo[15116]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:24 volumio volumio[15014]: Starting albumart workers Feb 18 07:07:24 volumio sudo[15116]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:25 volumio volumio[15017]: Starting albumart workers Feb 18 07:07:25 volumio go-librespot[15109]: time="2026-02-18T07:07:25+07:00" level=info msg="zeroconf server listening on port 44053" Feb 18 07:07:25 volumio volumio[14889]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 07:07:25 volumio volumio[14889]: info: Discovery: Found device Volumio Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::volumioGetState Feb 18 07:07:25 volumio volumio[14889]: info: CorePlayQueue::getTrack 0 Feb 18 07:07:25 volumio volumio[14889]: info: MPD Permissions set Feb 18 07:07:25 volumio volumio[14889]: info: MPD Permissions set Feb 18 07:07:25 volumio volumio[14889]: info: Upmpdcli Daemon Started Feb 18 07:07:25 volumio volumio[14889]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 07:07:25 volumio volumio[14889]: info: Discovery: Found device Volumio Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::volumioGetState Feb 18 07:07:25 volumio volumio[14889]: info: CorePlayQueue::getTrack 0 Feb 18 07:07:25 volumio volumio[14889]: info: Volumio called home Feb 18 07:07:25 volumio volumio[14889]: info: Spotify config file written Feb 18 07:07:25 volumio sudo[15124]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 07:07:25 volumio sudo[15124]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:25 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 07:07:25 volumio volumio[14889]: 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 18 07:07:25 volumio systemd[1]: go-librespot-daemon.service: Killing process 15122 (go-librespot) with signal SIGKILL. Feb 18 07:07:25 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 07:07:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:25 volumio go-librespot[15126]: go-librespot daemon starting... Feb 18 07:07:25 volumio sudo[15124]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:26 volumio go-librespot[15132]: time="2026-02-18T07:07:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:07:26 volumio go-librespot[15132]: time="2026-02-18T07:07:26+07:00" level=debug msg="app state loaded" Feb 18 07:07:26 volumio go-librespot[15132]: time="2026-02-18T07:07:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:07:26 volumio volumio[14889]: info: No need to fix Spotify hosts Feb 18 07:07:26 volumio go-librespot[15132]: time="2026-02-18T07:07:26+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 07:07:26 volumio go-librespot[15132]: time="2026-02-18T07:07:26+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 18 07:07:26 volumio go-librespot[15132]: time="2026-02-18T07:07:26+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 18 07:07:26 volumio go-librespot[15132]: time="2026-02-18T07:07:26+07:00" level=info msg="zeroconf server listening on port 38207" Feb 18 07:07:26 volumio go-librespot[15132]: time="2026-02-18T07:07:26+07:00" level=debug msg="obtained new client token: AAC7bJY0sGzZ4UN+fO3HAcYwhsqw/7KSSBW7VSPxW5/JCzBwJbVeDz4neYIUdMdQWdnwx8NcOC+4XaK3Jkci7qH6bdASoiVrS49RYEo4+8XfYcFPbB+PLhirxutRdiIybt2Hh25qIVcJO5LWmNsv3qGho0H3IGMMcQ1rK2vNglP3Vs5uen1k5hiNX7o5QNcIU5CQjvdl+dZpDj131eLjJNb2PBGI8k51i+cc6nXNxIxl5new4r8oJBzASQ==" Feb 18 07:07:27 volumio go-librespot[15132]: time="2026-02-18T07:07:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:07:27 volumio go-librespot[15132]: time="2026-02-18T07:07:27+07:00" level=debug msg="completed keyexchange" Feb 18 07:07:27 volumio go-librespot[15132]: time="2026-02-18T07:07:27+07:00" level=debug msg="completed challenge" Feb 18 07:07:27 volumio go-librespot[15132]: time="2026-02-18T07:07:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 07:07:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:07:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:07:27 volumio volumio[14889]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 07:07:27 volumio volumio[14889]: SPOTIFY: BQCWkSjAHH5qHPz7Vv1q1BfL8fb-ivW-MzxWuDO6P9P36BlyLEtuWEpLWmWaE1gaR7SwbDkNuARwQ3lN6fjN8uGF3JDsVpf-eRlfQPWUja6wG6TgcWXN9pcKDtq27EWp4Zs6RFOSv30O8xoJC4O2V5nVb8WCXOBU2bMyBaDGkmibd_G9SwZ-yMgv5QP6F_0oF-xj4ilfI9hfwWnvj7FuLTp0n-0eDpRhWY-IcCaaLaQfWCwZb1KJ_Ymsbv8TXxc4SzoQTvIkzqeKXgnBn2dKrZ_UH0-4wOA0IorNpUkeMeuQ_1ctcTFzTjTI Feb 18 07:07:27 volumio volumio[14889]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 07:07:27 volumio volumio[14889]: info: New Spotify access token = BQCWkSjAHH5qHPz7Vv1q1BfL8fb-ivW-MzxWuDO6P9P36BlyLEtuWEpLWmWaE1gaR7SwbDkNuARwQ3lN6fjN8uGF3JDsVpf-eRlfQPWUja6wG6TgcWXN9pcKDtq27EWp4Zs6RFOSv30O8xoJC4O2V5nVb8WCXOBU2bMyBaDGkmibd_G9SwZ-yMgv5QP6F_0oF-xj4ilfI9hfwWnvj7FuLTp0n-0eDpRhWY-IcCaaLaQfWCwZb1KJ_Ymsbv8TXxc4SzoQTvIkzqeKXgnBn2dKrZ_UH0-4wOA0IorNpUkeMeuQ_1ctcTFzTjTI Feb 18 07:07:27 volumio volumio[14889]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 07:07:27 volumio volumio[14889]: info: Starting Shairport Sync Feb 18 07:07:27 volumio volumio[14889]: info: Starting Shairport Sync Feb 18 07:07:27 volumio volumio[14889]: info: Starting Shairport Sync Feb 18 07:07:27 volumio sudo[15166]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 07:07:27 volumio sudo[15166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:27 volumio sudo[15164]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 07:07:27 volumio sudo[15164]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:27 volumio sudo[15168]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 07:07:27 volumio sudo[15168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:27 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 07:07:27 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 07:07:27 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 07:07:27 volumio systemd[1]: shairport-sync.service: Consumed 2.302s CPU time. Feb 18 07:07:27 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 07:07:27 volumio sudo[15164]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:27 volumio sudo[15166]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:27 volumio volumio[14889]: info: CoreCommandRouter::volumioGetState Feb 18 07:07:27 volumio volumio[14889]: info: CorePlayQueue::getTrack 0 Feb 18 07:07:27 volumio volumio[14889]: info: Shairport-Sync Started Feb 18 07:07:27 volumio volumio[14889]: Error adding Membership: Error: addMembership EINVAL Feb 18 07:07:27 volumio volumio[14889]: info: Shairport-Sync Started Feb 18 07:07:28 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 07:07:28 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 07:07:28 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 07:07:28 volumio volumio[14889]: 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 18 07:07:28 volumio volumio[14889]: info: Spotify Successfully logged in Feb 18 07:07:28 volumio volumio[14889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 07:07:28 volumio volumio[14889]: info: [1771373248084] CoreMusicLibrary::Adding element Spotify Feb 18 07:07:28 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 07:07:28 volumio volumio[14889]: Cannot find translation for source YouTube Music Feb 18 07:07:28 volumio volumio[14889]: Cannot find translation for source Spotify Feb 18 07:07:28 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 07:07:28 volumio sudo[15168]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:28 volumio volumio[14889]: info: Shairport-Sync Started Feb 18 07:07:29 volumio volumio[14889]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 07:07:29 volumio volumio[14889]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 07:07:29 volumio volumio[14889]: info: VolumeController:: Volume=100 Mute =false Feb 18 07:07:29 volumio volumio[14889]: info: CoreCommandRouter::volumioGetState Feb 18 07:07:29 volumio volumio[14889]: info: CorePlayQueue::getTrack 0 Feb 18 07:07:29 volumio volumio[14889]: info: CoreStateMachine::pushState Feb 18 07:07:29 volumio volumio[14889]: info: CorePlayQueue::getTrack 0 Feb 18 07:07:29 volumio volumio[14889]: info: CoreCommandRouter::volumioPushState Feb 18 07:07:30 volumio volumio[14889]: info: go-librespot daemon successfully initialized Feb 18 07:07:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 07:07:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:30 volumio go-librespot[15204]: go-librespot daemon starting... Feb 18 07:07:30 volumio go-librespot[15205]: time="2026-02-18T07:07:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:07:30 volumio go-librespot[15205]: time="2026-02-18T07:07:30+07:00" level=debug msg="app state loaded" Feb 18 07:07:30 volumio go-librespot[15205]: time="2026-02-18T07:07:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:07:30 volumio mpd[15107]: 2026-02-18T07:07:30 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 07:07:30 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 07:07:30 volumio sudo[15067]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:30 volumio sudo[15078]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:31 volumio volumio[14889]: error: MPD error: The expression evaluated to a falsy value: Feb 18 07:07:31 volumio volumio[14889]: assert.ok(self.idling) Feb 18 07:07:31 volumio volumio[14889]: error: The expression evaluated to a falsy value: Feb 18 07:07:31 volumio volumio[14889]: assert.ok(self.idling) Feb 18 07:07:31 volumio volumio[14889]: error: updateQueue error: null Feb 18 07:07:31 volumio volumio[14889]: info: MPD running with PID15107 Feb 18 07:07:31 volumio volumio[14889]: ,establishing connection Feb 18 07:07:31 volumio volumio[14889]: info: Completed starting Core Plugins Feb 18 07:07:31 volumio volumio[14889]: info: ------------------------------------------- Feb 18 07:07:31 volumio volumio[14889]: info: ----- MyVolumio plugins startup ---- Feb 18 07:07:31 volumio volumio[14889]: info: ------------------------------------------- Feb 18 07:07:31 volumio volumio[14889]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 07:07:31 volumio volumio[14889]: error: updateQueue error: null Feb 18 07:07:31 volumio go-librespot[15205]: time="2026-02-18T07:07:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 07:07:31 volumio go-librespot[15205]: time="2026-02-18T07:07:31+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 18 07:07:31 volumio go-librespot[15205]: time="2026-02-18T07:07:31+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 18 07:07:31 volumio go-librespot[15205]: time="2026-02-18T07:07:31+07:00" level=info msg="zeroconf server listening on port 38243" Feb 18 07:07:31 volumio go-librespot[15205]: time="2026-02-18T07:07:31+07:00" level=debug msg="obtained new client token: AAAeae2qaWjrSm6AjnS7qNNAUpWnzr5Crn9M/nZWloc7mt44h6zE+QP3LV1UeUStToVj9grOcG5Zk/ZV0P1piVDMLNkheOqHUR05ArJC+KkXSW1vPjnjdhgRwcs71dEag3VUpEpEONftKrhZa331wdbiANvZvuU0hkoYuzw/p+zV5QjC3Y/xxvQNtCHbZ0ZdaR4GdvTSStOyb5/AoYeVRId30B7jwmQ47HSkUlKQDP70ym/zaBcBaBm8zw==" Feb 18 07:07:31 volumio go-librespot[15205]: time="2026-02-18T07:07:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:07:31 volumio go-librespot[15205]: time="2026-02-18T07:07:31+07:00" level=debug msg="completed keyexchange" Feb 18 07:07:31 volumio go-librespot[15205]: time="2026-02-18T07:07:31+07:00" level=debug msg="completed challenge" Feb 18 07:07:31 volumio go-librespot[15205]: time="2026-02-18T07:07:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 07:07:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:07:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:07:33 volumio volumio[14889]: info: Initializing connection to go-librespot Websocket Feb 18 07:07:33 volumio volumio[14889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 07:07:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 07:07:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:35 volumio go-librespot[15216]: go-librespot daemon starting... Feb 18 07:07:35 volumio go-librespot[15217]: time="2026-02-18T07:07:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:07:35 volumio go-librespot[15217]: time="2026-02-18T07:07:35+07:00" level=debug msg="app state loaded" Feb 18 07:07:35 volumio go-librespot[15217]: time="2026-02-18T07:07:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:07:35 volumio go-librespot[15217]: time="2026-02-18T07:07:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 07:07:35 volumio go-librespot[15217]: time="2026-02-18T07:07:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 07:07:35 volumio go-librespot[15217]: time="2026-02-18T07:07:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 07:07:35 volumio go-librespot[15217]: time="2026-02-18T07:07:35+07:00" level=info msg="zeroconf server listening on port 42331" Feb 18 07:07:35 volumio go-librespot[15217]: time="2026-02-18T07:07:35+07:00" level=debug msg="obtained new client token: AAAYVYP9MIs+LRR4JLJsFMoqpXIfynbpgqQQtRlodltx5yTHy7tdnK8kIQTwmiddLEGNiGqLQliU9deDGl5wFC3821dP1W/AqqOQCLcEpwRbXOFM2tRDzED3op0/ObpnYhJSk7hUJWjdB8iMD4izpXxmIuExV84tclgE9w91POowj8Y3puVYy7RLNMrpZR7VactlFfwmL36wy7TjPHemor2eKQbURaV9TempWvfkqKCPgtXnhVn7cmhzBg==" Feb 18 07:07:35 volumio volumio[14889]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 07:07:35 volumio go-librespot[15217]: time="2026-02-18T07:07:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:07:36 volumio go-librespot[15217]: time="2026-02-18T07:07:36+07:00" level=debug msg="completed keyexchange" Feb 18 07:07:36 volumio go-librespot[15217]: time="2026-02-18T07:07:36+07:00" level=debug msg="completed challenge" Feb 18 07:07:36 volumio go-librespot[15217]: time="2026-02-18T07:07:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 07:07:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:07:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:07:36 volumio volumio[14889]: info: Initializing connection to go-librespot Websocket Feb 18 07:07:36 volumio volumio[14889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 07:07:39 volumio volumio[14889]: info: Initializing connection to go-librespot Websocket Feb 18 07:07:39 volumio volumio[14889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 07:07:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 07:07:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:39 volumio go-librespot[15225]: go-librespot daemon starting... Feb 18 07:07:39 volumio go-librespot[15226]: time="2026-02-18T07:07:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:07:39 volumio go-librespot[15226]: time="2026-02-18T07:07:39+07:00" level=debug msg="app state loaded" Feb 18 07:07:39 volumio go-librespot[15226]: time="2026-02-18T07:07:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 07:07:39 volumio volumio[14889]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 07:07:39 volumio volumio[14889]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 07:07:39 volumio volumio[14889]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 07:07:39 volumio volumio[14889]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 07:07:39 volumio volumio[14889]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 07:07:39 volumio volumio[14889]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 07:07:39 volumio volumio[14889]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 07:07:39 volumio go-librespot[15226]: time="2026-02-18T07:07:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 07:07:39 volumio go-librespot[15226]: time="2026-02-18T07:07:39+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 18 07:07:39 volumio go-librespot[15226]: time="2026-02-18T07:07:39+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 18 07:07:39 volumio go-librespot[15226]: time="2026-02-18T07:07:39+07:00" level=info msg="zeroconf server listening on port 46251" Feb 18 07:07:40 volumio go-librespot[15226]: time="2026-02-18T07:07:40+07:00" level=debug msg="obtained new client token: AAAthpee957eIsQJHBRKQaZZp8ABvAXXP4g+3zdbCabLvkK0dSYF3zLdhxVEXm7ivc9cHGIDWN1TfIs3LzDw22WW671Nv3+BqP2Gu5TmBaiuavjM0GubXpzstfc1I1h6558Zhk01CEIf7FK11/fD3NddljVB4ObutIMpuoYofmgm0LIiEJvoodfcE/Yg6n999UESXMqj2M7f+t5oHTlQF2sGqZlBlcPCMhChG6VLQ/XA27LaTwboY2A=" Feb 18 07:07:40 volumio go-librespot[15226]: time="2026-02-18T07:07:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:07:40 volumio go-librespot[15226]: time="2026-02-18T07:07:40+07:00" level=debug msg="completed keyexchange" Feb 18 07:07:40 volumio go-librespot[15226]: time="2026-02-18T07:07:40+07:00" level=debug msg="completed challenge" Feb 18 07:07:40 volumio go-librespot[15226]: time="2026-02-18T07:07:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 07:07:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:07:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:07:41 volumio volumio[14889]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 07:07:41 volumio volumio[14889]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 07:07:41 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:07:41 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:07:41 volumio volumio[14889]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 07:07:41 volumio volumio[14889]: info: MyVolumio login type: Token Feb 18 07:07:41 volumio volumio[14889]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 07:07:41 volumio volumio[14889]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 07:07:43 volumio volumio[14889]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 07:07:43 volumio volumio[14889]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 07:07:43 volumio volumio[14889]: info: Streaming services startup Feb 18 07:07:43 volumio volumio[14889]: info: Starting Streaming Daemon Feb 18 07:07:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 07:07:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:43 volumio sudo[15249]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 07:07:43 volumio volumio[14889]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 07:07:43 volumio sudo[15249]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:43 volumio go-librespot[15251]: go-librespot daemon starting... Feb 18 07:07:43 volumio sudo[15249]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:43 volumio go-librespot[15256]: time="2026-02-18T07:07:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:07:43 volumio go-librespot[15256]: time="2026-02-18T07:07:43+07:00" level=debug msg="app state loaded" Feb 18 07:07:43 volumio go-librespot[15256]: time="2026-02-18T07:07:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:07:43 volumio volumio[14889]: info: Initializing connection to go-librespot Websocket Feb 18 07:07:43 volumio volumio[14889]: error: Cannot start Volumio Streaming Daemon Feb 18 07:07:43 volumio volumio[14889]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 07:07:43 volumio volumio[14889]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 07:07:43 volumio go-librespot[15256]: time="2026-02-18T07:07:43+07:00" level=debug msg="new websocket client" Feb 18 07:07:43 volumio volumio[14889]: info: Connection to go-librespot Websocket established Feb 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+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 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+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 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+07:00" level=info msg="zeroconf server listening on port 40163" Feb 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+07:00" level=debug msg="obtained new client token: AAAadyoIhvfbc3pDe9x1PrCDdyNCbITSQPuwPLBZy1Cvf+JnJ4B5T8/4IbASBNQQLeU8z+OzzFykZJI1jBPdFpEzRuKkwWTfGMqZOoXWfb4jHPzj1ACMvAPTwFAABUVoZcC0uOzWKZetJQIpf/sOGEIUmzoz48D3gowSkE5swXmWt3kzn/AkGBheH4KAbeg1JJyK27Q+Mt8VmrMrAk5g0WXQfnn0qTB1lGjHbMT0ph0QkOIFQ8zz1M0+aQ==" Feb 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+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 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 07:07:44 volumio volumio[14889]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+07:00" level=debug msg="completed keyexchange" Feb 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+07:00" level=debug msg="completed challenge" Feb 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 07:07:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:07:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:07:44 volumio volumio[14889]: info: Connection to go-librespot Websocket closed Feb 18 07:07:45 volumio volumio[14889]: info: MyVolumio token set successfully Feb 18 07:07:45 volumio volumio[14889]: info: MYVOLUMIO: Adding device Feb 18 07:07:45 volumio volumio[14889]: info: MYVOLUMIO: Evaluating Server Feb 18 07:07:46 volumio volumio[14889]: info: MyVolumio status changed Feb 18 07:07:46 volumio volumio[14889]: info: Streaming services startup Feb 18 07:07:46 volumio volumio[14889]: info: Starting Streaming Daemon Feb 18 07:07:46 volumio volumio[14889]: info: Removing browser output: myVolumio user plan is not superstar Feb 18 07:07:46 volumio volumio[14889]: info: Removing audio output: Feb 18 07:07:46 volumio volumio[14889]: info: Stoppping Tunnel 1 Feb 18 07:07:46 volumio sudo[15284]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 07:07:46 volumio sudo[15284]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:46 volumio sudo[15284]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:46 volumio sudo[15287]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 18 07:07:46 volumio volumio[14889]: error: Cannot start Volumio Streaming Daemon Feb 18 07:07:46 volumio volumio[14889]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 07:07:46 volumio volumio[14889]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 07:07:46 volumio sudo[15287]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:46 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 07:07:46 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 07:07:46 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 07:07:46 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 07:07:46 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 07:07:46 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 07:07:46 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 07:07:46 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 07:07:46 volumio volumio[14889]: info: Setting Geolocation for MyVolumio to as1 Feb 18 07:07:46 volumio sudo[15287]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:46 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:07:46 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:07:46 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:07:46 volumio volumio[14889]: info: Remote SSH Stopped Feb 18 07:07:46 volumio volumio[14889]: info: Getting Spotify volume Feb 18 07:07:46 volumio volumio[14889]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 07:07:46 volumio volumio[14889]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 07:07:46 volumio volumio[14889]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 07:07:46 volumio volumio[14889]: errno: -111, Feb 18 07:07:46 volumio volumio[14889]: code: 'ECONNREFUSED', Feb 18 07:07:46 volumio volumio[14889]: syscall: 'connect', Feb 18 07:07:46 volumio volumio[14889]: address: '127.0.0.1', Feb 18 07:07:46 volumio volumio[14889]: port: 9879, Feb 18 07:07:46 volumio volumio[14889]: response: undefined Feb 18 07:07:46 volumio volumio[14889]: } Feb 18 07:07:46 volumio volumio[14889]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 07:07:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 07:07:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:47 volumio go-librespot[15301]: go-librespot daemon starting... Feb 18 07:07:47 volumio go-librespot[15302]: time="2026-02-18T07:07:47+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:07:47 volumio go-librespot[15302]: time="2026-02-18T07:07:47+07:00" level=debug msg="app state loaded" Feb 18 07:07:47 volumio go-librespot[15302]: time="2026-02-18T07:07:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:07:48 volumio sudo[15311]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 07:06' Feb 18 07:07:48 volumio sudo[15311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:48 volumio go-librespot[15302]: time="2026-02-18T07:07:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 07:07:48 volumio go-librespot[15302]: time="2026-02-18T07:07:48+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 18 07:07:48 volumio go-librespot[15302]: time="2026-02-18T07:07:48+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 18 07:07:48 volumio go-librespot[15302]: time="2026-02-18T07:07:48+07:00" level=info msg="zeroconf server listening on port 45245" Feb 18 07:07:48 volumio go-librespot[15302]: time="2026-02-18T07:07:48+07:00" level=debug msg="obtained new client token: AACG4b3YMp2CA6doNCjMHaVBS7SMjyLjn90mTUfq6d92FDm66NxsVUZJxBp+5lykyijqPIQOgtQI1eg++Wlo6vH7MnH0o8apCfdP5GH6RlPwKvWH3pWsWxdNNL+E1NDxWFX9sqUbkmklz+ePZDC/Za3rAOc87cAWN+AKcQVm+69Fcu6I9QWSwuIhLzRHt+HLGbXbYMNNp4JhezV0RWdH2pgCDoWCVHTLODpGa/pGRiXhbaSLy//BlZKs8Q==" Feb 18 07:07:48 volumio sudo[15311]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:48 volumio go-librespot[15302]: time="2026-02-18T07:07:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:07:48 volumio go-librespot[15302]: time="2026-02-18T07:07:48+07:00" level=debug msg="completed keyexchange" Feb 18 07:07:48 volumio go-librespot[15302]: time="2026-02-18T07:07:48+07:00" level=debug msg="completed challenge" Feb 18 07:07:48 volumio go-librespot[15302]: time="2026-02-18T07:07:48+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 18 07:07:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:07:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:07:50 volumio volumio-remote-updater[25144]: [2026-02-18 07:07:50] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 18 07:07:50 volumio volumio-remote-updater[25144]: [2026-02-18 07:07:50] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 18 07:07:50 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:07:50 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 07:07:50 volumio systemd[1]: volumio.service: Consumed 57.113s CPU time. Feb 18 07:07:50 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 07:07:50 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 07:07:50 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 21543. Feb 18 07:07:50 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 07:07:50 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 07:07:50 volumio systemd[1]: volumio.service: Consumed 57.113s CPU time. Feb 18 07:07:50 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 07:07:50 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 07:07:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 07:07:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:52 volumio go-librespot[15347]: go-librespot daemon starting... Feb 18 07:07:52 volumio go-librespot[15348]: time="2026-02-18T07:07:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:07:52 volumio go-librespot[15348]: time="2026-02-18T07:07:52+07:00" level=debug msg="app state loaded" Feb 18 07:07:52 volumio go-librespot[15348]: time="2026-02-18T07:07:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:07:52 volumio go-librespot[15348]: time="2026-02-18T07:07:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 07:07:52 volumio go-librespot[15348]: time="2026-02-18T07:07:52+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 18 07:07:52 volumio go-librespot[15348]: time="2026-02-18T07:07:52+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 18 07:07:52 volumio go-librespot[15348]: time="2026-02-18T07:07:52+07:00" level=info msg="zeroconf server listening on port 45765" Feb 18 07:07:53 volumio go-librespot[15348]: time="2026-02-18T07:07:53+07:00" level=debug msg="obtained new client token: AADR3nV5tMIMID8OYZYKiSHd+IxldEBlK+JxliE3rSSTmBKNbgUGbjA2Agzlz8VvoFKSRBIF2HIUyJBc4OuO1FXNn7JyuIct+i79kDv31G0+Oy9+s3Mid3YFYfpIlJD4LMsRujJOC30AHkkAERl9+fzCD7B/sG0Odu52Hfk4U2qtOS4Pl8cIUmx4xy12gurHfMjCpmZtIqXZl5S/Xg8ZJsb0NJQcQUx3Th0Qrr0bAES2ci5LBIwfp2MIwQ==" Feb 18 07:07:53 volumio go-librespot[15348]: time="2026-02-18T07:07:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:07:53 volumio go-librespot[15348]: time="2026-02-18T07:07:53+07:00" level=debug msg="completed keyexchange" Feb 18 07:07:53 volumio go-librespot[15348]: time="2026-02-18T07:07:53+07:00" level=debug msg="completed challenge" Feb 18 07:07:53 volumio go-librespot[15348]: time="2026-02-18T07:07:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 07:07:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:07:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:07:53 volumio volumio[15332]: info: ------------------------------------------- Feb 18 07:07:53 volumio volumio[15332]: info: ----- Volumio3 ---- Feb 18 07:07:53 volumio volumio[15332]: info: ------------------------------------------- Feb 18 07:07:53 volumio volumio[15332]: info: ----- System startup ---- Feb 18 07:07:53 volumio volumio[15332]: info: ------------------------------------------- Feb 18 07:07:55 volumio volumio-remote-updater[25144]: [2026-02-18 07:07:55] [connect] Successful connection Feb 18 07:07:55 volumio volumio[15332]: info: MYVOLUMIO Environment detected Feb 18 07:07:55 volumio volumio[15332]: info: Plugin folders cleanup Feb 18 07:07:55 volumio volumio[15332]: info: Scanning into folder /volumio/app/plugins/ Feb 18 07:07:55 volumio volumio[15332]: info: Scanning category audio_interface Feb 18 07:07:55 volumio volumio[15332]: info: Scanning category miscellanea Feb 18 07:07:55 volumio volumio[15332]: info: Scanning category music_service Feb 18 07:07:55 volumio volumio[15332]: info: Scanning category plugins.json Feb 18 07:07:55 volumio volumio[15332]: info: Scanning category system_controller Feb 18 07:07:55 volumio volumio[15332]: info: Scanning category user_interface Feb 18 07:07:55 volumio volumio[15332]: info: Scanning into folder /data/plugins/ Feb 18 07:07:55 volumio volumio[15332]: info: Scanning category music_service Feb 18 07:07:55 volumio volumio[15332]: info: Plugin folders cleanup completed Feb 18 07:07:55 volumio volumio[15332]: info: ------------------------------------------- Feb 18 07:07:55 volumio volumio[15332]: info: ----- Core plugins startup ---- Feb 18 07:07:55 volumio volumio[15332]: info: ------------------------------------------- Feb 18 07:07:55 volumio volumio[15332]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 07:07:55 volumio volumio[15332]: info: Adding plugin upnp to MyMusic Plugins Feb 18 07:07:55 volumio volumio[15332]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 07:07:55 volumio volumio[15332]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 07:07:55 volumio volumio[15332]: info: Loading plugins from folder /data/plugins/ Feb 18 07:07:55 volumio volumio[15332]: info: Loading plugin "system"... Feb 18 07:07:55 volumio volumio[15332]: info: Loading plugin "appearance"... Feb 18 07:07:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 07:07:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:07:56 volumio go-librespot[15368]: go-librespot daemon starting... Feb 18 07:07:56 volumio go-librespot[15369]: time="2026-02-18T07:07:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:07:56 volumio go-librespot[15369]: time="2026-02-18T07:07:56+07:00" level=debug msg="app state loaded" Feb 18 07:07:56 volumio go-librespot[15369]: time="2026-02-18T07:07:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:07:57 volumio go-librespot[15369]: time="2026-02-18T07:07:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 07:07:57 volumio go-librespot[15369]: time="2026-02-18T07:07:57+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 18 07:07:57 volumio go-librespot[15369]: time="2026-02-18T07:07:57+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 18 07:07:57 volumio go-librespot[15369]: time="2026-02-18T07:07:57+07:00" level=info msg="zeroconf server listening on port 46555" Feb 18 07:07:57 volumio volumio[15332]: info: Loading plugin "network"... Feb 18 07:07:57 volumio volumio[15332]: info: Refreshing Cached IP Addresses Feb 18 07:07:57 volumio sudo[15377]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 07:07:57 volumio sudo[15377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:57 volumio sudo[15379]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 07:07:57 volumio volumio[15332]: info: Loading plugin "services"... Feb 18 07:07:57 volumio go-librespot[15369]: time="2026-02-18T07:07:57+07:00" level=debug msg="obtained new client token: AAA1DUOjbzBingKz1tL74sGU82puQn0Lbs4S7gZfk0heszjrsrR53AsTSTDEDCzOr9r7+vatgqr7Vterqxe0/XP/jhUAsEJMErI9BL94cJm3+KWz0XiUzOF+kbJzAxO6KzNYt6DO7IA3SWQpPMBQp4EYt+/wORdw2ZP6G3QHiWIO+JyJ2gQkuILahtjwKthA8YLnc+DcN3axFiKXWgUhU0nSTCoF6dDyvtEc7GSDf+NCBxa6+h4UXopjTw==" Feb 18 07:07:57 volumio sudo[15379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:57 volumio volumio[15332]: info: Loading plugin "alsa_controller"... Feb 18 07:07:57 volumio sudo[15377]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:57 volumio sudo[15379]: pam_unix(sudo:session): session closed for user root Feb 18 07:07:57 volumio sudo[15387]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 07:07:57 volumio sudo[15387]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:07:57 volumio go-librespot[15369]: time="2026-02-18T07:07:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:07:57 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 07:07:57 volumio volumio[15332]: info: Loading plugin "wizard"... Feb 18 07:07:57 volumio volumio[15332]: info: Loading plugin "networkfs"... Feb 18 07:07:57 volumio volumio[15332]: info: Starting Udev Watcher for removable devices Feb 18 07:07:57 volumio go-librespot[15369]: time="2026-02-18T07:07:57+07:00" level=debug msg="completed keyexchange" Feb 18 07:07:57 volumio go-librespot[15369]: time="2026-02-18T07:07:57+07:00" level=debug msg="completed challenge" Feb 18 07:07:57 volumio volumio[15332]: info: Ignoring mount for partition: boot Feb 18 07:07:57 volumio volumio[15332]: info: Ignoring mount for partition: volumio Feb 18 07:07:57 volumio volumio[15332]: info: Ignoring mount for partition: volumio_data Feb 18 07:07:57 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 07:07:57 volumio volumio[15332]: info: Loading plugin "volumio_command_line_client"... Feb 18 07:07:57 volumio volumio[15332]: info: Loading plugin "upnp"... Feb 18 07:07:57 volumio volumio[15332]: info: [1771373277875] Starting Upmpd Daemon Feb 18 07:07:57 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 07:07:57 volumio volumio[15332]: info: Loading plugin "my_music"... Feb 18 07:07:57 volumio volumio[15332]: info: Loading plugin "mpd"... Feb 18 07:07:57 volumio go-librespot[15369]: time="2026-02-18T07:07:57+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 18 07:07:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:07:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:07:58 volumio volumio[15332]: info: Loading plugin "upnp_browser"... Feb 18 07:08:00 volumio sudo[15387]: pam_unix(sudo:session): session closed for user root Feb 18 07:08:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 07:08:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:08:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:08:01 volumio go-librespot[15411]: go-librespot daemon starting... Feb 18 07:08:01 volumio go-librespot[15412]: time="2026-02-18T07:08:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:08:01 volumio go-librespot[15412]: time="2026-02-18T07:08:01+07:00" level=debug msg="app state loaded" Feb 18 07:08:01 volumio go-librespot[15412]: time="2026-02-18T07:08:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:08:01 volumio volumio[15332]: info: Starting UPNP Browser Feb 18 07:08:01 volumio volumio[15332]: info: Loading plugin "alarm-clock"... Feb 18 07:08:01 volumio go-librespot[15412]: time="2026-02-18T07: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 07:08:01 volumio go-librespot[15412]: time="2026-02-18T07:08:01+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 18 07:08:01 volumio go-librespot[15412]: time="2026-02-18T07:08:01+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 18 07:08:01 volumio go-librespot[15412]: time="2026-02-18T07:08:01+07:00" level=info msg="zeroconf server listening on port 46301" Feb 18 07:08:01 volumio volumio[15332]: info: Loading plugin "airplay_emulation"... Feb 18 07:08:01 volumio volumio[15332]: info: Starting Shairport Sync Feb 18 07:08:01 volumio volumio[15332]: info: Loading plugin "last_100"... Feb 18 07:08:01 volumio volumio[15332]: info: Loading plugin "webradio"... Feb 18 07:08:01 volumio go-librespot[15412]: time="2026-02-18T07:08:01+07:00" level=debug msg="obtained new client token: AAC5MVTXeo21b105b0AtReVocYHqrIlXL0rIlVEX5GMYc45GwolC1UDfod2XVb3MGpJKsFUmOHltngYKAdnq3IV7J1A47NjG6uxiYFV2TleXc59cAyidIn+zmEIDE1b9FNmuwknbYoQuJTrK4PHAgNdIubUcoIfgEPCbe3vaKqmbMApkC9TiVz0xt/TkhgHIdiEetIRgameWUN4roNryUG6N20X/35pJ43mbJYkX6rz5Xau10AKM6aLt1g==" Feb 18 07:08:02 volumio volumio[15332]: info: Loading plugin "i2s_dacs"... Feb 18 07:08:02 volumio go-librespot[15412]: time="2026-02-18T07:08:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:08:02 volumio volumio[15332]: info: Loading plugin "volumiodiscovery"... Feb 18 07:08:02 volumio volumio[15332]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 07:08:02 volumio volumio[15332]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 07:08:02 volumio volumio[15332]: *** WARNING *** For more information see Feb 18 07:08:02 volumio volumio[15332]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 07:08:02 volumio volumio[15332]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 07:08:02 volumio volumio[15332]: *** WARNING *** For more information see Feb 18 07:08:02 volumio node[15332]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 07:08:02 volumio node[15332]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 07:08:02 volumio node[15332]: *** WARNING *** For more information see Feb 18 07:08:02 volumio node[15332]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 07:08:02 volumio node[15332]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 07:08:02 volumio node[15332]: *** WARNING *** For more information see Feb 18 07:08:02 volumio volumio[15332]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 07:08:02 volumio volumio[15332]: info: Discovery: Started advertising with name: Volumio Feb 18 07:08:02 volumio go-librespot[15412]: time="2026-02-18T07:08:02+07:00" level=debug msg="completed keyexchange" Feb 18 07:08:02 volumio go-librespot[15412]: time="2026-02-18T07:08:02+07:00" level=debug msg="completed challenge" Feb 18 07:08:02 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 07:08:02 volumio volumio[15332]: info: Loading plugin "spop"... Feb 18 07:08:02 volumio go-librespot[15412]: time="2026-02-18T07: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 18 07:08:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:08:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:08:04 volumio volumio[15332]: info: Loading plugin "ytcr"... Feb 18 07:08:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 07:08:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:08:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:08:05 volumio go-librespot[15422]: go-librespot daemon starting... Feb 18 07:08:05 volumio go-librespot[15423]: time="2026-02-18T07:08:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:08:05 volumio go-librespot[15423]: time="2026-02-18T07:08:05+07:00" level=debug msg="app state loaded" Feb 18 07:08:05 volumio go-librespot[15423]: time="2026-02-18T07:08:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:08:05 volumio go-librespot[15423]: time="2026-02-18T07: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 07:08:05 volumio go-librespot[15423]: time="2026-02-18T07:08: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 18 07:08:05 volumio go-librespot[15423]: time="2026-02-18T07:08: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 18 07:08:05 volumio go-librespot[15423]: time="2026-02-18T07:08:05+07:00" level=info msg="zeroconf server listening on port 39725" Feb 18 07:08:06 volumio go-librespot[15423]: time="2026-02-18T07:08:06+07:00" level=debug msg="obtained new client token: AAB47ocNC+n9AEPMcP8gPp7Mp8lloeuWoR8jimkNUrozbAx2YSWyfYk09n26sGSF7ReqizSZCNr+kcUGXrqmcEh04y6yjWl+ILL5lDVHjGxOVxL2sskMhron78GRzsi87mhZ5alwVNMQUWXh0MEVfogcor17c6H84FTzVcfa96QQJsudmbTOoXQApljKhMLrqq/Fcr2kSLwySONJmZrcGxitkyS3HBylAULtzSMoaTk4sZaH76EkfpM=" Feb 18 07:08:06 volumio go-librespot[15423]: time="2026-02-18T07:08:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:08:06 volumio go-librespot[15423]: time="2026-02-18T07:08:06+07:00" level=debug msg="completed keyexchange" Feb 18 07:08:06 volumio go-librespot[15423]: time="2026-02-18T07:08:06+07:00" level=debug msg="completed challenge" Feb 18 07:08:06 volumio go-librespot[15423]: time="2026-02-18T07: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 18 07:08:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:08:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:08:06 volumio volumio[15332]: info: Loading plugin "ytmusic"... Feb 18 07:08:07 volumio volumio-remote-updater[25144]: [2026-02-18 07:08:07] [connect] Successful connection Feb 18 07:08:07 volumio volumio[15332]: info: Loading plugin "outputs"... Feb 18 07:08:07 volumio volumio[15332]: info: Loading plugin "albumart"... Feb 18 07:08:07 volumio volumio[15332]: info: Plugin example_plugin is not enabled Feb 18 07:08:07 volumio volumio[15332]: info: Loading plugin "inputs"... Feb 18 07:08:07 volumio volumio[15332]: info: Loading plugin "updater_comm"... Feb 18 07:08:07 volumio volumio[15332]: info: Plugin mpdemulation is not enabled Feb 18 07:08:07 volumio volumio[15332]: info: Loading plugin "rest_api"... Feb 18 07:08:08 volumio volumio[15332]: info: Loading plugin "websocket"... Feb 18 07:08:08 volumio volumio[15332]: info: Starting Socket.io Server version 1.7.4 Feb 18 07:08:08 volumio volumio[15332]: info: Loading plugin "RoonBridge"... Feb 18 07:08:08 volumio volumio[15332]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 07:08:08 volumio volumio[15332]: info: Loading i18n strings for locale en Feb 18 07:08:08 volumio volumio[15332]: Updating browse sources language Feb 18 07:08:08 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 07:08:08 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 07:08:08 volumio volumio[15332]: info: CoreCommandRouter::initPlayerControls Feb 18 07:08:08 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:08 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:08 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:08 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:08 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:08 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:08 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:08 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:08 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 07:08:08 volumio volumio[15332]: Express server listening on port 3000 Feb 18 07:08:08 volumio volumio[15332]: [Metrics] WebUI: 15s 899.00ms Feb 18 07:08:08 volumio volumio[15444]: Forking 3 albumart workers Feb 18 07:08:08 volumio volumio[15332]: info: CoreStateMachine::resetVolumioState Feb 18 07:08:08 volumio volumio[15332]: info: CoreStateMachine::getcurrentVolume Feb 18 07:08:08 volumio volumio[15332]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 07:08:09 volumio sudo[15469]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 07:08:09 volumio sudo[15469]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:08:09 volumio sudo[15478]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 07:08:09 volumio sudo[15478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:08:09 volumio sudo[15469]: pam_unix(sudo:session): session closed for user root Feb 18 07:08:09 volumio sudo[15478]: pam_unix(sudo:session): session closed for user root Feb 18 07:08:09 volumio volumio[15332]: info: Volumio Network Manager: Network status updated: 1 Feb 18 07:08:09 volumio volumio[15332]: info: VolumeController:: Volume=100 Mute =false Feb 18 07:08:09 volumio volumio[15332]: info: CoreStateMachine::pushState Feb 18 07:08:09 volumio volumio[15332]: info: CorePlayQueue::getTrack 0 Feb 18 07:08:09 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 07:08:09 volumio volumio[15332]: info: CoreCommandRouter::volumioPushState Feb 18 07:08:09 volumio volumio[15332]: info: CoreStateMachine::updateTrackBlock Feb 18 07:08:09 volumio volumio[15332]: info: CorePlayQueue::getTrackBlock Feb 18 07:08:09 volumio volumio[15332]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 07:08:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 07:08:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:08:09 volumio volumio-remote-updater[25144]: [2026-02-18 07:08:09] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771373287 101 Feb 18 07:08:09 volumio volumio[15332]: 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 18 07:08:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:08:09 volumio go-librespot[15497]: go-librespot daemon starting... Feb 18 07:08:09 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:08:09 volumio volumio[15332]: info: Reloading queue from file Feb 18 07:08:09 volumio go-librespot[15499]: time="2026-02-18T07:08:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:08:09 volumio go-librespot[15499]: time="2026-02-18T07:08:09+07:00" level=debug msg="app state loaded" Feb 18 07:08:09 volumio go-librespot[15499]: time="2026-02-18T07:08:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:08:09 volumio volumio[15332]: info: CoreStateMachine::setRepeat null single undefined Feb 18 07:08:09 volumio volumio[15332]: info: CoreStateMachine::pushState Feb 18 07:08:09 volumio volumio[15332]: info: CorePlayQueue::getTrack 0 Feb 18 07:08:09 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 07:08:09 volumio volumio[15332]: info: CoreCommandRouter::volumioPushState Feb 18 07:08:09 volumio volumio[15332]: info: CoreStateMachine::setRandom null Feb 18 07:08:09 volumio volumio[15332]: info: CoreStateMachine::pushState Feb 18 07:08:09 volumio volumio[15332]: info: CorePlayQueue::getTrack 0 Feb 18 07:08:09 volumio volumio[15332]: info: CoreCommandRouter::volumioPushState Feb 18 07:08:09 volumio volumio[15332]: info: Setting Device type: Raspberry PI Feb 18 07:08:09 volumio volumio[15332]: info: Completed loading Core Plugins Feb 18 07:08:09 volumio volumio[15332]: info: Preparing to generate the ALSA configuration file Feb 18 07:08:10 volumio volumio[15332]: info: VolumeController:: Volume=100 Mute =false Feb 18 07:08:10 volumio volumio[15332]: info: CoreStateMachine::pushState Feb 18 07:08:10 volumio volumio[15332]: info: CorePlayQueue::getTrack 0 Feb 18 07:08:10 volumio volumio[15332]: info: CoreCommandRouter::volumioPushState Feb 18 07:08:10 volumio volumio[15332]: info: Asound.conf file unchanged, so no further update is needed Feb 18 07:08:10 volumio volumio[15332]: info: Output device has changed, restarting MPD Feb 18 07:08:10 volumio volumio[15332]: info: Output device has changed, restarting Shairport Sync Feb 18 07:08:10 volumio sudo[15514]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 07:08:10 volumio sudo[15514]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:08:10 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:10 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:08:10 volumio volumio[15332]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 07:08:10 volumio volumio[15332]: info: ___________ START PLUGINS ___________ Feb 18 07:08:10 volumio sudo[15516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 07:08:10 volumio go-librespot[15499]: time="2026-02-18T07: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 07:08:10 volumio go-librespot[15499]: time="2026-02-18T07:08:10+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 18 07:08:10 volumio go-librespot[15499]: time="2026-02-18T07:08:10+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 18 07:08:10 volumio sudo[15516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:08:10 volumio sudo[15514]: pam_unix(sudo:session): session closed for user root Feb 18 07:08:10 volumio volumio[15332]: info: ControllerMpd::onStart: Initializing MPD Feb 18 07:08:10 volumio volumio[15332]: info: Creating MPD Configuration file Feb 18 07:08:10 volumio sudo[15518]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 07:08:10 volumio sudo[15518]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:08:10 volumio go-librespot[15499]: time="2026-02-18T07:08:10+07:00" level=info msg="zeroconf server listening on port 46633" Feb 18 07:08:10 volumio sudo[15516]: pam_unix(sudo:session): session closed for user root Feb 18 07:08:10 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 07:08:10 volumio sudo[15527]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 07:08:10 volumio sudo[15527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:08:10 volumio sudo[15529]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 07:08:10 volumio sudo[15527]: pam_unix(sudo:session): session closed for user root Feb 18 07:08:10 volumio sudo[15529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:08:10 volumio volumio[15332]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 07:08:10 volumio volumio[15332]: info: [1771373290539] CoreMusicLibrary::Adding element Media Servers Feb 18 07:08:10 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 07:08:10 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 07:08:10 volumio volumio[15332]: info: UPNP Browser: Client initialized successfully Feb 18 07:08:10 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 07:08:10 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 07:08:10 volumio systemd[1]: mpd.service: Consumed 7.271s CPU time. Feb 18 07:08:10 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 07:08:10 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 07:08:10 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 07:08:10 volumio go-librespot[15499]: time="2026-02-18T07:08:10+07:00" level=debug msg="obtained new client token: AAAOZHs3LSQcy9YouBRfGtOuPXHCHpFev6w3ImCArwvvjH3CY+xgUBvexyqYw5FM9TYT8imU2qbS9Wtu5m4Zq3qYzj9wf8bfNIjGUpM82nirgANqFMYFnpNBgqOEwBimGcW7yBK0rMtr3/bCaSnyZnEQ4pTmzNlxUXMmChMDxRszSwjAUypWGTXQGjyFYQYryNqf5Vnp1aWIkD75qd3oedsn7DdADd7ojZZLEqsD9WU+KXS/akW4YQmtYw==" Feb 18 07:08:10 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:10 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:08:10 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 07:08:10 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 07:08:10 volumio go-librespot[15499]: time="2026-02-18T07:08:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:08:10 volumio volumio[15332]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 07:08:10 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:10 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:08:10 volumio volumio[15332]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 07:08:10 volumio volumio[15332]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 07:08:10 volumio volumio[15332]: info: [1771373290968] CoreMusicLibrary::Adding element Last_100 Feb 18 07:08:10 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 07:08:10 volumio volumio[15332]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 07:08:10 volumio volumio[15332]: info: [1771373290984] CoreMusicLibrary::Adding element Webradio Feb 18 07:08:10 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 07:08:10 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 07:08:11 volumio go-librespot[15499]: time="2026-02-18T07:08:11+07:00" level=debug msg="completed keyexchange" Feb 18 07:08:11 volumio volumio[15332]: info: Initializing BBC Radios Feb 18 07:08:11 volumio go-librespot[15499]: time="2026-02-18T07:08:11+07:00" level=debug msg="completed challenge" Feb 18 07:08:11 volumio go-librespot[15499]: time="2026-02-18T07:08:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 07:08:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:08:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:08:11 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 07:08:11 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:08:11 volumio volumio[15332]: info: Creating Spotify config file Feb 18 07:08:11 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:11 volumio sudo[15537]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 07:08:11 volumio sudo[15537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 07:08:11 volumio sudo[15537]: pam_unix(sudo:session): session closed for user root Feb 18 07:08:12 volumio volumio[15458]: Starting albumart workers Feb 18 07:08:12 volumio volumio[15332]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 07:08:12 volumio volumio[15332]: info: [1771373292443] CoreMusicLibrary::Adding element YouTube Music Feb 18 07:08:12 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 07:08:12 volumio volumio[15332]: Cannot find translation for source YouTube Music Feb 18 07:08:12 volumio volumio[15332]: info: Volumio Calling Home Feb 18 07:08:12 volumio volumio[15459]: Starting albumart workers Feb 18 07:08:12 volumio volumio[15457]: Starting albumart workers Feb 18 07:08:12 volumio sudo[15558]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 07:08:12 volumio sudo[15558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:08:12 volumio sudo[15558]: pam_unix(sudo:session): session closed for user root Feb 18 07:08:13 volumio volumio[15332]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 07:08:13 volumio volumio[15332]: info: Discovery: Found device Volumio Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::volumioGetState Feb 18 07:08:13 volumio volumio[15332]: info: CorePlayQueue::getTrack 0 Feb 18 07:08:13 volumio volumio[15332]: info: MPD Permissions set Feb 18 07:08:13 volumio volumio[15332]: info: MPD Permissions set Feb 18 07:08:13 volumio volumio[15332]: info: Upmpdcli Daemon Started Feb 18 07:08:13 volumio volumio[15332]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 07:08:13 volumio volumio[15332]: info: Discovery: Found device Volumio Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::volumioGetState Feb 18 07:08:13 volumio volumio[15332]: info: CorePlayQueue::getTrack 0 Feb 18 07:08:13 volumio volumio[15332]: info: Spotify config file written Feb 18 07:08:13 volumio sudo[15565]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 07:08:13 volumio volumio[15332]: 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 18 07:08:13 volumio sudo[15565]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:08:13 volumio volumio[15332]: info: Volumio called home Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:08:13 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 07:08:13 volumio go-librespot[15572]: go-librespot daemon starting... Feb 18 07:08:13 volumio sudo[15565]: pam_unix(sudo:session): session closed for user root Feb 18 07:08:13 volumio volumio[15332]: info: No need to fix Spotify hosts Feb 18 07:08:14 volumio go-librespot[15578]: time="2026-02-18T07:08:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:08:14 volumio go-librespot[15578]: time="2026-02-18T07:08:14+07:00" level=debug msg="app state loaded" Feb 18 07:08:14 volumio go-librespot[15578]: time="2026-02-18T07:08:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:08:14 volumio go-librespot[15578]: time="2026-02-18T07: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 07:08:14 volumio go-librespot[15578]: time="2026-02-18T07:08: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 18 07:08:14 volumio go-librespot[15578]: time="2026-02-18T07:08: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 18 07:08:14 volumio go-librespot[15578]: time="2026-02-18T07:08:14+07:00" level=info msg="zeroconf server listening on port 34035" Feb 18 07:08:14 volumio go-librespot[15578]: time="2026-02-18T07:08:14+07:00" level=debug msg="obtained new client token: AACWppUksp25V+mc6SKTmxRjdiysHS4S6rIV8AGawYzOJoqnK8+T4tkRZdNUH/hrxs1aS0/y0HsiDAeiWpFl1O+d/dprKzKyWDfTUdu83gL3k7kz9WMBsw0gUgEISrKYPSA8ryjzZSk6nJy6HohL2vBA4l+oe80btC1lVO1xYVr/cPAbSz0t/lqYF5jsdx61iYEwK03F4fLfmhXShK7r6BtrZHPmVGteDERyeAEUzGw9Pw88AkfR1dW0TA==" Feb 18 07:08:15 volumio go-librespot[15578]: time="2026-02-18T07:08:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:08:15 volumio go-librespot[15578]: time="2026-02-18T07:08:15+07:00" level=debug msg="completed keyexchange" Feb 18 07:08:15 volumio go-librespot[15578]: time="2026-02-18T07:08:15+07:00" level=debug msg="completed challenge" Feb 18 07:08:15 volumio volumio[15332]: info: Starting Shairport Sync Feb 18 07:08:15 volumio volumio[15332]: info: Starting Shairport Sync Feb 18 07:08:15 volumio go-librespot[15578]: time="2026-02-18T07: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 18 07:08:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:08:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:08:15 volumio volumio[15332]: info: Starting Shairport Sync Feb 18 07:08:15 volumio sudo[15604]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 07:08:15 volumio sudo[15604]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:08:15 volumio sudo[15606]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 07:08:15 volumio sudo[15606]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:08:15 volumio sudo[15608]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 07:08:15 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 07:08:15 volumio sudo[15608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:08:15 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 07:08:15 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 07:08:15 volumio systemd[1]: shairport-sync.service: Consumed 2.340s CPU time. Feb 18 07:08:15 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 07:08:15 volumio sudo[15604]: pam_unix(sudo:session): session closed for user root Feb 18 07:08:15 volumio volumio[15332]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 07:08:15 volumio volumio[15332]: SPOTIFY: BQBuPb-NAl3pBAap9CX6eH9JUwX1PEbrHhpq9SogI48Cxe3v9a0a0V5_o_JSrQUUBvk3aqwHq_6IW-qsUtAo9ud08dyA1530L6WTP43ZgD0kOPOjnFXQLRF0FFnvooduArx1QAE4iWSJfqw6at68ZVdKADZie_mkbOPqYtjrTGidTfanJu9dZD4YEOliHnSfZ7zdLhL8Xp3P7rI3YEGUMLBXZxdlcRoXJfMvU1CV0ZzcvHP05qixkCXQwZ8vKV6BZLaAmwtBCNNilssPbuDN7tX8J5sNjcufx05lDMxG-C_G4t4ghOFyIHVy Feb 18 07:08:15 volumio volumio[15332]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 07:08:15 volumio volumio[15332]: info: New Spotify access token = BQBuPb-NAl3pBAap9CX6eH9JUwX1PEbrHhpq9SogI48Cxe3v9a0a0V5_o_JSrQUUBvk3aqwHq_6IW-qsUtAo9ud08dyA1530L6WTP43ZgD0kOPOjnFXQLRF0FFnvooduArx1QAE4iWSJfqw6at68ZVdKADZie_mkbOPqYtjrTGidTfanJu9dZD4YEOliHnSfZ7zdLhL8Xp3P7rI3YEGUMLBXZxdlcRoXJfMvU1CV0ZzcvHP05qixkCXQwZ8vKV6BZLaAmwtBCNNilssPbuDN7tX8J5sNjcufx05lDMxG-C_G4t4ghOFyIHVy Feb 18 07:08:15 volumio volumio[15332]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 07:08:15 volumio volumio[15332]: info: Shairport-Sync Started Feb 18 07:08:15 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 07:08:15 volumio volumio[15332]: Error adding Membership: Error: addMembership EINVAL Feb 18 07:08:15 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 07:08:15 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 07:08:15 volumio volumio[15332]: info: CoreCommandRouter::volumioGetState Feb 18 07:08:15 volumio volumio[15332]: info: CorePlayQueue::getTrack 0 Feb 18 07:08:15 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 07:08:15 volumio sudo[15606]: pam_unix(sudo:session): session closed for user root Feb 18 07:08:15 volumio sudo[15608]: pam_unix(sudo:session): session closed for user root Feb 18 07:08:15 volumio volumio[15332]: info: Shairport-Sync Started Feb 18 07:08:15 volumio volumio[15332]: info: Shairport-Sync Started Feb 18 07:08:16 volumio volumio[15332]: 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 18 07:08:16 volumio volumio[15332]: info: Spotify Successfully logged in Feb 18 07:08:16 volumio volumio[15332]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 07:08:16 volumio volumio[15332]: info: [1771373296125] CoreMusicLibrary::Adding element Spotify Feb 18 07:08:16 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 07:08:16 volumio volumio[15332]: Cannot find translation for source YouTube Music Feb 18 07:08:16 volumio volumio[15332]: Cannot find translation for source Spotify Feb 18 07:08:16 volumio volumio[15332]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 07:08:16 volumio volumio[15332]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 07:08:17 volumio volumio[15332]: info: VolumeController:: Volume=100 Mute =false Feb 18 07:08:17 volumio volumio[15332]: info: CoreCommandRouter::volumioGetState Feb 18 07:08:17 volumio volumio[15332]: info: CorePlayQueue::getTrack 0 Feb 18 07:08:17 volumio volumio[15332]: info: CoreStateMachine::pushState Feb 18 07:08:17 volumio volumio[15332]: info: CorePlayQueue::getTrack 0 Feb 18 07:08:17 volumio volumio[15332]: info: CoreCommandRouter::volumioPushState Feb 18 07:08:18 volumio volumio[15332]: info: go-librespot daemon successfully initialized Feb 18 07:08:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 18 07:08:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:08:18 volumio mpd[15556]: 2026-02-18T07:08:18 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 07:08:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:08:18 volumio go-librespot[15654]: go-librespot daemon starting... Feb 18 07:08:18 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 07:08:18 volumio sudo[15518]: pam_unix(sudo:session): session closed for user root Feb 18 07:08:18 volumio sudo[15529]: pam_unix(sudo:session): session closed for user root Feb 18 07:08:18 volumio go-librespot[15657]: time="2026-02-18T07:08:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:08:18 volumio go-librespot[15657]: time="2026-02-18T07:08:18+07:00" level=debug msg="app state loaded" Feb 18 07:08:18 volumio go-librespot[15657]: time="2026-02-18T07:08:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:08:18 volumio volumio[15332]: error: MPD error: The expression evaluated to a falsy value: Feb 18 07:08:18 volumio volumio[15332]: assert.ok(self.idling) Feb 18 07:08:18 volumio volumio[15332]: error: The expression evaluated to a falsy value: Feb 18 07:08:18 volumio volumio[15332]: assert.ok(self.idling) Feb 18 07:08:18 volumio volumio[15332]: error: updateQueue error: null Feb 18 07:08:18 volumio volumio[15332]: info: Completed starting Core Plugins Feb 18 07:08:18 volumio volumio[15332]: info: ------------------------------------------- Feb 18 07:08:18 volumio volumio[15332]: info: ----- MyVolumio plugins startup ---- Feb 18 07:08:18 volumio volumio[15332]: info: ------------------------------------------- Feb 18 07:08:18 volumio volumio[15332]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 07:08:18 volumio volumio[15332]: info: MPD running with PID15556 Feb 18 07:08:18 volumio volumio[15332]: ,establishing connection Feb 18 07:08:18 volumio volumio[15332]: error: updateQueue error: null Feb 18 07:08:18 volumio go-librespot[15657]: time="2026-02-18T07:08: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 18 07:08:18 volumio go-librespot[15657]: time="2026-02-18T07:08: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 18 07:08:18 volumio go-librespot[15657]: time="2026-02-18T07:08: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 18 07:08:18 volumio go-librespot[15657]: time="2026-02-18T07:08:18+07:00" level=info msg="zeroconf server listening on port 45039" Feb 18 07:08:19 volumio go-librespot[15657]: time="2026-02-18T07:08:19+07:00" level=debug msg="obtained new client token: AADetigfkhRxPSEqDydyZv5Q9k3gHOSPmXGW7vgTFifgFVzr/PEpIMAVxv74tDfj/ZmqGXs62gbjT4l5oj5ydIFeB9y3YSabGjQpY744cw3wFKlaO536mOZXu5JdRTo/M4ppASVe7zRIKVSiKFx2TGbw0S2pUPPQBw9oQSWkyGqzoTnJmkm84ak2YMQ/xOjsqCye8m3omY9lqySDZz/y6/ToFZz4y/gy8NzPOARi5ExKCzl8p+c/aio=" Feb 18 07:08:19 volumio go-librespot[15657]: time="2026-02-18T07:08:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:08:19 volumio go-librespot[15657]: time="2026-02-18T07:08:19+07:00" level=debug msg="completed keyexchange" Feb 18 07:08:19 volumio go-librespot[15657]: time="2026-02-18T07:08:19+07:00" level=debug msg="completed challenge" Feb 18 07:08:19 volumio go-librespot[15657]: time="2026-02-18T07:08: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 18 07:08:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:08:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:08:21 volumio volumio[15332]: info: Initializing connection to go-librespot Websocket Feb 18 07:08:21 volumio volumio[15332]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 07:08:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 18 07:08:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:08:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:08:22 volumio go-librespot[15666]: go-librespot daemon starting... Feb 18 07:08:22 volumio go-librespot[15667]: time="2026-02-18T07:08:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:08:22 volumio go-librespot[15667]: time="2026-02-18T07:08:22+07:00" level=debug msg="app state loaded" Feb 18 07:08:22 volumio go-librespot[15667]: time="2026-02-18T07:08:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:08:23 volumio go-librespot[15667]: time="2026-02-18T07:08:23+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 18 07:08:23 volumio go-librespot[15667]: time="2026-02-18T07:08:23+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 18 07:08:23 volumio go-librespot[15667]: time="2026-02-18T07:08:23+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 18 07:08:23 volumio go-librespot[15667]: time="2026-02-18T07:08:23+07:00" level=info msg="zeroconf server listening on port 33201" Feb 18 07:08:23 volumio go-librespot[15667]: time="2026-02-18T07:08:23+07:00" level=debug msg="obtained new client token: AACRNnWZVI/jybIKNYuMquj9I7AAHuyApMic45XWS0V5+L/hH6aWg1/7P3EywuiHZcNlOtVO928FU+TJZcr+Dk3Z5PT6sy/1dxWu6UyfT/Ek8r6aFoCFVVYCComYLXa8u3Cgx+KxGVCnRrtYlGuduy7KmTGTnZLMEI3+Tr0PWlz09q8+VQmFBXPEDExGV4ym0mlGjBUtW7aTH6WLR30BzmUXXrJ+FzqJcmt/u99TWpzw6VNcCnprk0weKw==" Feb 18 07:08:23 volumio volumio[15332]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 07:08:23 volumio go-librespot[15667]: time="2026-02-18T07:08:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:08:23 volumio go-librespot[15667]: time="2026-02-18T07:08:23+07:00" level=debug msg="completed keyexchange" Feb 18 07:08:23 volumio go-librespot[15667]: time="2026-02-18T07:08:23+07:00" level=debug msg="completed challenge" Feb 18 07:08:23 volumio go-librespot[15667]: time="2026-02-18T07:08: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 18 07:08:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:08:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:08:24 volumio volumio[15332]: info: Initializing connection to go-librespot Websocket Feb 18 07:08:24 volumio volumio[15332]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 07:08:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 18 07:08:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:08:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:08:26 volumio go-librespot[15676]: go-librespot daemon starting... Feb 18 07:08:26 volumio go-librespot[15677]: time="2026-02-18T07:08:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:08:26 volumio go-librespot[15677]: time="2026-02-18T07:08:26+07:00" level=debug msg="app state loaded" Feb 18 07:08:26 volumio go-librespot[15677]: time="2026-02-18T07:08:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:08:27 volumio volumio[15332]: info: Initializing connection to go-librespot Websocket Feb 18 07:08:27 volumio go-librespot[15677]: time="2026-02-18T07:08:27+07:00" level=debug msg="new websocket client" Feb 18 07:08:27 volumio volumio[15332]: info: Connection to go-librespot Websocket established Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 07:08:27 volumio volumio[15332]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 07:08:27 volumio volumio[15332]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 07:08:27 volumio volumio[15332]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 07:08:27 volumio volumio[15332]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 07:08:27 volumio volumio[15332]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 07:08:27 volumio volumio[15332]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 07:08:27 volumio volumio[15332]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 07:08:27 volumio volumio[15332]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 07:08:27 volumio go-librespot[15677]: time="2026-02-18T07:08:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 07:08:27 volumio go-librespot[15677]: time="2026-02-18T07:08:27+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 18 07:08:27 volumio go-librespot[15677]: time="2026-02-18T07:08:27+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 18 07:08:27 volumio go-librespot[15677]: time="2026-02-18T07:08:27+07:00" level=info msg="zeroconf server listening on port 43573" Feb 18 07:08:27 volumio go-librespot[15677]: time="2026-02-18T07:08:27+07:00" level=debug msg="obtained new client token: AACDbWlcQeSAapAuDbKAyBhJxD1sEVlY2MsMpfJyGtS7zLYQ8HzvQGCaZEIJfT1CrG+BGuQ7lWYzEol7eXUIteyw4KRX2vxC1Hzz2m9Cdkq3/yr9rQWtd4yPnwmvIgyKMRTGGxi/yH0zBljI8wP6H/HcrHUslDQXLhsPa1hZoXutU/aKusGrmXKVZqHZh/U+eSPp8GOMDUvsitA+EEGNlRmsQcQ6I3rlmyhbLFEGpAUVDR6KpJd2CW2g+w==" Feb 18 07:08:27 volumio go-librespot[15677]: time="2026-02-18T07:08:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:08:27 volumio go-librespot[15677]: time="2026-02-18T07:08:27+07:00" level=debug msg="completed keyexchange" Feb 18 07:08:27 volumio go-librespot[15677]: time="2026-02-18T07:08:27+07:00" level=debug msg="completed challenge" Feb 18 07:08:27 volumio go-librespot[15677]: time="2026-02-18T07:08:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 07:08:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:08:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:08:29 volumio volumio[15332]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 07:08:29 volumio volumio[15332]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 07:08:29 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:08:29 volumio volumio[15332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 07:08:29 volumio volumio[15332]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 07:08:29 volumio volumio[15332]: info: MyVolumio login type: Token Feb 18 07:08:29 volumio volumio[15332]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 07:08:29 volumio volumio[15332]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 07:08:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 18 07:08:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:08:31 volumio volumio[15332]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 07:08:31 volumio volumio[15332]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 07:08:31 volumio volumio[15332]: info: Streaming services startup Feb 18 07:08:31 volumio volumio[15332]: info: Starting Streaming Daemon Feb 18 07:08:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 07:08:31 volumio go-librespot[15699]: go-librespot daemon starting... Feb 18 07:08:31 volumio sudo[15701]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 07:08:31 volumio volumio[15332]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 07:08:31 volumio sudo[15701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 07:08:31 volumio go-librespot[15703]: time="2026-02-18T07:08:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 07:08:31 volumio go-librespot[15703]: time="2026-02-18T07:08:31+07:00" level=debug msg="app state loaded" Feb 18 07:08:31 volumio go-librespot[15703]: time="2026-02-18T07:08:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 07:08:31 volumio sudo[15701]: pam_unix(sudo:session): session closed for user root Feb 18 07:08:31 volumio volumio[15332]: info: Getting Spotify volume Feb 18 07:08:31 volumio volumio[15332]: info: Connection to go-librespot Websocket closed Feb 18 07:08:31 volumio volumio[15332]: error: Cannot start Volumio Streaming Daemon Feb 18 07:08:31 volumio volumio[15332]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 07:08:31 volumio volumio[15332]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 07:08:31 volumio volumio[15332]: 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 18 07:08:31 volumio volumio[15332]: info: CoreCommandRouter::volumioGetState Feb 18 07:08:31 volumio volumio[15332]: info: CorePlayQueue::getTrack 0 Feb 18 07:08:31 volumio volumio[15332]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 07:08:31 volumio volumio[15332]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 07:08:31 volumio volumio[15332]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 07:08:31 volumio volumio[15332]: info: Aligning Spotify Volume to Volumio Volume Feb 18 07:08:31 volumio volumio[15332]: info: CoreCommandRouter::volumioGetState Feb 18 07:08:31 volumio volumio[15332]: info: CorePlayQueue::getTrack 0 Feb 18 07:08:31 volumio volumio[15332]: info: Setting Spotify Volume from Volumio: 100 Feb 18 07:08:31 volumio go-librespot[15703]: time="2026-02-18T07:08:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 07:08:31 volumio go-librespot[15703]: time="2026-02-18T07:08:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 07:08:31 volumio go-librespot[15703]: time="2026-02-18T07:08:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 07:08:31 volumio go-librespot[15703]: time="2026-02-18T07:08:31+07:00" level=info msg="zeroconf server listening on port 37533" Feb 18 07:08:31 volumio go-librespot[15703]: time="2026-02-18T07:08:31+07:00" level=debug msg="obtained new client token: AAAAMZ4a5z/+3RHc++7NKDfRQ2kATpx1J/OEaTuDCkwF3nB+WvHsNkbMfKcUIIbrfY9j1llpgytZNT8Ys2ZkZdMNBphuMEkPvFs5+HDWW7Ohy6BdiZTxkYKTcLc14cn/T3S9IqXW9sfaqOMVc/+3oWmxsI/XKcvD5TxWqGUwAblNit924k32QGu6xx41OmvTC07DnZynVaL5Qpa130xy6+mjJ0S2koGcGsStn6ueXZrj8VG2BHwePIJT0Q==" Feb 18 07:08:32 volumio go-librespot[15703]: time="2026-02-18T07:08:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 07:08:32 volumio go-librespot[15703]: time="2026-02-18T07:08:32+07:00" level=debug msg="completed keyexchange" Feb 18 07:08:32 volumio go-librespot[15703]: time="2026-02-18T07:08:32+07:00" level=debug msg="completed challenge" Feb 18 07:08:32 volumio go-librespot[15703]: time="2026-02-18T07:08:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 07:08:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 07:08:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 07:08:32 volumio volumio[15332]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 18 07:08:32 volumio volumio[15332]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 07:08:32 volumio volumio[15332]: Error: socket hang up Feb 18 07:08:32 volumio volumio[15332]: at connResetException (node:internal/errors:720:14) Feb 18 07:08:32 volumio volumio[15332]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 07:08:32 volumio volumio[15332]: at Socket.emit (node:events:526:35) Feb 18 07:08:32 volumio volumio[15332]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 07:08:32 volumio volumio[15332]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 07:08:32 volumio volumio[15332]: code: 'ECONNRESET', Feb 18 07:08:32 volumio volumio[15332]: response: undefined Feb 18 07:08:32 volumio volumio[15332]: } Feb 18 07:08:32 volumio volumio[15332]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 07:08:33 volumio sudo[15728]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 07:07' Feb 18 07:08:33 volumio sudo[15728]: 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"