Feb 10 13:59:01 volumio volumio[7799]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 10 13:59:01 volumio volumio[7799]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 10 13:59:01 volumio volumio[7799]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:59:01 volumio volumio[7799]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:59:01 volumio volumio[7799]: info: Starting MyVolumio Remote Streaming Endpoints Feb 10 13:59:01 volumio volumio[7799]: info: MyVolumio login type: Token Feb 10 13:59:01 volumio volumio[7799]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 10 13:59:01 volumio volumio[7799]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 10 13:59:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 10 13:59:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:02 volumio go-librespot[8168]: go-librespot daemon starting... Feb 10 13:59:02 volumio go-librespot[8169]: time="2026-02-10T13:59:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:59:02 volumio go-librespot[8169]: time="2026-02-10T13:59:02+07:00" level=debug msg="app state loaded" Feb 10 13:59:02 volumio go-librespot[8169]: time="2026-02-10T13:59:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:59:03 volumio volumio[7799]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 10 13:59:03 volumio volumio[7799]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 10 13:59:03 volumio volumio[7799]: info: Streaming services startup Feb 10 13:59:03 volumio volumio[7799]: info: Starting Streaming Daemon Feb 10 13:59:03 volumio sudo[8180]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 10 13:59:03 volumio sudo[8180]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:03 volumio volumio[7799]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 10 13:59:03 volumio sudo[8180]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:03 volumio go-librespot[8169]: time="2026-02-10T13:59: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:59:03 volumio go-librespot[8169]: time="2026-02-10T13:59:03+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 10 13:59:03 volumio go-librespot[8169]: time="2026-02-10T13:59:03+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 10 13:59:03 volumio go-librespot[8169]: time="2026-02-10T13:59:03+07:00" level=info msg="zeroconf server listening on port 34945" Feb 10 13:59:03 volumio volumio[7799]: info: Getting Spotify volume Feb 10 13:59:03 volumio volumio[7799]: info: Connection to go-librespot Websocket closed Feb 10 13:59:03 volumio volumio[7799]: error: Cannot start Volumio Streaming Daemon Feb 10 13:59:03 volumio volumio[7799]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 10 13:59:03 volumio volumio[7799]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 10 13:59:03 volumio volumio[7799]: 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 10 13:59:03 volumio go-librespot[8169]: time="2026-02-10T13:59:03+07:00" level=debug msg="obtained new client token: AACA47W/xM1pLE5EdUxzxuxh7e+gHIxXBsbOsosbypiT8Vd88Bru9xZvyct4HrfyfC+YgT2pQM+6giNb740BbLtZNr/zwHS+Euhlhnvb0nkLu8PO2xpxT3sFeCIPN1XdNnzKYJrec5ia6JtpUZ93smlALVSqpfesBl/T/NlUYPxnwfTIRgfgleZLe5MPW1KsCs5PztevMit2HpZjVj4ol9uroFGTFP5uKXnH6Zeg73WG6KxxRKg7ZYvPTA==" Feb 10 13:59:03 volumio go-librespot[8169]: time="2026-02-10T13:59:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:59:03 volumio volumio[7799]: info: CoreCommandRouter::volumioGetState Feb 10 13:59:03 volumio volumio[7799]: info: CorePlayQueue::getTrack 0 Feb 10 13:59:03 volumio volumio[7799]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 10 13:59:03 volumio volumio[7799]: SPOTIFY: SPOTIFY VOLUME undefined Feb 10 13:59:03 volumio volumio[7799]: SPOTIFY: VOLUMIO VOLUME 100 Feb 10 13:59:03 volumio volumio[7799]: info: Aligning Spotify Volume to Volumio Volume Feb 10 13:59:03 volumio volumio[7799]: info: CoreCommandRouter::volumioGetState Feb 10 13:59:03 volumio volumio[7799]: info: CorePlayQueue::getTrack 0 Feb 10 13:59:03 volumio volumio[7799]: info: Setting Spotify Volume from Volumio: 100 Feb 10 13:59:03 volumio go-librespot[8169]: time="2026-02-10T13:59:03+07:00" level=debug msg="completed keyexchange" Feb 10 13:59:03 volumio go-librespot[8169]: time="2026-02-10T13:59:03+07:00" level=debug msg="completed challenge" Feb 10 13:59:03 volumio go-librespot[8169]: time="2026-02-10T13:59: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 10 13:59:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:59:03 volumio volumio[7799]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 13:59:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:59:03 volumio volumio[7799]: Error: socket hang up Feb 10 13:59:03 volumio volumio[7799]: at connResetException (node:internal/errors:720:14) Feb 10 13:59:03 volumio volumio[7799]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 10 13:59:03 volumio volumio[7799]: at Socket.emit (node:events:526:35) Feb 10 13:59:03 volumio volumio[7799]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 10 13:59:03 volumio volumio[7799]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 10 13:59:03 volumio volumio[7799]: code: 'ECONNRESET', Feb 10 13:59:03 volumio volumio[7799]: response: undefined Feb 10 13:59:03 volumio volumio[7799]: } Feb 10 13:59:03 volumio volumio[7799]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 13:59:05 volumio sudo[8200]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 13:58' Feb 10 13:59:05 volumio sudo[8200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:05 volumio sudo[8200]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:05 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:59:05 volumio volumio-remote-updater[643]: [2026-02-10 13:59:05] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 10 13:59:05 volumio volumio-remote-updater[643]: [2026-02-10 13:59:05] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 10 13:59:05 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 10 13:59:05 volumio systemd[1]: volumio.service: Consumed 55.201s CPU time. Feb 10 13:59:05 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 13:59:05 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 13:59:05 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10326. Feb 10 13:59:05 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 13:59:05 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 10 13:59:05 volumio systemd[1]: volumio.service: Consumed 55.201s CPU time. Feb 10 13:59:05 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 10 13:59:05 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 13:59:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 10 13:59:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:06 volumio go-librespot[8230]: go-librespot daemon starting... Feb 10 13:59:06 volumio go-librespot[8231]: time="2026-02-10T13:59:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:59:06 volumio go-librespot[8231]: time="2026-02-10T13:59:06+07:00" level=debug msg="app state loaded" Feb 10 13:59:06 volumio go-librespot[8231]: time="2026-02-10T13:59:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:59:07 volumio go-librespot[8231]: time="2026-02-10T13:59: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:59:07 volumio go-librespot[8231]: time="2026-02-10T13:59:07+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 10 13:59:07 volumio go-librespot[8231]: time="2026-02-10T13:59:07+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 10 13:59:07 volumio go-librespot[8231]: time="2026-02-10T13:59:07+07:00" level=info msg="zeroconf server listening on port 32913" Feb 10 13:59:07 volumio go-librespot[8231]: time="2026-02-10T13:59:07+07:00" level=debug msg="obtained new client token: AADzbe0lLkt4+9j5BHx+GeMC+1gKc7/Zz/Uleyza+SjajN7bCRl8Pq4pDjnVN95yYwawhi/PF3wz5CNGXrY5XOLZX4llMFVWKHJDM8nf6Z7B2o1PqoITUrAP6X5qnW5GAJ2Xc3VIWZ79VdXtjSw7EbDapR8Xb1piFg8ZSkMyWJaHAUe150kGRMOTHIIxrMie1fOc3TabWhunMnCImAi0s5utJpcEVyLWD4kkNdAV6zuD9wVMYq0cTJMSVA==" Feb 10 13:59:07 volumio go-librespot[8231]: time="2026-02-10T13:59:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:59:07 volumio go-librespot[8231]: time="2026-02-10T13:59:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:59:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:59:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:59:09 volumio volumio[8215]: info: ------------------------------------------- Feb 10 13:59:09 volumio volumio[8215]: info: ----- Volumio3 ---- Feb 10 13:59:09 volumio volumio[8215]: info: ------------------------------------------- Feb 10 13:59:09 volumio volumio[8215]: info: ----- System startup ---- Feb 10 13:59:09 volumio volumio[8215]: info: ------------------------------------------- Feb 10 13:59:10 volumio volumio-remote-updater[643]: [2026-02-10 13:59:10] [connect] Successful connection Feb 10 13:59:10 volumio volumio[8215]: info: MYVOLUMIO Environment detected Feb 10 13:59:10 volumio volumio[8215]: info: Plugin folders cleanup Feb 10 13:59:10 volumio volumio[8215]: info: Scanning into folder /volumio/app/plugins/ Feb 10 13:59:10 volumio volumio[8215]: info: Scanning category audio_interface Feb 10 13:59:10 volumio volumio[8215]: info: Scanning category miscellanea Feb 10 13:59:10 volumio volumio[8215]: info: Scanning category music_service Feb 10 13:59:10 volumio volumio[8215]: info: Scanning category plugins.json Feb 10 13:59:10 volumio volumio[8215]: info: Scanning category system_controller Feb 10 13:59:10 volumio volumio[8215]: info: Scanning category user_interface Feb 10 13:59:10 volumio volumio[8215]: info: Scanning into folder /data/plugins/ Feb 10 13:59:10 volumio volumio[8215]: info: Scanning category music_service Feb 10 13:59:10 volumio volumio[8215]: info: Plugin folders cleanup completed Feb 10 13:59:10 volumio volumio[8215]: info: ------------------------------------------- Feb 10 13:59:10 volumio volumio[8215]: info: ----- Core plugins startup ---- Feb 10 13:59:10 volumio volumio[8215]: info: ------------------------------------------- Feb 10 13:59:10 volumio volumio[8215]: info: Loading plugins from folder /volumio/app/plugins/ Feb 10 13:59:10 volumio volumio[8215]: info: Adding plugin upnp to MyMusic Plugins Feb 10 13:59:11 volumio volumio[8215]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 10 13:59:11 volumio volumio[8215]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 10 13:59:11 volumio volumio[8215]: info: Loading plugins from folder /data/plugins/ Feb 10 13:59:11 volumio volumio[8215]: info: Loading plugin "system"... Feb 10 13:59:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 10 13:59:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:11 volumio volumio[8215]: info: Loading plugin "appearance"... Feb 10 13:59:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:11 volumio go-librespot[8249]: go-librespot daemon starting... Feb 10 13:59:11 volumio go-librespot[8253]: time="2026-02-10T13:59:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:59:11 volumio go-librespot[8253]: time="2026-02-10T13:59:11+07:00" level=debug msg="app state loaded" Feb 10 13:59:11 volumio go-librespot[8253]: time="2026-02-10T13:59:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:59:11 volumio go-librespot[8253]: time="2026-02-10T13:59:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 13:59:11 volumio go-librespot[8253]: time="2026-02-10T13:59:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 13:59:11 volumio go-librespot[8253]: time="2026-02-10T13:59:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 13:59:11 volumio go-librespot[8253]: time="2026-02-10T13:59:11+07:00" level=info msg="zeroconf server listening on port 39833" Feb 10 13:59:11 volumio go-librespot[8253]: time="2026-02-10T13:59:11+07:00" level=debug msg="obtained new client token: AAAk6D+XlHyih9XkhJ1KAMiYj7z6KY22UPTUi2nLtk9jcBiztpOIx7PgkK/bmR0oAkV5/1w4ZCFBEK10E6pllV8AYLNPGMObDnqwQa8L/Pw8DTstEdxNuS3f1CvmNNAUmxbIVBjpBor8CilxiERYKkmnY5sJQmhUCYmkvGxeOLL9VEsqpWWvDgMtAzXr3iifeN5qV3XJJRTbySHygCt2dsyoEpF2clrDEgtlFP+5lAOxq5Fu1+wpYNjXvg==" Feb 10 13:59:12 volumio go-librespot[8253]: time="2026-02-10T13:59:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:59:12 volumio go-librespot[8253]: time="2026-02-10T13:59:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:59:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:59:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:59:13 volumio volumio[8215]: info: Loading plugin "network"... Feb 10 13:59:13 volumio volumio[8215]: info: Refreshing Cached IP Addresses Feb 10 13:59:13 volumio sudo[8261]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 13:59:13 volumio sudo[8261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:13 volumio sudo[8263]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 13:59:13 volumio volumio[8215]: info: Loading plugin "services"... Feb 10 13:59:13 volumio sudo[8263]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:13 volumio sudo[8261]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:13 volumio volumio[8215]: info: Loading plugin "alsa_controller"... Feb 10 13:59:13 volumio sudo[8263]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:13 volumio sudo[8271]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 10 13:59:13 volumio sudo[8271]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:13 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:59:13 volumio volumio[8215]: info: Loading plugin "wizard"... Feb 10 13:59:13 volumio volumio[8215]: info: Loading plugin "networkfs"... Feb 10 13:59:13 volumio volumio[8215]: info: Starting Udev Watcher for removable devices Feb 10 13:59:13 volumio volumio[8215]: info: Ignoring mount for partition: boot Feb 10 13:59:13 volumio volumio[8215]: info: Ignoring mount for partition: volumio Feb 10 13:59:13 volumio volumio[8215]: info: Ignoring mount for partition: volumio_data Feb 10 13:59:13 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:59:13 volumio volumio[8215]: info: Loading plugin "volumio_command_line_client"... Feb 10 13:59:13 volumio volumio[8215]: info: Loading plugin "upnp"... Feb 10 13:59:13 volumio volumio[8215]: info: [1770706753421] Starting Upmpd Daemon Feb 10 13:59:13 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:59:13 volumio volumio[8215]: info: Loading plugin "my_music"... Feb 10 13:59:13 volumio volumio[8215]: info: Loading plugin "mpd"... Feb 10 13:59:14 volumio volumio[8215]: info: Loading plugin "upnp_browser"... Feb 10 13:59:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 10 13:59:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:15 volumio go-librespot[8294]: go-librespot daemon starting... Feb 10 13:59:15 volumio go-librespot[8295]: time="2026-02-10T13:59:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:59:15 volumio go-librespot[8295]: time="2026-02-10T13:59:15+07:00" level=debug msg="app state loaded" Feb 10 13:59:15 volumio go-librespot[8295]: time="2026-02-10T13:59:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:59:15 volumio go-librespot[8295]: time="2026-02-10T13:59:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:59:15 volumio go-librespot[8295]: time="2026-02-10T13:59:15+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 10 13:59:15 volumio go-librespot[8295]: time="2026-02-10T13:59:15+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 10 13:59:15 volumio sudo[8271]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:15 volumio go-librespot[8295]: time="2026-02-10T13:59:15+07:00" level=info msg="zeroconf server listening on port 43331" Feb 10 13:59:16 volumio go-librespot[8295]: time="2026-02-10T13:59:16+07:00" level=debug msg="obtained new client token: AAAyUN7Ks1s+FBpA7jbNCWebuzrMb+oe+tBwD2VeHLyZES0WrBqUuVmFRbbbA/mvpr3uqZOzmWMXvA26g9LotOS/6TMpB1LZxpps9FlpsW4m56NBY0HRqJ61ThLnn1ujr+Q/rUtMrHp8dvll2C8jrSp1k0L0WNscYuZfFQJJggBJU6t7uqZ3VMO4a/kyTGNzDQkFqppuVWsE0C0F/R/vlyr3h62ve+lyBW351I7nU68cC89nF5i6LCk=" Feb 10 13:59:16 volumio go-librespot[8295]: time="2026-02-10T13:59:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:59:16 volumio go-librespot[8295]: time="2026-02-10T13:59:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:59:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:59:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:59:17 volumio volumio[8215]: info: Starting UPNP Browser Feb 10 13:59:17 volumio volumio[8215]: info: Loading plugin "alarm-clock"... Feb 10 13:59:17 volumio volumio[8215]: info: Loading plugin "airplay_emulation"... Feb 10 13:59:17 volumio volumio[8215]: info: Starting Shairport Sync Feb 10 13:59:17 volumio volumio[8215]: info: Loading plugin "last_100"... Feb 10 13:59:17 volumio volumio[8215]: info: Loading plugin "webradio"... Feb 10 13:59:17 volumio volumio[8215]: info: Loading plugin "i2s_dacs"... Feb 10 13:59:17 volumio volumio[8215]: info: Loading plugin "volumiodiscovery"... Feb 10 13:59:17 volumio volumio[8215]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 13:59:17 volumio volumio[8215]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:59:17 volumio node[8215]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 13:59:17 volumio volumio[8215]: *** WARNING *** For more information see Feb 10 13:59:17 volumio volumio[8215]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 13:59:17 volumio volumio[8215]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:59:17 volumio volumio[8215]: *** WARNING *** For more information see Feb 10 13:59:17 volumio node[8215]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:59:17 volumio node[8215]: *** WARNING *** For more information see Feb 10 13:59:17 volumio node[8215]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 13:59:17 volumio node[8215]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:59:17 volumio node[8215]: *** WARNING *** For more information see Feb 10 13:59:17 volumio volumio[8215]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 13:59:17 volumio volumio[8215]: info: Discovery: Started advertising with name: Volumio Feb 10 13:59:17 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:59:17 volumio volumio[8215]: info: Loading plugin "spop"... Feb 10 13:59:19 volumio volumio[8215]: info: Loading plugin "ytcr"... Feb 10 13:59:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 10 13:59:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:19 volumio go-librespot[8305]: go-librespot daemon starting... Feb 10 13:59:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:19 volumio go-librespot[8306]: time="2026-02-10T13:59:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:59:19 volumio go-librespot[8306]: time="2026-02-10T13:59:19+07:00" level=debug msg="app state loaded" Feb 10 13:59:19 volumio go-librespot[8306]: time="2026-02-10T13:59:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:59:20 volumio go-librespot[8306]: time="2026-02-10T13:59: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:59:20 volumio go-librespot[8306]: time="2026-02-10T13:59:20+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 10 13:59:20 volumio go-librespot[8306]: time="2026-02-10T13:59:20+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 10 13:59:20 volumio go-librespot[8306]: time="2026-02-10T13:59:20+07:00" level=info msg="zeroconf server listening on port 40421" Feb 10 13:59:20 volumio go-librespot[8306]: time="2026-02-10T13:59:20+07:00" level=debug msg="obtained new client token: AAD8P0AfzehLdufRWMeEWZunSk38iVFxyDcgLetVug7RO1n5ZwY9yihTdzJ+hO2kBQcyqNb1AjqcYN8UWQpBaBPkmWqX8wVA4IjqAPm3hItd+wLsEx0jTyYKqHar8DYC6IdmgW0oxn/GkXWJbl03NG1q26JZ1mPhTwGG8KhXfR/1i9PLvoU4fAolkO71bfSII1v5Ycck5RrQ/01R4hID40uCGblDERI4MQPU7JobkGFxJCzPDYuCyUhIPg==" Feb 10 13:59:20 volumio go-librespot[8306]: time="2026-02-10T13:59:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:59:20 volumio go-librespot[8306]: time="2026-02-10T13:59:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:59:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:59:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:59:22 volumio volumio[8215]: info: Loading plugin "ytmusic"... Feb 10 13:59:23 volumio volumio-remote-updater[643]: [2026-02-10 13:59:22] [connect] Successful connection Feb 10 13:59:23 volumio volumio[8215]: info: Loading plugin "outputs"... Feb 10 13:59:23 volumio volumio[8215]: info: Loading plugin "albumart"... Feb 10 13:59:23 volumio volumio[8215]: info: Plugin example_plugin is not enabled Feb 10 13:59:23 volumio volumio[8215]: info: Loading plugin "inputs"... Feb 10 13:59:23 volumio volumio[8215]: info: Loading plugin "updater_comm"... Feb 10 13:59:23 volumio volumio[8215]: info: Plugin mpdemulation is not enabled Feb 10 13:59:23 volumio volumio[8215]: info: Loading plugin "rest_api"... Feb 10 13:59:23 volumio volumio[8215]: info: Loading plugin "websocket"... Feb 10 13:59:23 volumio volumio[8215]: info: Starting Socket.io Server version 1.7.4 Feb 10 13:59:23 volumio volumio[8215]: info: Loading plugin "RoonBridge"... Feb 10 13:59:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 10 13:59:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:23 volumio go-librespot[8337]: go-librespot daemon starting... Feb 10 13:59:23 volumio go-librespot[8338]: time="2026-02-10T13:59:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:59:23 volumio go-librespot[8338]: time="2026-02-10T13:59:23+07:00" level=debug msg="app state loaded" Feb 10 13:59:23 volumio go-librespot[8338]: time="2026-02-10T13:59:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:59:24 volumio volumio[8215]: info: Applying required configuration parameters for plugin RoonBridge Feb 10 13:59:24 volumio volumio[8215]: info: Loading i18n strings for locale en Feb 10 13:59:24 volumio volumio[8215]: Updating browse sources language Feb 10 13:59:24 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:59:24 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:59:24 volumio volumio[8215]: info: CoreCommandRouter::initPlayerControls Feb 10 13:59:24 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:24 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:24 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:24 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:24 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:24 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:24 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:24 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:24 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:59:24 volumio volumio[8215]: Express server listening on port 3000 Feb 10 13:59:24 volumio volumio[8215]: [Metrics] WebUI: 15s 880.80ms Feb 10 13:59:24 volumio volumio[8322]: Forking 3 albumart workers Feb 10 13:59:24 volumio volumio[8215]: info: CoreStateMachine::resetVolumioState Feb 10 13:59:24 volumio volumio[8215]: info: CoreStateMachine::getcurrentVolume Feb 10 13:59:24 volumio volumio[8215]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:59:24 volumio go-librespot[8338]: time="2026-02-10T13:59:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:59:24 volumio go-librespot[8338]: time="2026-02-10T13:59:24+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 10 13:59:24 volumio go-librespot[8338]: time="2026-02-10T13:59:24+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 10 13:59:24 volumio go-librespot[8338]: time="2026-02-10T13:59:24+07:00" level=info msg="zeroconf server listening on port 40535" Feb 10 13:59:24 volumio sudo[8353]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 13:59:24 volumio sudo[8353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:24 volumio sudo[8362]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 13:59:24 volumio sudo[8353]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:24 volumio sudo[8362]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:24 volumio sudo[8362]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:24 volumio volumio[8215]: info: Volumio Network Manager: Network status updated: 1 Feb 10 13:59:24 volumio go-librespot[8338]: time="2026-02-10T13:59:24+07:00" level=debug msg="obtained new client token: AAASeBrO5GhhCM7Q1agwusS/55QkapwKkPqPSYnrEw/SXjdv1pvuMHenoK/wjzf/KY0BpkaTBqlQ5lsysgz/w2b/kuN2dbs+N7q/q0ssSbvyTclHI8QdrANOrbHKfvaqQST2HQGdwT1usI7v4vwKI2NSx8tiBxkXG4U9vzKoumavoc+/jqUnDjYmEtI82JoP0X/2UVgqcPSDdiFhmDt6Q6PE6JIu3OqQUZeQgxpwNVr6J7kl8jtvrpgcYA==" Feb 10 13:59:25 volumio go-librespot[8338]: time="2026-02-10T13:59:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:59:25 volumio volumio[8215]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:59:25 volumio volumio[8215]: info: CoreStateMachine::pushState Feb 10 13:59:25 volumio volumio[8215]: info: CorePlayQueue::getTrack 0 Feb 10 13:59:25 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 13:59:25 volumio volumio[8215]: info: CoreCommandRouter::volumioPushState Feb 10 13:59:25 volumio volumio[8215]: info: CoreStateMachine::updateTrackBlock Feb 10 13:59:25 volumio volumio[8215]: info: CorePlayQueue::getTrackBlock Feb 10 13:59:25 volumio volumio[8215]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:59:25 volumio volumio-remote-updater[643]: [2026-02-10 13:59:25] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770706762 101 Feb 10 13:59:25 volumio go-librespot[8338]: time="2026-02-10T13:59:25+07:00" level=debug msg="completed keyexchange" Feb 10 13:59:25 volumio go-librespot[8338]: time="2026-02-10T13:59:25+07:00" level=debug msg="completed challenge" Feb 10 13:59:25 volumio volumio[8215]: 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 10 13:59:25 volumio go-librespot[8338]: time="2026-02-10T13:59:25+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 10 13:59:25 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:59:25 volumio volumio[8215]: info: Reloading queue from file Feb 10 13:59:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:59:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:59:25 volumio volumio[8215]: info: CoreStateMachine::setRepeat null single undefined Feb 10 13:59:25 volumio volumio[8215]: info: CoreStateMachine::pushState Feb 10 13:59:25 volumio volumio[8215]: info: CorePlayQueue::getTrack 0 Feb 10 13:59:25 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 13:59:25 volumio volumio[8215]: info: CoreCommandRouter::volumioPushState Feb 10 13:59:25 volumio volumio[8215]: info: CoreStateMachine::setRandom null Feb 10 13:59:25 volumio volumio[8215]: info: CoreStateMachine::pushState Feb 10 13:59:25 volumio volumio[8215]: info: CorePlayQueue::getTrack 0 Feb 10 13:59:25 volumio volumio[8215]: info: CoreCommandRouter::volumioPushState Feb 10 13:59:25 volumio volumio[8215]: info: Setting Device type: Raspberry PI Feb 10 13:59:25 volumio volumio[8215]: info: Completed loading Core Plugins Feb 10 13:59:25 volumio volumio[8215]: info: Preparing to generate the ALSA configuration file Feb 10 13:59:25 volumio volumio[8215]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:59:25 volumio volumio[8215]: info: CoreStateMachine::pushState Feb 10 13:59:25 volumio volumio[8215]: info: CorePlayQueue::getTrack 0 Feb 10 13:59:25 volumio volumio[8215]: info: CoreCommandRouter::volumioPushState Feb 10 13:59:25 volumio volumio[8215]: info: Asound.conf file unchanged, so no further update is needed Feb 10 13:59:25 volumio volumio[8215]: info: Output device has changed, restarting MPD Feb 10 13:59:25 volumio volumio[8215]: info: Output device has changed, restarting Shairport Sync Feb 10 13:59:25 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:25 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:59:25 volumio sudo[8396]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 13:59:25 volumio sudo[8396]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:25 volumio volumio[8215]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:59:25 volumio volumio[8215]: info: ___________ START PLUGINS ___________ Feb 10 13:59:25 volumio volumio[8215]: info: ControllerMpd::onStart: Initializing MPD Feb 10 13:59:25 volumio sudo[8398]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 13:59:25 volumio volumio[8215]: info: Creating MPD Configuration file Feb 10 13:59:25 volumio sudo[8398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:25 volumio sudo[8398]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:25 volumio sudo[8401]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 13:59:25 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:59:25 volumio sudo[8401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:25 volumio volumio[8215]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:59:25 volumio volumio[8215]: info: [1770706765763] CoreMusicLibrary::Adding element Media Servers Feb 10 13:59:25 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:59:25 volumio volumio[8215]: info: UPNP Browser: Client initialized successfully Feb 10 13:59:25 volumio sudo[8408]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 13:59:25 volumio sudo[8410]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 13:59:25 volumio sudo[8396]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:25 volumio sudo[8410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:25 volumio sudo[8408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:25 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:25 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:59:25 volumio sudo[8408]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:25 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 13:59:25 volumio volumio[8215]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:59:25 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:25 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:59:26 volumio volumio[8215]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:59:26 volumio volumio[8215]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:59:26 volumio volumio[8215]: info: [1770706766053] CoreMusicLibrary::Adding element Last_100 Feb 10 13:59:26 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:59:26 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 13:59:26 volumio volumio[8215]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:59:26 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 13:59:26 volumio systemd[1]: mpd.service: Consumed 7.089s CPU time. Feb 10 13:59:26 volumio volumio[8215]: info: [1770706766073] CoreMusicLibrary::Adding element Webradio Feb 10 13:59:26 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:59:26 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 13:59:26 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 13:59:26 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 13:59:26 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:59:26 volumio volumio[8215]: info: Initializing BBC Radios Feb 10 13:59:26 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 13:59:26 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 13:59:26 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 13:59:26 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 13:59:26 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 13:59:26 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 13:59:26 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 13:59:26 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 13:59:26 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:59:26 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:59:26 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 13:59:26 volumio volumio[8215]: info: Creating Spotify config file Feb 10 13:59:26 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:26 volumio sudo[8438]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 13:59:26 volumio sudo[8438]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 13:59:26 volumio sudo[8438]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:27 volumio volumio[8215]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:59:27 volumio volumio[8215]: info: [1770706767305] CoreMusicLibrary::Adding element YouTube Music Feb 10 13:59:27 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:59:27 volumio volumio[8215]: Cannot find translation for source YouTube Music Feb 10 13:59:27 volumio volumio[8215]: info: Volumio Calling Home Feb 10 13:59:27 volumio sudo[8442]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 10 13:59:27 volumio sudo[8442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:27 volumio sudo[8442]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:27 volumio volumio[8350]: Starting albumart workers Feb 10 13:59:28 volumio volumio[8215]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 13:59:28 volumio volumio[8215]: info: Discovery: Found device Volumio Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::volumioGetState Feb 10 13:59:28 volumio volumio[8215]: info: CorePlayQueue::getTrack 0 Feb 10 13:59:28 volumio volumio[8348]: Starting albumart workers Feb 10 13:59:28 volumio volumio[8215]: info: MPD Permissions set Feb 10 13:59:28 volumio volumio[8215]: info: MPD Permissions set Feb 10 13:59:28 volumio volumio[8215]: info: Upmpdcli Daemon Started Feb 10 13:59:28 volumio volumio[8215]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 13:59:28 volumio volumio[8215]: info: Discovery: Found device Volumio Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::volumioGetState Feb 10 13:59:28 volumio volumio[8215]: info: CorePlayQueue::getTrack 0 Feb 10 13:59:28 volumio volumio[8215]: info: Spotify config file written Feb 10 13:59:28 volumio volumio[8351]: Starting albumart workers Feb 10 13:59:28 volumio sudo[8448]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 13:59:28 volumio sudo[8448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:28 volumio volumio[8215]: 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 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 10 13:59:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:28 volumio go-librespot[8452]: go-librespot daemon starting... Feb 10 13:59:28 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 10 13:59:28 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 10 13:59:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:28 volumio sudo[8448]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:28 volumio go-librespot[8463]: go-librespot daemon starting... Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:59:28 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:59:28 volumio volumio[8215]: info: No need to fix Spotify hosts Feb 10 13:59:28 volumio go-librespot[8464]: time="2026-02-10T13:59:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:59:28 volumio go-librespot[8464]: time="2026-02-10T13:59:28+07:00" level=debug msg="app state loaded" Feb 10 13:59:28 volumio go-librespot[8464]: time="2026-02-10T13:59:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:59:29 volumio go-librespot[8464]: time="2026-02-10T13:59:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:59:29 volumio go-librespot[8464]: time="2026-02-10T13:59:29+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 10 13:59:29 volumio go-librespot[8464]: time="2026-02-10T13:59:29+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 10 13:59:29 volumio go-librespot[8464]: time="2026-02-10T13:59:29+07:00" level=info msg="zeroconf server listening on port 34853" Feb 10 13:59:29 volumio go-librespot[8464]: time="2026-02-10T13:59:29+07:00" level=debug msg="obtained new client token: AABCye/2IvAXaA4b7uRJTBde5MqXEr5Co+KRZlSUdg17L6fS2Jh6chg7M0/OrNBDQnBW4/3JnlyAT6hXLQlVGcojtFiy+xA4e5dAT2sVhZysa23k2F0S1y27QfDU8qhHexRwKyyjKTJ7VUSrcKHBDEahk0bGFDpAOuoQfXHalxjaUWseDJHKLNb1IqlhDh43m/rC0TZrVdoSMKQIWDo4VdL9xm7Rjtgkl2TS44trfmv1ecpt3jbvuUjzmQ==" Feb 10 13:59:29 volumio go-librespot[8464]: time="2026-02-10T13:59:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:59:29 volumio go-librespot[8464]: time="2026-02-10T13:59:29+07:00" level=debug msg="completed keyexchange" Feb 10 13:59:29 volumio go-librespot[8464]: time="2026-02-10T13:59:29+07:00" level=debug msg="completed challenge" Feb 10 13:59:29 volumio go-librespot[8464]: time="2026-02-10T13:59:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:59:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:59:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:59:30 volumio volumio[8215]: info: Volumio called home Feb 10 13:59:30 volumio volumio[8215]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 13:59:30 volumio volumio[8215]: SPOTIFY: BQCkIfctIjMNxcr8gqs7n2lpLdiY-hWdHnA0yvUxH6cXzxTz7oMrfV_633cm9VBtj2qMkKK7PrbdR6D5DxNPa_id7IprJNUrWc5w1SNmoDKgE2olqSyoXnDNAUBWLWm9fCwMUPkfbo8cLsibWXN8WToRaFfs4A2aOwsa5se_ExSzvs60ebDYzz7t-VhKXaRBGtEXoXS5zDFDQ-ucLrHplRI7gVydbiVTewFLbNNolFlS6rAy2aBax-jZ-72p93ztamAH6YS8uUsaEUx_CslmgqgIjXeJBB5bQ_bhgwBBDLoNqxWsKQiRMkq0 Feb 10 13:59:30 volumio volumio[8215]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 13:59:30 volumio volumio[8215]: info: New Spotify access token = BQCkIfctIjMNxcr8gqs7n2lpLdiY-hWdHnA0yvUxH6cXzxTz7oMrfV_633cm9VBtj2qMkKK7PrbdR6D5DxNPa_id7IprJNUrWc5w1SNmoDKgE2olqSyoXnDNAUBWLWm9fCwMUPkfbo8cLsibWXN8WToRaFfs4A2aOwsa5se_ExSzvs60ebDYzz7t-VhKXaRBGtEXoXS5zDFDQ-ucLrHplRI7gVydbiVTewFLbNNolFlS6rAy2aBax-jZ-72p93ztamAH6YS8uUsaEUx_CslmgqgIjXeJBB5bQ_bhgwBBDLoNqxWsKQiRMkq0 Feb 10 13:59:30 volumio volumio[8215]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 13:59:30 volumio volumio[8215]: info: Starting Shairport Sync Feb 10 13:59:30 volumio volumio[8215]: info: Starting Shairport Sync Feb 10 13:59:30 volumio volumio[8215]: info: Starting Shairport Sync Feb 10 13:59:30 volumio sudo[8486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:59:30 volumio sudo[8486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:30 volumio sudo[8490]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:59:30 volumio sudo[8490]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:30 volumio sudo[8488]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:59:30 volumio sudo[8488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:30 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 13:59:30 volumio volumio[8215]: info: CoreCommandRouter::volumioGetState Feb 10 13:59:30 volumio volumio[8215]: info: CorePlayQueue::getTrack 0 Feb 10 13:59:30 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 13:59:30 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:59:30 volumio systemd[1]: shairport-sync.service: Consumed 2.323s CPU time. Feb 10 13:59:30 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:59:30 volumio sudo[8488]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:30 volumio sudo[8486]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:30 volumio sudo[8490]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:31 volumio volumio[8215]: info: Shairport-Sync Started Feb 10 13:59:31 volumio volumio[8215]: Error adding Membership: Error: addMembership EINVAL Feb 10 13:59:31 volumio volumio[8215]: info: Shairport-Sync Started Feb 10 13:59:31 volumio volumio[8215]: info: Shairport-Sync Started Feb 10 13:59:31 volumio volumio[8215]: 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 10 13:59:31 volumio volumio[8215]: info: Spotify Successfully logged in Feb 10 13:59:31 volumio volumio[8215]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:59:31 volumio volumio[8215]: info: [1770706771245] CoreMusicLibrary::Adding element Spotify Feb 10 13:59:31 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:59:31 volumio volumio[8215]: Cannot find translation for source YouTube Music Feb 10 13:59:31 volumio volumio[8215]: Cannot find translation for source Spotify Feb 10 13:59:31 volumio volumio[8215]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 10 13:59:31 volumio volumio[8215]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:59:32 volumio volumio[8215]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:59:32 volumio volumio[8215]: info: CoreCommandRouter::volumioGetState Feb 10 13:59:32 volumio volumio[8215]: info: CorePlayQueue::getTrack 0 Feb 10 13:59:32 volumio volumio[8215]: info: CoreStateMachine::pushState Feb 10 13:59:32 volumio volumio[8215]: info: CorePlayQueue::getTrack 0 Feb 10 13:59:32 volumio volumio[8215]: info: CoreCommandRouter::volumioPushState Feb 10 13:59:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 10 13:59:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:33 volumio go-librespot[8518]: go-librespot daemon starting... Feb 10 13:59:33 volumio go-librespot[8519]: time="2026-02-10T13:59:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:59:33 volumio go-librespot[8519]: time="2026-02-10T13:59:33+07:00" level=debug msg="app state loaded" Feb 10 13:59:33 volumio go-librespot[8519]: time="2026-02-10T13:59:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:59:33 volumio volumio[8215]: info: go-librespot daemon successfully initialized Feb 10 13:59:33 volumio go-librespot[8519]: time="2026-02-10T13:59:33+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 10 13:59:33 volumio go-librespot[8519]: time="2026-02-10T13:59:33+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 10 13:59:33 volumio go-librespot[8519]: time="2026-02-10T13:59:33+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 10 13:59:33 volumio go-librespot[8519]: time="2026-02-10T13:59:33+07:00" level=info msg="zeroconf server listening on port 35691" Feb 10 13:59:33 volumio mpd[8440]: 2026-02-10T13:59:33 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 13:59:33 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 13:59:33 volumio sudo[8410]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:33 volumio sudo[8401]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:34 volumio go-librespot[8519]: time="2026-02-10T13:59:34+07:00" level=debug msg="obtained new client token: AABhsvHmiBc038gq7SUB91vJA6A+DdpIERmv2Keq7nK0kea3FSKeyRaM4U37I04udkw/dOqTH5qtKWTGOCaroaGDxw/xIfFVjiTMMoTisEd9Dyi6h4OkpIR+z0rNuyP8vDqFYM6qtywR+fNN4vZqh12giILaefUMeDJmZDkdM2D/QdhOfwzH+Psn1g6A9TkPDs7UKe3NlOGR/MsElJoBMcLi2D/lxoWalGuDpGgKi9q+IooNSNFqLOcAEg==" Feb 10 13:59:34 volumio volumio[8215]: error: MPD error: The expression evaluated to a falsy value: Feb 10 13:59:34 volumio volumio[8215]: assert.ok(self.idling) Feb 10 13:59:34 volumio volumio[8215]: error: The expression evaluated to a falsy value: Feb 10 13:59:34 volumio volumio[8215]: assert.ok(self.idling) Feb 10 13:59:34 volumio go-librespot[8519]: time="2026-02-10T13:59:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:59:34 volumio volumio[8215]: info: MPD running with PID8440 Feb 10 13:59:34 volumio volumio[8215]: ,establishing connection Feb 10 13:59:34 volumio volumio[8215]: error: updateQueue error: null Feb 10 13:59:34 volumio volumio[8215]: info: Completed starting Core Plugins Feb 10 13:59:34 volumio volumio[8215]: info: ------------------------------------------- Feb 10 13:59:34 volumio volumio[8215]: info: ----- MyVolumio plugins startup ---- Feb 10 13:59:34 volumio volumio[8215]: info: ------------------------------------------- Feb 10 13:59:34 volumio volumio[8215]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 13:59:34 volumio volumio[8215]: error: updateQueue error: null Feb 10 13:59:34 volumio go-librespot[8519]: time="2026-02-10T13:59:34+07:00" level=debug msg="completed keyexchange" Feb 10 13:59:34 volumio go-librespot[8519]: time="2026-02-10T13:59:34+07:00" level=debug msg="completed challenge" Feb 10 13:59:34 volumio go-librespot[8519]: time="2026-02-10T13:59:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:59:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:59:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:59:36 volumio volumio[8215]: info: Initializing connection to go-librespot Websocket Feb 10 13:59:36 volumio volumio[8215]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 13:59:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 10 13:59:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:37 volumio go-librespot[8544]: go-librespot daemon starting... Feb 10 13:59:37 volumio go-librespot[8545]: time="2026-02-10T13:59:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:59:37 volumio go-librespot[8545]: time="2026-02-10T13:59:37+07:00" level=debug msg="app state loaded" Feb 10 13:59:37 volumio go-librespot[8545]: time="2026-02-10T13:59:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:59:38 volumio go-librespot[8545]: time="2026-02-10T13:59:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:59:38 volumio go-librespot[8545]: time="2026-02-10T13:59:38+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 10 13:59:38 volumio go-librespot[8545]: time="2026-02-10T13:59:38+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 10 13:59:38 volumio go-librespot[8545]: time="2026-02-10T13:59:38+07:00" level=info msg="zeroconf server listening on port 38909" Feb 10 13:59:38 volumio go-librespot[8545]: time="2026-02-10T13:59:38+07:00" level=debug msg="obtained new client token: AAAx3RR4GrwMMEbMk5w6n0WGhIM3DoJhGxnVpRFnCOa/Sm1ZzMQbVT+iyGglaBWAAQf55EbMMjNsP1IC4BEyz1c73U4M2dvyTRMsiXxJ2AZl5kUuVMWvaavmcwY+bLplvbId8X5GiSS7RW2K87QL6yf/RRSvC3lLHKRt4jumjblHLO8P4BhL8DVgSRdVe9s6qP5/oJLJ0oc6s9nEMRulc+Wi+c2gGIFuMU4IKcV1I+pKXh5yrYrc/J8iwg==" Feb 10 13:59:38 volumio go-librespot[8545]: time="2026-02-10T13:59:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:59:38 volumio go-librespot[8545]: time="2026-02-10T13:59:38+07:00" level=debug msg="completed keyexchange" Feb 10 13:59:38 volumio go-librespot[8545]: time="2026-02-10T13:59:38+07:00" level=debug msg="completed challenge" Feb 10 13:59:38 volumio go-librespot[8545]: time="2026-02-10T13:59:38+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 10 13:59:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:59:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:59:38 volumio volumio[8215]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 10 13:59:39 volumio volumio[8215]: info: Initializing connection to go-librespot Websocket Feb 10 13:59:39 volumio volumio[8215]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 13:59:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 10 13:59:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:41 volumio go-librespot[8553]: go-librespot daemon starting... Feb 10 13:59:41 volumio go-librespot[8554]: time="2026-02-10T13:59:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:59:41 volumio go-librespot[8554]: time="2026-02-10T13:59:41+07:00" level=debug msg="app state loaded" Feb 10 13:59:41 volumio go-librespot[8554]: time="2026-02-10T13:59:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:59:42 volumio go-librespot[8554]: time="2026-02-10T13:59:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:59:42 volumio go-librespot[8554]: time="2026-02-10T13:59:42+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 10 13:59:42 volumio go-librespot[8554]: time="2026-02-10T13:59:42+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 10 13:59:42 volumio volumio[8215]: info: Initializing connection to go-librespot Websocket Feb 10 13:59:42 volumio go-librespot[8554]: time="2026-02-10T13:59:42+07:00" level=debug msg="new websocket client" Feb 10 13:59:42 volumio go-librespot[8554]: time="2026-02-10T13:59:42+07:00" level=info msg="zeroconf server listening on port 46207" Feb 10 13:59:42 volumio volumio[8215]: info: Connection to go-librespot Websocket established Feb 10 13:59:42 volumio go-librespot[8554]: time="2026-02-10T13:59:42+07:00" level=debug msg="obtained new client token: AACY5AOa3taBBPugbElOWPvl/I8593rJbZ8JjFd3UcLC/yXRxZOEzG1bbEBiaydbFcsmj1VQjEtRxDjMiyOSe8oTUy9JavuCP59kukD/8Z2WAlaAjnyYfpuTwsKwL/GMeICJRMxYhXOxihjJqyeFeYqMkIg9Y3fWk/hPEWEjVhWLBwo9Np6GAsA65lZkt4pT+YkIgrr75lhOtY5ZWXvC3yyj/3azSoNZipeU9AkyUfKuoNwOvjvw4ymH/g==" Feb 10 13:59:42 volumio go-librespot[8554]: time="2026-02-10T13:59:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:59:42 volumio go-librespot[8554]: time="2026-02-10T13:59:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:59:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:59:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:59:42 volumio volumio[8215]: info: Connection to go-librespot Websocket closed Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 10 13:59:42 volumio volumio[8215]: info: Adding plugin bluetooth to MyMusic Plugins Feb 10 13:59:42 volumio volumio[8215]: info: Adding plugin multiroom to MyMusic Plugins Feb 10 13:59:42 volumio volumio[8215]: info: Adding plugin metavolumio to MyMusic Plugins Feb 10 13:59:42 volumio volumio[8215]: info: Adding plugin cd_controller to MyMusic Plugins Feb 10 13:59:42 volumio volumio[8215]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 10 13:59:42 volumio volumio[8215]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 10 13:59:42 volumio volumio[8215]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 10 13:59:42 volumio volumio[8215]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 10 13:59:44 volumio volumio[8215]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 10 13:59:44 volumio volumio[8215]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 10 13:59:44 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:59:44 volumio volumio[8215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:59:44 volumio volumio[8215]: info: Starting MyVolumio Remote Streaming Endpoints Feb 10 13:59:44 volumio volumio[8215]: info: MyVolumio login type: Token Feb 10 13:59:44 volumio volumio[8215]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 10 13:59:44 volumio volumio[8215]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 10 13:59:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 10 13:59:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:46 volumio go-librespot[8576]: go-librespot daemon starting... Feb 10 13:59:46 volumio go-librespot[8577]: time="2026-02-10T13:59:46+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:59:46 volumio go-librespot[8577]: time="2026-02-10T13:59:46+07:00" level=debug msg="app state loaded" Feb 10 13:59:46 volumio go-librespot[8577]: time="2026-02-10T13:59:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:59:46 volumio volumio[8215]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 10 13:59:46 volumio volumio[8215]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 10 13:59:46 volumio volumio[8215]: info: Streaming services startup Feb 10 13:59:46 volumio volumio[8215]: info: Starting Streaming Daemon Feb 10 13:59:46 volumio sudo[8585]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 10 13:59:46 volumio sudo[8585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:46 volumio go-librespot[8577]: time="2026-02-10T13:59:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 13:59:46 volumio go-librespot[8577]: time="2026-02-10T13:59:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 13:59:46 volumio go-librespot[8577]: time="2026-02-10T13:59:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 13:59:46 volumio volumio[8215]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 10 13:59:46 volumio go-librespot[8577]: time="2026-02-10T13:59:46+07:00" level=info msg="zeroconf server listening on port 38141" Feb 10 13:59:46 volumio sudo[8585]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:46 volumio volumio[8215]: info: Getting Spotify volume Feb 10 13:59:46 volumio volumio[8215]: info: Initializing connection to go-librespot Websocket Feb 10 13:59:46 volumio volumio[8215]: error: Cannot start Volumio Streaming Daemon Feb 10 13:59:46 volumio volumio[8215]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 10 13:59:46 volumio volumio[8215]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 10 13:59:46 volumio go-librespot[8577]: time="2026-02-10T13:59:46+07:00" level=debug msg="new websocket client" Feb 10 13:59:46 volumio volumio[8215]: 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 10 13:59:46 volumio go-librespot[8577]: time="2026-02-10T13:59:46+07:00" level=debug msg="obtained new client token: AAAJpI+UX+Zec8c0dpPjl3YRwEKw2j0WdzzvaAaVswWrQchTTUIyOFfK8QE0XyDmh8kkLLaYFE1D1bIXpdT4usyTjZnyfh96WH2aIJz7OLtGSuGDhZAAZJd+6WhXo7dtobCD8dYDEl3gdBEpxdzjD5Gb/KhuLdjQNS6xjwfxtMtRRuxDo+O/1gRwGWlwv8SkxGUUqb96OCfVMDbl0qYdgmxknNq0XYVRYKzq7I3xy498/egiSXUg89x6+g==" Feb 10 13:59:46 volumio volumio[8215]: info: Connection to go-librespot Websocket established Feb 10 13:59:47 volumio go-librespot[8577]: time="2026-02-10T13:59:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:59:47 volumio go-librespot[8577]: time="2026-02-10T13:59:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:59:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:59:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:59:47 volumio volumio[8215]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 13:59:47 volumio volumio[8215]: Error: socket hang up Feb 10 13:59:47 volumio volumio[8215]: at connResetException (node:internal/errors:720:14) Feb 10 13:59:47 volumio volumio[8215]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 10 13:59:47 volumio volumio[8215]: at Socket.emit (node:events:526:35) Feb 10 13:59:47 volumio volumio[8215]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 10 13:59:47 volumio volumio[8215]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 10 13:59:47 volumio volumio[8215]: code: 'ECONNRESET', Feb 10 13:59:47 volumio volumio[8215]: response: undefined Feb 10 13:59:47 volumio volumio[8215]: } Feb 10 13:59:47 volumio volumio[8215]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 13:59:48 volumio sudo[8606]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 13:58' Feb 10 13:59:48 volumio sudo[8606]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:48 volumio sudo[8606]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:49 volumio volumio-remote-updater[643]: [2026-02-10 13:59:49] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 10 13:59:49 volumio volumio-remote-updater[643]: [2026-02-10 13:59:49] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 10 13:59:49 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:59:49 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 10 13:59:49 volumio systemd[1]: volumio.service: Consumed 55.382s CPU time. Feb 10 13:59:49 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 13:59:49 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 13:59:49 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10327. Feb 10 13:59:49 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 13:59:49 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 10 13:59:49 volumio systemd[1]: volumio.service: Consumed 55.382s CPU time. Feb 10 13:59:49 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 10 13:59:49 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 13:59:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 10 13:59:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:50 volumio go-librespot[8641]: go-librespot daemon starting... Feb 10 13:59:50 volumio go-librespot[8643]: time="2026-02-10T13:59:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:59:50 volumio go-librespot[8643]: time="2026-02-10T13:59:50+07:00" level=debug msg="app state loaded" Feb 10 13:59:50 volumio go-librespot[8643]: time="2026-02-10T13:59:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:59:50 volumio go-librespot[8643]: time="2026-02-10T13:59:50+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 10 13:59:50 volumio go-librespot[8643]: time="2026-02-10T13:59:50+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 10 13:59:50 volumio go-librespot[8643]: time="2026-02-10T13:59:50+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 10 13:59:50 volumio go-librespot[8643]: time="2026-02-10T13:59:50+07:00" level=info msg="zeroconf server listening on port 44113" Feb 10 13:59:51 volumio go-librespot[8643]: time="2026-02-10T13:59:51+07:00" level=debug msg="obtained new client token: AACkMKUqHAWvEnxtO/04U+l3McCiEtqEsnTp5LDDQaZ+pR/SQp24hMvJB+rN1fAmetlpQv1wrVyBP4jra1VcuhYkkFKdjd/6Yi3w45Xx9VSitS57BC6B8aqAgTu8kHfxcQHhXenHoqZCtUjeULkgVNAtv6A7sltJ5WwJxAHnLBkC0hhLsl1nokKUls0PeQg4iusRHc8uE3baynuUT24bhwAV/b1oVoeHft+sxgE8XuV6W6/715PZA1I=" Feb 10 13:59:51 volumio go-librespot[8643]: time="2026-02-10T13:59:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:59:51 volumio go-librespot[8643]: time="2026-02-10T13:59:51+07:00" level=debug msg="completed keyexchange" Feb 10 13:59:51 volumio go-librespot[8643]: time="2026-02-10T13:59:51+07:00" level=debug msg="completed challenge" Feb 10 13:59:51 volumio go-librespot[8643]: time="2026-02-10T13:59:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:59:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:59:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:59:52 volumio volumio[8626]: info: ------------------------------------------- Feb 10 13:59:52 volumio volumio[8626]: info: ----- Volumio3 ---- Feb 10 13:59:52 volumio volumio[8626]: info: ------------------------------------------- Feb 10 13:59:52 volumio volumio[8626]: info: ----- System startup ---- Feb 10 13:59:52 volumio volumio[8626]: info: ------------------------------------------- Feb 10 13:59:54 volumio volumio-remote-updater[643]: [2026-02-10 13:59:54] [connect] Successful connection Feb 10 13:59:54 volumio volumio[8626]: info: MYVOLUMIO Environment detected Feb 10 13:59:54 volumio volumio[8626]: info: Plugin folders cleanup Feb 10 13:59:54 volumio volumio[8626]: info: Scanning into folder /volumio/app/plugins/ Feb 10 13:59:54 volumio volumio[8626]: info: Scanning category audio_interface Feb 10 13:59:54 volumio volumio[8626]: info: Scanning category miscellanea Feb 10 13:59:54 volumio volumio[8626]: info: Scanning category music_service Feb 10 13:59:54 volumio volumio[8626]: info: Scanning category plugins.json Feb 10 13:59:54 volumio volumio[8626]: info: Scanning category system_controller Feb 10 13:59:54 volumio volumio[8626]: info: Scanning category user_interface Feb 10 13:59:54 volumio volumio[8626]: info: Scanning into folder /data/plugins/ Feb 10 13:59:54 volumio volumio[8626]: info: Scanning category music_service Feb 10 13:59:54 volumio volumio[8626]: info: Plugin folders cleanup completed Feb 10 13:59:54 volumio volumio[8626]: info: ------------------------------------------- Feb 10 13:59:54 volumio volumio[8626]: info: ----- Core plugins startup ---- Feb 10 13:59:54 volumio volumio[8626]: info: ------------------------------------------- Feb 10 13:59:54 volumio volumio[8626]: info: Loading plugins from folder /volumio/app/plugins/ Feb 10 13:59:54 volumio volumio[8626]: info: Adding plugin upnp to MyMusic Plugins Feb 10 13:59:54 volumio volumio[8626]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 10 13:59:54 volumio volumio[8626]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 10 13:59:54 volumio volumio[8626]: info: Loading plugins from folder /data/plugins/ Feb 10 13:59:54 volumio volumio[8626]: info: Loading plugin "system"... Feb 10 13:59:54 volumio volumio[8626]: info: Loading plugin "appearance"... Feb 10 13:59:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 10 13:59:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:54 volumio go-librespot[8662]: go-librespot daemon starting... Feb 10 13:59:54 volumio go-librespot[8663]: time="2026-02-10T13:59:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:59:54 volumio go-librespot[8663]: time="2026-02-10T13:59:54+07:00" level=debug msg="app state loaded" Feb 10 13:59:54 volumio go-librespot[8663]: time="2026-02-10T13:59:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:59:55 volumio go-librespot[8663]: time="2026-02-10T13:59:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 13:59:55 volumio go-librespot[8663]: time="2026-02-10T13:59:55+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 13:59:55 volumio go-librespot[8663]: time="2026-02-10T13:59:55+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 13:59:55 volumio go-librespot[8663]: time="2026-02-10T13:59:55+07:00" level=info msg="zeroconf server listening on port 42807" Feb 10 13:59:55 volumio go-librespot[8663]: time="2026-02-10T13:59:55+07:00" level=debug msg="obtained new client token: AADtMh5XdkqHQv7sy6GPRPfynmU8+RJrLWJWHGAHYZ3dd4Nr4JNX5UkkkFObB6UeGiYPWP3FfaglD5Sltk7Amg2eFYmOwTbY4K0W3HqaeD+QZgf365/bwaZPvmGioUmzLE64DmJfIZaxMvDr9AjsKrquDvOOdd1GYFfLPE018qyU0EY180AYGZXNUIStw09I8ibLuZ1lU1UF5/ghX8cftTbd7oZ5ETtQu1Tu8tVSMA9ntgTZwhkW2al67g==" Feb 10 13:59:55 volumio go-librespot[8663]: time="2026-02-10T13:59:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:59:55 volumio go-librespot[8663]: time="2026-02-10T13:59:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:59:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:59:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:59:56 volumio volumio[8626]: info: Loading plugin "network"... Feb 10 13:59:56 volumio volumio[8626]: info: Refreshing Cached IP Addresses Feb 10 13:59:56 volumio sudo[8671]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 13:59:56 volumio sudo[8671]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:56 volumio volumio[8626]: info: Loading plugin "services"... Feb 10 13:59:56 volumio sudo[8673]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 13:59:56 volumio volumio[8626]: info: Loading plugin "alsa_controller"... Feb 10 13:59:56 volumio sudo[8671]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:56 volumio sudo[8673]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:56 volumio sudo[8673]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:56 volumio sudo[8685]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 10 13:59:56 volumio sudo[8685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:59:56 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:59:56 volumio volumio[8626]: info: Loading plugin "wizard"... Feb 10 13:59:56 volumio volumio[8626]: info: Loading plugin "networkfs"... Feb 10 13:59:56 volumio volumio[8626]: info: Starting Udev Watcher for removable devices Feb 10 13:59:56 volumio volumio[8626]: info: Ignoring mount for partition: boot Feb 10 13:59:56 volumio volumio[8626]: info: Ignoring mount for partition: volumio Feb 10 13:59:56 volumio volumio[8626]: info: Ignoring mount for partition: volumio_data Feb 10 13:59:56 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:59:56 volumio volumio[8626]: info: Loading plugin "volumio_command_line_client"... Feb 10 13:59:56 volumio volumio[8626]: info: Loading plugin "upnp"... Feb 10 13:59:56 volumio volumio[8626]: info: [1770706796846] Starting Upmpd Daemon Feb 10 13:59:56 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:59:56 volumio volumio[8626]: info: Loading plugin "my_music"... Feb 10 13:59:56 volumio volumio[8626]: info: Loading plugin "mpd"... Feb 10 13:59:57 volumio volumio[8626]: info: Loading plugin "upnp_browser"... Feb 10 13:59:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 10 13:59:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:59:58 volumio go-librespot[8704]: go-librespot daemon starting... Feb 10 13:59:58 volumio go-librespot[8705]: time="2026-02-10T13:59:58+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:59:58 volumio go-librespot[8705]: time="2026-02-10T13:59:58+07:00" level=debug msg="app state loaded" Feb 10 13:59:58 volumio go-librespot[8705]: time="2026-02-10T13:59:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:59:59 volumio sudo[8685]: pam_unix(sudo:session): session closed for user root Feb 10 13:59:59 volumio go-librespot[8705]: time="2026-02-10T13:59:59+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 10 13:59:59 volumio go-librespot[8705]: time="2026-02-10T13:59:59+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 10 13:59:59 volumio go-librespot[8705]: time="2026-02-10T13:59:59+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 10 13:59:59 volumio go-librespot[8705]: time="2026-02-10T13:59:59+07:00" level=info msg="zeroconf server listening on port 45593" Feb 10 13:59:59 volumio go-librespot[8705]: time="2026-02-10T13:59:59+07:00" level=debug msg="obtained new client token: AADQyl6MmevrnLFnsnLJ7suFmQGHh3l9zrMW/jqzdRbhhzEUU0U4c2OZOAMBlWsiz53Wn1aC5IvPjg001TQxEE0sHXhP9A8x3OvX3lG1eyV/23g8vhtTrXA3Ll7R8OiYHELS7172//mKSgCmfiRbyb8ttxm53PqkpHNv+YJCzgPoFV4/W+fFScLwwYrrWGSpX9r20k7LA3YlDANalQmpT7D3YqGFM/GFRIUTCNxdRyiFgn8NBO5xjd8MuQ==" Feb 10 13:59:59 volumio go-librespot[8705]: time="2026-02-10T13:59:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:59:59 volumio go-librespot[8705]: time="2026-02-10T13:59:59+07:00" level=debug msg="completed keyexchange" Feb 10 13:59:59 volumio go-librespot[8705]: time="2026-02-10T13:59:59+07:00" level=debug msg="completed challenge" Feb 10 13:59:59 volumio go-librespot[8705]: time="2026-02-10T13:59:59+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 10 14:00:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:00:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:00:00 volumio volumio[8626]: info: Starting UPNP Browser Feb 10 14:00:00 volumio volumio[8626]: info: Loading plugin "alarm-clock"... Feb 10 14:00:00 volumio volumio[8626]: info: Loading plugin "airplay_emulation"... Feb 10 14:00:00 volumio volumio[8626]: info: Starting Shairport Sync Feb 10 14:00:00 volumio volumio[8626]: info: Loading plugin "last_100"... Feb 10 14:00:00 volumio volumio[8626]: info: Loading plugin "webradio"... Feb 10 14:00:00 volumio volumio[8626]: info: Loading plugin "i2s_dacs"... Feb 10 14:00:01 volumio volumio[8626]: info: Loading plugin "volumiodiscovery"... Feb 10 14:00:01 volumio volumio[8626]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 14:00:01 volumio volumio[8626]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 14:00:01 volumio volumio[8626]: *** WARNING *** For more information see Feb 10 14:00:01 volumio volumio[8626]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 14:00:01 volumio volumio[8626]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 14:00:01 volumio volumio[8626]: *** WARNING *** For more information see Feb 10 14:00:01 volumio node[8626]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 14:00:01 volumio node[8626]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 14:00:01 volumio node[8626]: *** WARNING *** For more information see Feb 10 14:00:01 volumio node[8626]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 14:00:01 volumio node[8626]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 14:00:01 volumio node[8626]: *** WARNING *** For more information see Feb 10 14:00:01 volumio volumio[8626]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 14:00:01 volumio volumio[8626]: info: Discovery: Started advertising with name: Volumio Feb 10 14:00:01 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 14:00:01 volumio volumio[8626]: info: Loading plugin "spop"... Feb 10 14:00:02 volumio volumio[8626]: info: Loading plugin "ytcr"... Feb 10 14:00:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 10 14:00:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:00:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:00:03 volumio go-librespot[8717]: go-librespot daemon starting... Feb 10 14:00:03 volumio go-librespot[8718]: time="2026-02-10T14:00:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:00:03 volumio go-librespot[8718]: time="2026-02-10T14:00:03+07:00" level=debug msg="app state loaded" Feb 10 14:00:03 volumio go-librespot[8718]: time="2026-02-10T14:00:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:00:03 volumio go-librespot[8718]: time="2026-02-10T14:00: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-gew1.spotify.com:80]" Feb 10 14:00:03 volumio go-librespot[8718]: time="2026-02-10T14:00:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 14:00:03 volumio go-librespot[8718]: time="2026-02-10T14:00:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 14:00:03 volumio go-librespot[8718]: time="2026-02-10T14:00:03+07:00" level=info msg="zeroconf server listening on port 37267" Feb 10 14:00:03 volumio go-librespot[8718]: time="2026-02-10T14:00:03+07:00" level=debug msg="obtained new client token: AADzECBhI4DO3nnPfpsNqz/q3NTVEBkFGjfkhwnU+t7F5Rme0nuJ+V2Vo85qHiZLRLgiTPOPd233ZWG9oJcGngeKNGua5RbbEyndd5MccYauJ1nzH4AuiqoxC8ZWVP5F3ES2Lx0fC4jLUXioWCAyEIeAn01nPsE34pFzJ7PfrxOBahCUQ1A7kLxKysomdtUK08gRVKsoiusSQ7nNAhONvJARV6VtMKCadBn3xDMjVaURZg7MDuxzdiFijw==" Feb 10 14:00:04 volumio go-librespot[8718]: time="2026-02-10T14:00:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 14:00:04 volumio go-librespot[8718]: time="2026-02-10T14:00:04+07:00" level=debug msg="completed keyexchange" Feb 10 14:00:04 volumio go-librespot[8718]: time="2026-02-10T14:00:04+07:00" level=debug msg="completed challenge" Feb 10 14:00:04 volumio go-librespot[8718]: time="2026-02-10T14:00:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:00:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:00:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:00:05 volumio volumio[8626]: info: Loading plugin "ytmusic"... Feb 10 14:00:06 volumio volumio-remote-updater[643]: [2026-02-10 14:00:06] [connect] Successful connection Feb 10 14:00:06 volumio volumio[8626]: info: Loading plugin "outputs"... Feb 10 14:00:06 volumio volumio[8626]: info: Loading plugin "albumart"... Feb 10 14:00:06 volumio volumio[8626]: info: Plugin example_plugin is not enabled Feb 10 14:00:06 volumio volumio[8626]: info: Loading plugin "inputs"... Feb 10 14:00:06 volumio volumio[8626]: info: Loading plugin "updater_comm"... Feb 10 14:00:06 volumio volumio[8626]: info: Plugin mpdemulation is not enabled Feb 10 14:00:06 volumio volumio[8626]: info: Loading plugin "rest_api"... Feb 10 14:00:06 volumio volumio[8626]: info: Loading plugin "websocket"... Feb 10 14:00:07 volumio volumio[8626]: info: Starting Socket.io Server version 1.7.4 Feb 10 14:00:07 volumio volumio[8626]: info: Loading plugin "RoonBridge"... Feb 10 14:00:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 10 14:00:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:00:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:00:07 volumio go-librespot[8749]: go-librespot daemon starting... Feb 10 14:00:07 volumio go-librespot[8750]: time="2026-02-10T14:00:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:00:07 volumio go-librespot[8750]: time="2026-02-10T14:00:07+07:00" level=debug msg="app state loaded" Feb 10 14:00:07 volumio go-librespot[8750]: time="2026-02-10T14:00:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:00:07 volumio volumio[8626]: info: Applying required configuration parameters for plugin RoonBridge Feb 10 14:00:07 volumio volumio[8626]: info: Loading i18n strings for locale en Feb 10 14:00:07 volumio volumio[8626]: Updating browse sources language Feb 10 14:00:07 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:00:07 volumio volumio[8739]: Forking 3 albumart workers Feb 10 14:00:07 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 14:00:07 volumio volumio[8626]: info: CoreCommandRouter::initPlayerControls Feb 10 14:00:07 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:07 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:07 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:07 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:07 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:07 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:07 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:07 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:07 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 14:00:07 volumio volumio[8626]: Express server listening on port 3000 Feb 10 14:00:07 volumio volumio[8626]: [Metrics] WebUI: 15s 973.98ms Feb 10 14:00:08 volumio volumio[8626]: info: CoreStateMachine::resetVolumioState Feb 10 14:00:08 volumio volumio[8626]: info: CoreStateMachine::getcurrentVolume Feb 10 14:00:08 volumio volumio[8626]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 14:00:08 volumio go-librespot[8750]: time="2026-02-10T14:00:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:00:08 volumio go-librespot[8750]: time="2026-02-10T14:00:08+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 10 14:00:08 volumio go-librespot[8750]: time="2026-02-10T14:00:08+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 10 14:00:08 volumio go-librespot[8750]: time="2026-02-10T14:00:08+07:00" level=info msg="zeroconf server listening on port 43753" Feb 10 14:00:08 volumio sudo[8791]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 14:00:08 volumio sudo[8791]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:00:08 volumio sudo[8791]: pam_unix(sudo:session): session closed for user root Feb 10 14:00:08 volumio sudo[8793]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 14:00:08 volumio sudo[8793]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:00:08 volumio volumio[8626]: info: Volumio Network Manager: Network status updated: 1 Feb 10 14:00:08 volumio sudo[8793]: pam_unix(sudo:session): session closed for user root Feb 10 14:00:08 volumio go-librespot[8750]: time="2026-02-10T14:00:08+07:00" level=debug msg="obtained new client token: AAAT3o+2XzlzMc7chveBITyn1Nk78ti+w7IQSMOzN8D7opQLCuf9NJlYPPCGUHEo+fZkgAlGsZbbNxGo0qXUqbdxsdpZzTOZrBTtlSci9XK7zJAXCp3UaMXW4oqKYkMSuxgGJuC0mTeBkRQmnpWRv5FjElNLU0Z/rBrv0OzsPx5BXxAeHP5Af39L6eJEXAGJ+Do/3y5LXEr3N1dkQwRYLsmDiKVhQhuwk0+qEf2gzReE9MYKomAQ0UUDVg==" Feb 10 14:00:08 volumio go-librespot[8750]: time="2026-02-10T14:00:08+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 10 14:00:08 volumio go-librespot[8750]: time="2026-02-10T14:00:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 10 14:00:08 volumio volumio[8626]: info: VolumeController:: Volume=100 Mute =false Feb 10 14:00:08 volumio volumio[8626]: info: CoreStateMachine::pushState Feb 10 14:00:08 volumio volumio[8626]: info: CorePlayQueue::getTrack 0 Feb 10 14:00:08 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 14:00:08 volumio volumio[8626]: info: CoreCommandRouter::volumioPushState Feb 10 14:00:08 volumio volumio[8626]: info: CoreStateMachine::updateTrackBlock Feb 10 14:00:08 volumio volumio[8626]: info: CorePlayQueue::getTrackBlock Feb 10 14:00:08 volumio volumio[8626]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 14:00:08 volumio volumio-remote-updater[643]: [2026-02-10 14:00:08] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770706806 101 Feb 10 14:00:08 volumio go-librespot[8750]: time="2026-02-10T14:00:08+07:00" level=debug msg="completed keyexchange" Feb 10 14:00:08 volumio go-librespot[8750]: time="2026-02-10T14:00:08+07:00" level=debug msg="completed challenge" Feb 10 14:00:08 volumio volumio[8626]: 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 10 14:00:08 volumio go-librespot[8750]: time="2026-02-10T14:00:08+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 10 14:00:08 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:00:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:00:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:00:08 volumio volumio[8626]: info: Reloading queue from file Feb 10 14:00:08 volumio volumio[8626]: info: CoreStateMachine::setRepeat null single undefined Feb 10 14:00:08 volumio volumio[8626]: info: CoreStateMachine::pushState Feb 10 14:00:08 volumio volumio[8626]: info: CorePlayQueue::getTrack 0 Feb 10 14:00:08 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 14:00:08 volumio volumio[8626]: info: CoreCommandRouter::volumioPushState Feb 10 14:00:08 volumio volumio[8626]: info: CoreStateMachine::setRandom null Feb 10 14:00:08 volumio volumio[8626]: info: CoreStateMachine::pushState Feb 10 14:00:08 volumio volumio[8626]: info: CorePlayQueue::getTrack 0 Feb 10 14:00:08 volumio volumio[8626]: info: CoreCommandRouter::volumioPushState Feb 10 14:00:08 volumio volumio[8626]: info: Setting Device type: Raspberry PI Feb 10 14:00:09 volumio volumio[8626]: info: Completed loading Core Plugins Feb 10 14:00:09 volumio volumio[8626]: info: Preparing to generate the ALSA configuration file Feb 10 14:00:09 volumio volumio[8626]: info: VolumeController:: Volume=100 Mute =false Feb 10 14:00:09 volumio volumio[8626]: info: CoreStateMachine::pushState Feb 10 14:00:09 volumio volumio[8626]: info: CorePlayQueue::getTrack 0 Feb 10 14:00:09 volumio volumio[8626]: info: CoreCommandRouter::volumioPushState Feb 10 14:00:09 volumio volumio[8626]: info: Asound.conf file unchanged, so no further update is needed Feb 10 14:00:09 volumio volumio[8626]: info: Output device has changed, restarting MPD Feb 10 14:00:09 volumio sudo[8809]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 14:00:09 volumio volumio[8626]: info: Output device has changed, restarting Shairport Sync Feb 10 14:00:09 volumio sudo[8809]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:00:09 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:09 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:00:09 volumio sudo[8811]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 14:00:09 volumio sudo[8811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:00:09 volumio sudo[8811]: pam_unix(sudo:session): session closed for user root Feb 10 14:00:09 volumio sudo[8813]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 14:00:09 volumio sudo[8813]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:00:09 volumio sudo[8809]: pam_unix(sudo:session): session closed for user root Feb 10 14:00:09 volumio volumio[8626]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 14:00:09 volumio volumio[8626]: info: ___________ START PLUGINS ___________ Feb 10 14:00:09 volumio volumio[8626]: info: ControllerMpd::onStart: Initializing MPD Feb 10 14:00:09 volumio volumio[8626]: info: Creating MPD Configuration file Feb 10 14:00:09 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 14:00:09 volumio sudo[8822]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 14:00:09 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 14:00:09 volumio volumio[8626]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:00:09 volumio volumio[8626]: info: [1770706809539] CoreMusicLibrary::Adding element Media Servers Feb 10 14:00:09 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:00:09 volumio sudo[8822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:00:09 volumio sudo[8822]: pam_unix(sudo:session): session closed for user root Feb 10 14:00:09 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 14:00:09 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 14:00:09 volumio systemd[1]: mpd.service: Consumed 7.119s CPU time. Feb 10 14:00:09 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 14:00:09 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 14:00:09 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 14:00:09 volumio volumio[8626]: info: UPNP Browser: Client initialized successfully Feb 10 14:00:09 volumio sudo[8824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 14:00:09 volumio sudo[8824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:00:09 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:09 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:00:09 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 14:00:09 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 14:00:09 volumio volumio[8626]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 14:00:09 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:09 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:00:09 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 14:00:09 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 14:00:09 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 14:00:09 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 14:00:09 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 14:00:09 volumio volumio[8626]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 14:00:09 volumio volumio[8626]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:00:09 volumio volumio[8626]: info: [1770706809862] CoreMusicLibrary::Adding element Last_100 Feb 10 14:00:09 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:00:09 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 14:00:09 volumio volumio[8626]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:00:09 volumio volumio[8626]: info: [1770706809886] CoreMusicLibrary::Adding element Webradio Feb 10 14:00:09 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:00:09 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 14:00:09 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 14:00:09 volumio volumio[8626]: info: Initializing BBC Radios Feb 10 14:00:10 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 14:00:10 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:00:10 volumio volumio[8626]: info: Creating Spotify config file Feb 10 14:00:10 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:10 volumio sudo[8839]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 14:00:10 volumio sudo[8839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 14:00:10 volumio sudo[8839]: pam_unix(sudo:session): session closed for user root Feb 10 14:00:10 volumio volumio[8758]: Starting albumart workers Feb 10 14:00:11 volumio volumio[8759]: Starting albumart workers Feb 10 14:00:11 volumio volumio[8760]: Starting albumart workers Feb 10 14:00:11 volumio volumio[8626]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:00:11 volumio volumio[8626]: info: [1770706811416] CoreMusicLibrary::Adding element YouTube Music Feb 10 14:00:11 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:00:11 volumio volumio[8626]: Cannot find translation for source YouTube Music Feb 10 14:00:11 volumio volumio[8626]: info: Volumio Calling Home Feb 10 14:00:11 volumio sudo[8856]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 10 14:00:11 volumio sudo[8856]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:00:11 volumio sudo[8856]: pam_unix(sudo:session): session closed for user root Feb 10 14:00:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 10 14:00:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:00:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:00:12 volumio go-librespot[8861]: go-librespot daemon starting... Feb 10 14:00:12 volumio go-librespot[8862]: time="2026-02-10T14:00:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:00:12 volumio volumio[8626]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 14:00:12 volumio volumio[8626]: info: Discovery: Found device Volumio Feb 10 14:00:12 volumio volumio[8626]: info: CoreCommandRouter::volumioGetState Feb 10 14:00:12 volumio volumio[8626]: info: CorePlayQueue::getTrack 0 Feb 10 14:00:12 volumio volumio[8626]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 14:00:12 volumio volumio[8626]: info: Discovery: Found device Volumio Feb 10 14:00:12 volumio volumio[8626]: info: CoreCommandRouter::volumioGetState Feb 10 14:00:12 volumio volumio[8626]: info: CorePlayQueue::getTrack 0 Feb 10 14:00:12 volumio go-librespot[8862]: time="2026-02-10T14:00:12+07:00" level=info msg="zeroconf server listening on port 39175" Feb 10 14:00:12 volumio volumio[8626]: info: MPD Permissions set Feb 10 14:00:12 volumio volumio[8626]: info: MPD Permissions set Feb 10 14:00:12 volumio volumio[8626]: info: Upmpdcli Daemon Started Feb 10 14:00:13 volumio volumio[8626]: info: Volumio called home Feb 10 14:00:13 volumio volumio[8626]: info: Spotify config file written Feb 10 14:00:13 volumio sudo[8882]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 14:00:13 volumio sudo[8882]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:00:13 volumio volumio[8626]: 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 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:13 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 10 14:00:13 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 10 14:00:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:00:13 volumio volumio[8626]: info: No need to fix Spotify hosts Feb 10 14:00:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:00:13 volumio sudo[8882]: pam_unix(sudo:session): session closed for user root Feb 10 14:00:13 volumio go-librespot[8896]: go-librespot daemon starting... Feb 10 14:00:13 volumio go-librespot[8902]: time="2026-02-10T14:00:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:00:13 volumio go-librespot[8902]: time="2026-02-10T14:00:13+07:00" level=debug msg="app state loaded" Feb 10 14:00:13 volumio go-librespot[8902]: time="2026-02-10T14:00:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:00:14 volumio go-librespot[8902]: time="2026-02-10T14:00: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 10 14:00:14 volumio go-librespot[8902]: time="2026-02-10T14:00: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 10 14:00:14 volumio go-librespot[8902]: time="2026-02-10T14:00: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 10 14:00:14 volumio go-librespot[8902]: time="2026-02-10T14:00:14+07:00" level=info msg="zeroconf server listening on port 36947" Feb 10 14:00:14 volumio volumio[8626]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 14:00:14 volumio volumio[8626]: SPOTIFY: BQBEXvrAeXbC8aiOnxKF9C4Wj9oUYEmxLVCP1hT_tHI86q3yf_a98ZfQGw6v65JXWI1F4kRK153gK1in8jktL6qYG_kOELMUP8GsIRUDgt91Q3tF8MZaVEJtFLf29yGJdL_JSWJ9h3twzrgzxAozM5twy-Pk99gaQ-l-xHdwr_ldty_tvs6wgus2uEglczw8bQsIZFiz5iThwVD64blc5W-Mzrw3x5cosn3ac5MQFpDeTVVXNSBUcOTwYiGvl4f6jYtdWNE1l7diJtAnJlIB7lJfGliiqCG6T-GOinfOfBEah889tPFvutfV Feb 10 14:00:14 volumio volumio[8626]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 14:00:14 volumio volumio[8626]: info: New Spotify access token = BQBEXvrAeXbC8aiOnxKF9C4Wj9oUYEmxLVCP1hT_tHI86q3yf_a98ZfQGw6v65JXWI1F4kRK153gK1in8jktL6qYG_kOELMUP8GsIRUDgt91Q3tF8MZaVEJtFLf29yGJdL_JSWJ9h3twzrgzxAozM5twy-Pk99gaQ-l-xHdwr_ldty_tvs6wgus2uEglczw8bQsIZFiz5iThwVD64blc5W-Mzrw3x5cosn3ac5MQFpDeTVVXNSBUcOTwYiGvl4f6jYtdWNE1l7diJtAnJlIB7lJfGliiqCG6T-GOinfOfBEah889tPFvutfV Feb 10 14:00:14 volumio volumio[8626]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 14:00:14 volumio volumio[8626]: info: Starting Shairport Sync Feb 10 14:00:14 volumio volumio[8626]: info: Starting Shairport Sync Feb 10 14:00:14 volumio volumio[8626]: info: Starting Shairport Sync Feb 10 14:00:14 volumio sudo[8911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 14:00:14 volumio sudo[8911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:00:14 volumio go-librespot[8902]: time="2026-02-10T14:00:14+07:00" level=debug msg="obtained new client token: AADri4vPPw5wlD6mQABfyNY6p9IFT0LRWVk5aH6ODCBk4Q/J9Fijh94s3iMXktt5cMy2VEOl4fcDJF5RpGMaUrNyS7DXrUY0WPFABSvrc5+g9lmzbup6G00vwXtrQHxT+YpcscR9YC/18cIx3s/YV/qZjb9vLt5udAUOQiRGySl39csJJtB4G/bBM8/F7qUVNFSvA9FnOmBKJV2ffaG8nfgzxJbIH/Up+O0iCsDjbmSxIhCQOKYiOccPow==" Feb 10 14:00:14 volumio sudo[8913]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 14:00:14 volumio sudo[8913]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:00:14 volumio sudo[8915]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 14:00:14 volumio sudo[8915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:00:14 volumio go-librespot[8902]: time="2026-02-10T14:00:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 14:00:14 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 14:00:14 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 14:00:14 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 14:00:14 volumio systemd[1]: shairport-sync.service: Consumed 2.355s CPU time. Feb 10 14:00:14 volumio go-librespot[8902]: time="2026-02-10T14:00:14+07:00" level=debug msg="completed keyexchange" Feb 10 14:00:14 volumio go-librespot[8902]: time="2026-02-10T14:00:14+07:00" level=debug msg="completed challenge" Feb 10 14:00:14 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 14:00:14 volumio sudo[8911]: pam_unix(sudo:session): session closed for user root Feb 10 14:00:14 volumio sudo[8913]: pam_unix(sudo:session): session closed for user root Feb 10 14:00:14 volumio go-librespot[8902]: time="2026-02-10T14:00:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:00:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:00:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:00:14 volumio volumio[8626]: info: Shairport-Sync Started Feb 10 14:00:14 volumio volumio[8626]: Error adding Membership: Error: addMembership EINVAL Feb 10 14:00:14 volumio volumio[8626]: info: Shairport-Sync Started Feb 10 14:00:14 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 14:00:14 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 14:00:14 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 14:00:14 volumio volumio[8626]: info: CoreCommandRouter::volumioGetState Feb 10 14:00:14 volumio volumio[8626]: info: CorePlayQueue::getTrack 0 Feb 10 14:00:14 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 14:00:14 volumio sudo[8915]: pam_unix(sudo:session): session closed for user root Feb 10 14:00:15 volumio volumio[8626]: info: Shairport-Sync Started Feb 10 14:00:15 volumio volumio[8626]: 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 10 14:00:15 volumio volumio[8626]: info: Spotify Successfully logged in Feb 10 14:00:15 volumio volumio[8626]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:00:15 volumio volumio[8626]: info: [1770706815171] CoreMusicLibrary::Adding element Spotify Feb 10 14:00:15 volumio volumio[8626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:00:15 volumio volumio[8626]: Cannot find translation for source YouTube Music Feb 10 14:00:15 volumio volumio[8626]: Cannot find translation for source Spotify Feb 10 14:00:15 volumio volumio[8626]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 10 14:00:15 volumio volumio[8626]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 14:00:16 volumio volumio[8626]: info: VolumeController:: Volume=100 Mute =false Feb 10 14:00:16 volumio volumio[8626]: info: CoreCommandRouter::volumioGetState Feb 10 14:00:16 volumio volumio[8626]: info: CorePlayQueue::getTrack 0 Feb 10 14:00:16 volumio volumio[8626]: info: CoreStateMachine::pushState Feb 10 14:00:16 volumio volumio[8626]: info: CorePlayQueue::getTrack 0 Feb 10 14:00:16 volumio volumio[8626]: info: CoreCommandRouter::volumioPushState Feb 10 14:00:17 volumio volumio[8626]: info: go-librespot daemon successfully initialized Feb 10 14:00:17 volumio mpd[8854]: 2026-02-10T14:00:17 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 14:00:17 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 14:00:17 volumio sudo[8813]: pam_unix(sudo:session): session closed for user root Feb 10 14:00:17 volumio sudo[8824]: pam_unix(sudo:session): session closed for user root Feb 10 14:00:17 volumio volumio[8626]: error: MPD error: The expression evaluated to a falsy value: Feb 10 14:00:17 volumio volumio[8626]: assert.ok(self.idling) Feb 10 14:00:17 volumio volumio[8626]: error: The expression evaluated to a falsy value: Feb 10 14:00:17 volumio volumio[8626]: assert.ok(self.idling) Feb 10 14:00:17 volumio volumio[8626]: error: updateQueue error: null Feb 10 14:00:17 volumio volumio[8626]: info: MPD running with PID8854 Feb 10 14:00:17 volumio volumio[8626]: ,establishing connection Feb 10 14:00:17 volumio volumio[8626]: info: Completed starting Core Plugins Feb 10 14:00:17 volumio volumio[8626]: info: ------------------------------------------- Feb 10 14:00:17 volumio volumio[8626]: info: ----- MyVolumio plugins startup ---- Feb 10 14:00:17 volumio volumio[8626]: info: ------------------------------------------- Feb 10 14:00:17 volumio volumio[8626]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 14:00:17 volumio volumio[8626]: error: updateQueue error: null Feb 10 14:00:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 10 14:00:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:00:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:00:17 volumio go-librespot[8967]: go-librespot daemon starting... Feb 10 14:00:17 volumio go-librespot[8968]: time="2026-02-10T14:00:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:00:17 volumio go-librespot[8968]: time="2026-02-10T14:00:17+07:00" level=debug msg="app state loaded" Feb 10 14:00:17 volumio go-librespot[8968]: time="2026-02-10T14:00:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:00:18 volumio go-librespot[8968]: time="2026-02-10T14:00: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:00:18 volumio go-librespot[8968]: time="2026-02-10T14:00:18+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 10 14:00:18 volumio go-librespot[8968]: time="2026-02-10T14:00:18+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 10 14:00:18 volumio go-librespot[8968]: time="2026-02-10T14:00:18+07:00" level=info msg="zeroconf server listening on port 43663" Feb 10 14:00:18 volumio go-librespot[8968]: time="2026-02-10T14:00:18+07:00" level=debug msg="obtained new client token: AACOMEt+dWo0eW8rEq9BRfOnM13XW2RbR4si0iQjo4FGS55sgv2kNr22nEQ+B0e2H7D8DHV2AHXG0X1CPjuvveDRpiY6Zk7OMhUoLY1ABy7l/BmPWJ0gf78PaTtQ/ivsSoSXDgzon/UgEsl8kqDx3ia8Yozg/GwdP3HgOfIGaXO9YZk+QxsIiqoQdQLWwPRKjqKVxgizxPm3yHTj/B9ODype3LH4jlu7iN/uHRds2BEzCYBZMFUgD5sw7Q==" Feb 10 14:00:18 volumio go-librespot[8968]: time="2026-02-10T14:00:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 14:00:18 volumio go-librespot[8968]: time="2026-02-10T14:00:18+07:00" level=debug msg="completed keyexchange" Feb 10 14:00:18 volumio go-librespot[8968]: time="2026-02-10T14:00:18+07:00" level=debug msg="completed challenge" Feb 10 14:00:18 volumio go-librespot[8968]: time="2026-02-10T14:00:18+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 10 14:00:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:00:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:00:20 volumio volumio[8626]: info: Initializing connection to go-librespot Websocket Feb 10 14:00:20 volumio volumio[8626]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 14:00:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 10 14:00:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:00:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:00:22 volumio go-librespot[8975]: go-librespot daemon starting... Feb 10 14:00:22 volumio go-librespot[8976]: time="2026-02-10T14:00:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:00:22 volumio go-librespot[8976]: time="2026-02-10T14:00:22+07:00" level=debug msg="app state loaded" Feb 10 14:00:22 volumio go-librespot[8976]: time="2026-02-10T14:00:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:00:22 volumio volumio[8626]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 10 14:00:22 volumio go-librespot[8976]: time="2026-02-10T14:00:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:00:22 volumio go-librespot[8976]: time="2026-02-10T14:00:22+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:00:22 volumio go-librespot[8976]: time="2026-02-10T14:00:22+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:00:22 volumio go-librespot[8976]: time="2026-02-10T14:00:22+07:00" level=info msg="zeroconf server listening on port 39467" Feb 10 14:00:23 volumio go-librespot[8976]: time="2026-02-10T14:00:23+07:00" level=debug msg="obtained new client token: AAD4Fuehg7R3fEs1+CCq+UkbK1ATIcwj6RTEbsh7bjVcM8ERsVDyd3j4RPpfknJhYoVRTfvRU0YL3Jd+pac8Vtgc8EUIH1QzcPWygTPLxA80jm9gpLW5agGyQvKDsgEW8s+J/ffGbQ1w1ZxQRjQbWhHUBiwZimNdjjONvctACc+PYVQf1rmnMBcHaGmwC0BUDF2WsG/2/psYT8wa3cmduZxN2YhXkGbcs/An0QJhWD8HKXbPgMb0OsA=" Feb 10 14:00:23 volumio go-librespot[8976]: time="2026-02-10T14:00:23+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 10 14:00:23 volumio volumio[8626]: info: Initializing connection to go-librespot Websocket Feb 10 14:00:23 volumio go-librespot[8976]: time="2026-02-10T14:00:23+07:00" level=debug msg="new websocket client" Feb 10 14:00:23 volumio go-librespot[8976]: time="2026-02-10T14:00:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 10 14:00:23 volumio volumio[8626]: info: Connection to go-librespot Websocket established Feb 10 14:00:23 volumio go-librespot[8976]: time="2026-02-10T14:00:23+07:00" level=debug msg="completed keyexchange" Feb 10 14:00:23 volumio go-librespot[8976]: time="2026-02-10T14:00:23+07:00" level=debug msg="completed challenge" Feb 10 14:00:23 volumio go-librespot[8976]: time="2026-02-10T14:00: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 10 14:00:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:00:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:00:23 volumio volumio[8626]: info: Connection to go-librespot Websocket closed Feb 10 14:00:26 volumio volumio[8626]: info: Getting Spotify volume Feb 10 14:00:26 volumio volumio[8626]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 14:00:26 volumio volumio[8626]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 14:00:26 volumio volumio[8626]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 10 14:00:26 volumio volumio[8626]: errno: -111, Feb 10 14:00:26 volumio volumio[8626]: code: 'ECONNREFUSED', Feb 10 14:00:26 volumio volumio[8626]: syscall: 'connect', Feb 10 14:00:26 volumio volumio[8626]: address: '127.0.0.1', Feb 10 14:00:26 volumio volumio[8626]: port: 9879, Feb 10 14:00:26 volumio volumio[8626]: response: undefined Feb 10 14:00:26 volumio volumio[8626]: } Feb 10 14:00:26 volumio volumio[8626]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 14:00:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 10 14:00:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:00:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:00:26 volumio go-librespot[8995]: go-librespot daemon starting... Feb 10 14:00:26 volumio go-librespot[8996]: time="2026-02-10T14:00:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:00:26 volumio go-librespot[8996]: time="2026-02-10T14:00:26+07:00" level=debug msg="app state loaded" Feb 10 14:00:26 volumio go-librespot[8996]: time="2026-02-10T14:00:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:00:27 volumio go-librespot[8996]: time="2026-02-10T14:00:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:00:27 volumio go-librespot[8996]: time="2026-02-10T14:00:27+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 10 14:00:27 volumio go-librespot[8996]: time="2026-02-10T14:00:27+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 10 14:00:27 volumio go-librespot[8996]: time="2026-02-10T14:00:27+07:00" level=info msg="zeroconf server listening on port 41863" Feb 10 14:00:27 volumio go-librespot[8996]: time="2026-02-10T14:00:27+07:00" level=debug msg="obtained new client token: AADx4b14KJrRA9qax/GyRfm+iQ6pIHrBZNcbpI2ElBl50qRFMXMRwCsDvbokDUX48ZYoY4HySCtoVYTt9L/2Oh2spK4NCozDqtjp6CKQ/+G69RP/Trk1Bh5ct+p2XwnD0hr8dz5OVIeLbF6cPSn2inEagHvwShUoB1IJWHJzgfbHmvhuAUYpleyy+WeHsLKDLSXvQhzWgiwd26nF5xdMEGJoWRrYPVOT/hFJSShaLhC/Vz/BQIYKrms80g==" Feb 10 14:00:27 volumio go-librespot[8996]: time="2026-02-10T14:00:27+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 10 14:00:27 volumio go-librespot[8996]: time="2026-02-10T14:00:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 10 14:00:27 volumio go-librespot[8996]: time="2026-02-10T14:00:27+07:00" level=debug msg="completed keyexchange" Feb 10 14:00:27 volumio go-librespot[8996]: time="2026-02-10T14:00:27+07:00" level=debug msg="completed challenge" Feb 10 14:00:27 volumio sudo[9019]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 13:59' Feb 10 14:00:27 volumio sudo[9019]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:00:27 volumio go-librespot[8996]: time="2026-02-10T14:00: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 10 14:00:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:00:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. 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"