Feb 19 00:13:00 volumio volumio[25782]: info: Getting Spotify volume Feb 19 00:13:00 volumio volumio[25782]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 19 00:13:00 volumio volumio[25782]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 00:13:00 volumio volumio[25782]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 19 00:13:00 volumio volumio[25782]: errno: -111, Feb 19 00:13:00 volumio volumio[25782]: code: 'ECONNREFUSED', Feb 19 00:13:00 volumio volumio[25782]: syscall: 'connect', Feb 19 00:13:00 volumio volumio[25782]: address: '127.0.0.1', Feb 19 00:13:00 volumio volumio[25782]: port: 9879, Feb 19 00:13:00 volumio volumio[25782]: response: undefined Feb 19 00:13:00 volumio volumio[25782]: } Feb 19 00:13:00 volumio volumio[25782]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 19 00:13:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 19 00:13:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:00 volumio go-librespot[26139]: go-librespot daemon starting... Feb 19 00:13:00 volumio go-librespot[26140]: time="2026-02-19T00:13:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:13:00 volumio go-librespot[26140]: time="2026-02-19T00:13:00+07:00" level=debug msg="app state loaded" Feb 19 00:13:00 volumio go-librespot[26140]: time="2026-02-19T00:13:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:13:00 volumio go-librespot[26140]: time="2026-02-19T00:13:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 19 00:13:00 volumio go-librespot[26140]: time="2026-02-19T00:13:00+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 19 00:13:00 volumio go-librespot[26140]: time="2026-02-19T00:13:00+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 19 00:13:01 volumio go-librespot[26140]: time="2026-02-19T00:13:01+07:00" level=info msg="zeroconf server listening on port 40419" Feb 19 00:13:01 volumio go-librespot[26140]: time="2026-02-19T00:13:01+07:00" level=debug msg="obtained new client token: AADCzRWzonyEWXdqolimDskm7qBN5rfo1r+avY2efUYWjG9ZREH1k68UQ9yeP/V2as7KlrBLW6UueFKamG1R+2zgZEoEWb5jgs23U2wgDyF5a8CXnYiCnClq5BVBqRXRo/rM8dX5eEZLfelXEukOCeKXa01pxPZlkxuJJmy0kxo3pPfOkdrQrgER4F91ufPSNaIX5/HFGG2QfnE0VvnaN0PLQ3LGwiSaNSf9L9DdKvyqb5W/SI1Mufk=" Feb 19 00:13:01 volumio go-librespot[26140]: time="2026-02-19T00:13:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 00:13:01 volumio go-librespot[26140]: time="2026-02-19T00:13:01+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 19 00:13:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:13:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:13:01 volumio sudo[26165]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-19 00:12' Feb 19 00:13:01 volumio sudo[26165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:01 volumio sudo[26165]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:02 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:13:02 volumio volumio-remote-updater[25144]: [2026-02-19 00:13:02] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 19 00:13:02 volumio volumio-remote-updater[25144]: [2026-02-19 00:13:02] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 19 00:13:02 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 19 00:13:02 volumio systemd[1]: volumio.service: Consumed 49.537s CPU time. Feb 19 00:13:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 19 00:13:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 19 00:13:02 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22642. Feb 19 00:13:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 19 00:13:02 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 19 00:13:02 volumio systemd[1]: volumio.service: Consumed 49.537s CPU time. Feb 19 00:13:02 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 19 00:13:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 19 00:13:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 19 00:13:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:04 volumio go-librespot[26196]: go-librespot daemon starting... Feb 19 00:13:04 volumio go-librespot[26197]: time="2026-02-19T00:13:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:13:04 volumio go-librespot[26197]: time="2026-02-19T00:13:04+07:00" level=debug msg="app state loaded" Feb 19 00:13:04 volumio go-librespot[26197]: time="2026-02-19T00:13:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:13:05 volumio go-librespot[26197]: time="2026-02-19T00:13:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 19 00:13:05 volumio go-librespot[26197]: time="2026-02-19T00:13:05+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 19 00:13:05 volumio go-librespot[26197]: time="2026-02-19T00:13:05+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 19 00:13:05 volumio go-librespot[26197]: time="2026-02-19T00:13:05+07:00" level=info msg="zeroconf server listening on port 34061" Feb 19 00:13:05 volumio go-librespot[26197]: time="2026-02-19T00:13:05+07:00" level=debug msg="obtained new client token: AADM9gM54j5JJZbGbW3YoYGr0yjd10sBdK8xnSS/9riz+rrvR1YvbDwVlev3gME4Cco06wgr4Q1Q0mMDOpssZw5g+fwYB+0l6XopduOPkUuxx+71JpTsKnGnUs18sC7fHsVHS6IiUekXXRwUE3TWmEBPCR2DTD0jPazi5TRwuaZn+tMAr8SspBCdnir+e1ZIHsGx9LRfCj+2+m8YzwIjxEGryZ3UGrftWO1lQaZ8dQBIX1RaJow/9DWTWg==" Feb 19 00:13:05 volumio go-librespot[26197]: time="2026-02-19T00:13:05+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 19 00:13:05 volumio go-librespot[26197]: time="2026-02-19T00:13:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 19 00:13:05 volumio go-librespot[26197]: time="2026-02-19T00:13:05+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 19 00:13:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:13:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:13:05 volumio volumio[26178]: info: ------------------------------------------- Feb 19 00:13:05 volumio volumio[26178]: info: ----- Volumio3 ---- Feb 19 00:13:05 volumio volumio[26178]: info: ------------------------------------------- Feb 19 00:13:05 volumio volumio[26178]: info: ----- System startup ---- Feb 19 00:13:05 volumio volumio[26178]: info: ------------------------------------------- Feb 19 00:13:07 volumio volumio-remote-updater[25144]: [2026-02-19 00:13:07] [connect] Successful connection Feb 19 00:13:07 volumio volumio[26178]: info: MYVOLUMIO Environment detected Feb 19 00:13:07 volumio volumio[26178]: info: Plugin folders cleanup Feb 19 00:13:07 volumio volumio[26178]: info: Scanning into folder /volumio/app/plugins/ Feb 19 00:13:07 volumio volumio[26178]: info: Scanning category audio_interface Feb 19 00:13:07 volumio volumio[26178]: info: Scanning category miscellanea Feb 19 00:13:07 volumio volumio[26178]: info: Scanning category music_service Feb 19 00:13:07 volumio volumio[26178]: info: Scanning category plugins.json Feb 19 00:13:07 volumio volumio[26178]: info: Scanning category system_controller Feb 19 00:13:07 volumio volumio[26178]: info: Scanning category user_interface Feb 19 00:13:07 volumio volumio[26178]: info: Scanning into folder /data/plugins/ Feb 19 00:13:07 volumio volumio[26178]: info: Scanning category music_service Feb 19 00:13:07 volumio volumio[26178]: info: Plugin folders cleanup completed Feb 19 00:13:07 volumio volumio[26178]: info: ------------------------------------------- Feb 19 00:13:07 volumio volumio[26178]: info: ----- Core plugins startup ---- Feb 19 00:13:07 volumio volumio[26178]: info: ------------------------------------------- Feb 19 00:13:07 volumio volumio[26178]: info: Loading plugins from folder /volumio/app/plugins/ Feb 19 00:13:07 volumio volumio[26178]: info: Adding plugin upnp to MyMusic Plugins Feb 19 00:13:07 volumio volumio[26178]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 19 00:13:07 volumio volumio[26178]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 19 00:13:07 volumio volumio[26178]: info: Loading plugins from folder /data/plugins/ Feb 19 00:13:07 volumio volumio[26178]: info: Loading plugin "system"... Feb 19 00:13:07 volumio volumio[26178]: info: Loading plugin "appearance"... Feb 19 00:13:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 19 00:13:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:08 volumio go-librespot[26216]: go-librespot daemon starting... Feb 19 00:13:08 volumio go-librespot[26217]: time="2026-02-19T00:13:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:13:08 volumio go-librespot[26217]: time="2026-02-19T00:13:08+07:00" level=debug msg="app state loaded" Feb 19 00:13:08 volumio go-librespot[26217]: time="2026-02-19T00:13:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:13:09 volumio volumio[26178]: info: Loading plugin "network"... Feb 19 00:13:09 volumio volumio[26178]: info: Refreshing Cached IP Addresses Feb 19 00:13:09 volumio go-librespot[26217]: time="2026-02-19T00:13:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 19 00:13:09 volumio go-librespot[26217]: time="2026-02-19T00:13:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 19 00:13:09 volumio go-librespot[26217]: time="2026-02-19T00:13:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 19 00:13:09 volumio sudo[26225]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 19 00:13:09 volumio sudo[26225]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:09 volumio sudo[26227]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 19 00:13:09 volumio go-librespot[26217]: time="2026-02-19T00:13:09+07:00" level=info msg="zeroconf server listening on port 46377" Feb 19 00:13:09 volumio volumio[26178]: info: Loading plugin "services"... Feb 19 00:13:09 volumio sudo[26227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:09 volumio sudo[26225]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:09 volumio volumio[26178]: info: Loading plugin "alsa_controller"... Feb 19 00:13:09 volumio sudo[26227]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:09 volumio sudo[26238]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 19 00:13:09 volumio sudo[26238]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:09 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 19 00:13:09 volumio volumio[26178]: info: Loading plugin "wizard"... Feb 19 00:13:09 volumio volumio[26178]: info: Loading plugin "networkfs"... Feb 19 00:13:09 volumio go-librespot[26217]: time="2026-02-19T00:13:09+07:00" level=debug msg="obtained new client token: AAAZ2cLNeBHcnNirANcxxiGcBSXeS9tDuoIS5j0Xb9thivI2Jl95ZSLSHP/TDbNsVf7TZ1MEimA7ACdvd1QgLh67F3AhXaSMxX4JaY8y4/FPsCkL4PKQfz76d3muzBmCDrY6tSOshHN0k/Ar+/DwXxRJ4zc3NtoXBGSHOyHRYTiE0opJltr/2zccIk3TTMa/VxGG8usMXGXyjUlwIdFOPHp2e2NFR1XvnR7qboRUoapJcZSkC0LE9EdtEA==" Feb 19 00:13:09 volumio volumio[26178]: info: Starting Udev Watcher for removable devices Feb 19 00:13:09 volumio go-librespot[26217]: time="2026-02-19T00:13:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 00:13:09 volumio volumio[26178]: info: Ignoring mount for partition: boot Feb 19 00:13:09 volumio volumio[26178]: info: Ignoring mount for partition: volumio Feb 19 00:13:09 volumio volumio[26178]: info: Ignoring mount for partition: volumio_data Feb 19 00:13:09 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 19 00:13:09 volumio volumio[26178]: info: Loading plugin "volumio_command_line_client"... Feb 19 00:13:09 volumio volumio[26178]: info: Loading plugin "upnp"... Feb 19 00:13:09 volumio volumio[26178]: info: [1771434789855] Starting Upmpd Daemon Feb 19 00:13:09 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 19 00:13:09 volumio volumio[26178]: info: Loading plugin "my_music"... Feb 19 00:13:09 volumio volumio[26178]: info: Loading plugin "mpd"... Feb 19 00:13:09 volumio go-librespot[26217]: time="2026-02-19T00:13:09+07:00" level=debug msg="completed keyexchange" Feb 19 00:13:09 volumio go-librespot[26217]: time="2026-02-19T00:13:09+07:00" level=debug msg="completed challenge" Feb 19 00:13:09 volumio go-librespot[26217]: time="2026-02-19T00:13:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 19 00:13:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:13:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:13:10 volumio volumio[26178]: info: Loading plugin "upnp_browser"... Feb 19 00:13:12 volumio sudo[26238]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 19 00:13:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:13 volumio go-librespot[26258]: go-librespot daemon starting... Feb 19 00:13:13 volumio go-librespot[26259]: time="2026-02-19T00:13:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:13:13 volumio go-librespot[26259]: time="2026-02-19T00:13:13+07:00" level=debug msg="app state loaded" Feb 19 00:13:13 volumio go-librespot[26259]: time="2026-02-19T00:13:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:13:13 volumio volumio[26178]: info: Starting UPNP Browser Feb 19 00:13:13 volumio volumio[26178]: info: Loading plugin "alarm-clock"... Feb 19 00:13:13 volumio go-librespot[26259]: time="2026-02-19T00:13:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 19 00:13:13 volumio go-librespot[26259]: time="2026-02-19T00:13:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 19 00:13:13 volumio go-librespot[26259]: time="2026-02-19T00:13:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 19 00:13:13 volumio go-librespot[26259]: time="2026-02-19T00:13:13+07:00" level=info msg="zeroconf server listening on port 37051" Feb 19 00:13:13 volumio volumio[26178]: info: Loading plugin "airplay_emulation"... Feb 19 00:13:13 volumio volumio[26178]: info: Starting Shairport Sync Feb 19 00:13:13 volumio volumio[26178]: info: Loading plugin "last_100"... Feb 19 00:13:13 volumio volumio[26178]: info: Loading plugin "webradio"... Feb 19 00:13:14 volumio go-librespot[26259]: time="2026-02-19T00:13:14+07:00" level=debug msg="obtained new client token: AAAgYkPMfOdERQLF9tDVCJNqtBiI1y0BA1hmkk7oEz+J6vswSpvRWg6crikGZBTFTITBOSbUHzLhZXB4Xy4rqg6MnWfFK3mi1m635o98n9ubQrp604lGhC8BamiCBPZGMVCQpHqfnri6EnXOPZcbDnYjDD4pL2SrsuhwWybtwFz3IA73sPTaxPAxNnllmd3breQKHupljPOn9IyOtgXuyDfiA/Y535fu92dxjvlBFcwQepUeGX96dQ91Sg==" Feb 19 00:13:14 volumio volumio[26178]: info: Loading plugin "i2s_dacs"... Feb 19 00:13:14 volumio volumio[26178]: info: Loading plugin "volumiodiscovery"... Feb 19 00:13:14 volumio go-librespot[26259]: time="2026-02-19T00:13:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 00:13:14 volumio volumio[26178]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 19 00:13:14 volumio volumio[26178]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 19 00:13:14 volumio volumio[26178]: *** WARNING *** For more information see Feb 19 00:13:14 volumio volumio[26178]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 19 00:13:14 volumio volumio[26178]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 19 00:13:14 volumio volumio[26178]: *** WARNING *** For more information see Feb 19 00:13:14 volumio node[26178]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 19 00:13:14 volumio node[26178]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 19 00:13:14 volumio node[26178]: *** WARNING *** For more information see Feb 19 00:13:14 volumio node[26178]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 19 00:13:14 volumio node[26178]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 19 00:13:14 volumio node[26178]: *** WARNING *** For more information see Feb 19 00:13:14 volumio volumio[26178]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 19 00:13:14 volumio volumio[26178]: info: Discovery: Started advertising with name: Volumio Feb 19 00:13:14 volumio go-librespot[26259]: time="2026-02-19T00:13:14+07:00" level=debug msg="completed keyexchange" Feb 19 00:13:14 volumio go-librespot[26259]: time="2026-02-19T00:13:14+07:00" level=debug msg="completed challenge" Feb 19 00:13:14 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 19 00:13:14 volumio volumio[26178]: info: Loading plugin "spop"... Feb 19 00:13:14 volumio go-librespot[26259]: time="2026-02-19T00:13: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 19 00:13:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:13:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:13:16 volumio volumio[26178]: info: Loading plugin "ytcr"... Feb 19 00:13:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 19 00:13:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:17 volumio go-librespot[26269]: go-librespot daemon starting... Feb 19 00:13:17 volumio go-librespot[26270]: time="2026-02-19T00:13:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:13:17 volumio go-librespot[26270]: time="2026-02-19T00:13:17+07:00" level=debug msg="app state loaded" Feb 19 00:13:17 volumio go-librespot[26270]: time="2026-02-19T00:13:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:13:18 volumio go-librespot[26270]: time="2026-02-19T00:13: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 19 00:13:18 volumio go-librespot[26270]: time="2026-02-19T00:13:18+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 19 00:13:18 volumio go-librespot[26270]: time="2026-02-19T00:13:18+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 19 00:13:18 volumio go-librespot[26270]: time="2026-02-19T00:13:18+07:00" level=info msg="zeroconf server listening on port 39339" Feb 19 00:13:18 volumio go-librespot[26270]: time="2026-02-19T00:13:18+07:00" level=debug msg="obtained new client token: AAA6yYBc47jx3TzzY1p5IkFFrk9kDijFV0dPCBuci3fCdVnilc9H1CmjGkn8cti1VXwFsBXRnmWlMt9ssMOB7OjoiueYi93867NUGJ5Cn+6ZlqPWmz4QOIEWgeSInK5gxmE4FXkg4AzQwVhOQP0C9eisjF8gSNtQt95IGfQRVE2jEOE+xPbE1TRCi96Rip1DlGhdjz4yAx32rE2rYIhMLM0aMELbABtwJegJRtHcfkdwOcusKJWgvdFblg==" Feb 19 00:13:18 volumio go-librespot[26270]: time="2026-02-19T00:13:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 00:13:18 volumio go-librespot[26270]: time="2026-02-19T00:13:18+07:00" level=debug msg="completed keyexchange" Feb 19 00:13:18 volumio go-librespot[26270]: time="2026-02-19T00:13:18+07:00" level=debug msg="completed challenge" Feb 19 00:13:18 volumio go-librespot[26270]: time="2026-02-19T00:13: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 19 00:13:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:13:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:13:18 volumio volumio[26178]: info: Loading plugin "ytmusic"... Feb 19 00:13:19 volumio volumio-remote-updater[25144]: [2026-02-19 00:13:19] [connect] Successful connection Feb 19 00:13:19 volumio volumio[26178]: info: Loading plugin "outputs"... Feb 19 00:13:19 volumio volumio[26178]: info: Loading plugin "albumart"... Feb 19 00:13:19 volumio volumio[26178]: info: Plugin example_plugin is not enabled Feb 19 00:13:19 volumio volumio[26178]: info: Loading plugin "inputs"... Feb 19 00:13:19 volumio volumio[26178]: info: Loading plugin "updater_comm"... Feb 19 00:13:20 volumio volumio[26178]: info: Plugin mpdemulation is not enabled Feb 19 00:13:20 volumio volumio[26178]: info: Loading plugin "rest_api"... Feb 19 00:13:20 volumio volumio[26178]: info: Loading plugin "websocket"... Feb 19 00:13:20 volumio volumio[26178]: info: Starting Socket.io Server version 1.7.4 Feb 19 00:13:20 volumio volumio[26178]: info: Loading plugin "RoonBridge"... Feb 19 00:13:20 volumio volumio[26178]: info: Applying required configuration parameters for plugin RoonBridge Feb 19 00:13:20 volumio volumio[26178]: info: Loading i18n strings for locale en Feb 19 00:13:20 volumio volumio[26178]: Updating browse sources language Feb 19 00:13:20 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 00:13:20 volumio volumio[26292]: Forking 3 albumart workers Feb 19 00:13:21 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 00:13:21 volumio volumio[26178]: info: CoreCommandRouter::initPlayerControls Feb 19 00:13:21 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:21 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:21 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:21 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:21 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:21 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:21 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:21 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:21 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 00:13:21 volumio volumio[26178]: Express server listening on port 3000 Feb 19 00:13:21 volumio volumio[26178]: [Metrics] WebUI: 16s 212.30ms Feb 19 00:13:21 volumio volumio[26178]: info: CoreStateMachine::resetVolumioState Feb 19 00:13:21 volumio volumio[26178]: info: CoreStateMachine::getcurrentVolume Feb 19 00:13:21 volumio volumio[26178]: info: CoreCommandRouter::volumioRetrievevolume Feb 19 00:13:21 volumio sudo[26338]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 19 00:13:21 volumio sudo[26338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:21 volumio sudo[26340]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 19 00:13:21 volumio sudo[26340]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:21 volumio sudo[26338]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:21 volumio sudo[26340]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:21 volumio volumio[26178]: info: Volumio Network Manager: Network status updated: 1 Feb 19 00:13:21 volumio volumio[26178]: info: VolumeController:: Volume=100 Mute =false Feb 19 00:13:21 volumio volumio[26178]: info: CoreStateMachine::pushState Feb 19 00:13:21 volumio volumio[26178]: info: CorePlayQueue::getTrack 0 Feb 19 00:13:21 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 19 00:13:21 volumio volumio[26178]: info: CoreCommandRouter::volumioPushState Feb 19 00:13:21 volumio volumio[26178]: info: CoreStateMachine::updateTrackBlock Feb 19 00:13:21 volumio volumio[26178]: info: CorePlayQueue::getTrackBlock Feb 19 00:13:21 volumio volumio[26178]: info: CoreCommandRouter::volumioRetrievevolume Feb 19 00:13:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 19 00:13:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:21 volumio volumio-remote-updater[25144]: [2026-02-19 00:13:21] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771434799 101 Feb 19 00:13:21 volumio volumio[26178]: 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 19 00:13:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:21 volumio go-librespot[26345]: go-librespot daemon starting... Feb 19 00:13:21 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 00:13:22 volumio volumio[26178]: info: Reloading queue from file Feb 19 00:13:22 volumio go-librespot[26350]: time="2026-02-19T00:13:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:13:22 volumio go-librespot[26350]: time="2026-02-19T00:13:22+07:00" level=debug msg="app state loaded" Feb 19 00:13:22 volumio go-librespot[26350]: time="2026-02-19T00:13:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:13:22 volumio volumio[26178]: info: CoreStateMachine::setRepeat null single undefined Feb 19 00:13:22 volumio volumio[26178]: info: CoreStateMachine::pushState Feb 19 00:13:22 volumio volumio[26178]: info: CorePlayQueue::getTrack 0 Feb 19 00:13:22 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 19 00:13:22 volumio volumio[26178]: info: CoreCommandRouter::volumioPushState Feb 19 00:13:22 volumio volumio[26178]: info: CoreStateMachine::setRandom null Feb 19 00:13:22 volumio volumio[26178]: info: CoreStateMachine::pushState Feb 19 00:13:22 volumio volumio[26178]: info: CorePlayQueue::getTrack 0 Feb 19 00:13:22 volumio volumio[26178]: info: CoreCommandRouter::volumioPushState Feb 19 00:13:22 volumio volumio[26178]: info: Setting Device type: Raspberry PI Feb 19 00:13:22 volumio volumio[26178]: info: Completed loading Core Plugins Feb 19 00:13:22 volumio volumio[26178]: info: Preparing to generate the ALSA configuration file Feb 19 00:13:22 volumio volumio[26178]: info: VolumeController:: Volume=100 Mute =false Feb 19 00:13:22 volumio volumio[26178]: info: CoreStateMachine::pushState Feb 19 00:13:22 volumio volumio[26178]: info: CorePlayQueue::getTrack 0 Feb 19 00:13:22 volumio volumio[26178]: info: CoreCommandRouter::volumioPushState Feb 19 00:13:22 volumio volumio[26178]: info: Asound.conf file unchanged, so no further update is needed Feb 19 00:13:22 volumio volumio[26178]: info: Output device has changed, restarting MPD Feb 19 00:13:22 volumio sudo[26361]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 19 00:13:22 volumio volumio[26178]: info: Output device has changed, restarting Shairport Sync Feb 19 00:13:22 volumio sudo[26361]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:22 volumio sudo[26363]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 19 00:13:22 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:22 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 00:13:22 volumio sudo[26363]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:22 volumio sudo[26363]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:22 volumio sudo[26365]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 19 00:13:22 volumio sudo[26365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:22 volumio volumio[26178]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 19 00:13:22 volumio volumio[26178]: info: ___________ START PLUGINS ___________ Feb 19 00:13:22 volumio volumio[26178]: info: ControllerMpd::onStart: Initializing MPD Feb 19 00:13:22 volumio volumio[26178]: info: Creating MPD Configuration file Feb 19 00:13:22 volumio go-librespot[26350]: time="2026-02-19T00:13: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-gew1.spotify.com:80]" Feb 19 00:13:22 volumio go-librespot[26350]: time="2026-02-19T00:13:22+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 19 00:13:22 volumio go-librespot[26350]: time="2026-02-19T00:13:22+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 19 00:13:22 volumio go-librespot[26350]: time="2026-02-19T00:13:22+07:00" level=info msg="zeroconf server listening on port 41229" Feb 19 00:13:22 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 19 00:13:22 volumio sudo[26361]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:22 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 00:13:22 volumio volumio[26178]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 00:13:22 volumio volumio[26178]: info: [1771434802814] CoreMusicLibrary::Adding element Media Servers Feb 19 00:13:22 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 00:13:22 volumio sudo[26374]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 19 00:13:22 volumio sudo[26374]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:22 volumio sudo[26376]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 19 00:13:22 volumio sudo[26374]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:22 volumio sudo[26376]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:22 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 19 00:13:22 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 19 00:13:22 volumio systemd[1]: mpd.service: Consumed 7.227s CPU time. Feb 19 00:13:22 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 19 00:13:22 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 19 00:13:22 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 19 00:13:23 volumio volumio[26178]: info: UPNP Browser: Client initialized successfully Feb 19 00:13:23 volumio go-librespot[26350]: time="2026-02-19T00:13:23+07:00" level=debug msg="obtained new client token: AAD+RZTat3FIJo/WJGPJ3kNkUG4mNeiTXIy+gXGvcjb7IKAhn0P8HFaqH5aC6dc3tKo463sTP2VejEkTBPAD3NTR+aJrag00NmUiYHRZJGYiU64K5qldtfBXArp5vK+wAX/rqT1yy0Ke11iRELN3dUlj2QQa1KlBSQoYlq8SO2Z3HTiboiL7IvC1Rr+T+T6Gc2u2r4joHwFbfZ5VeFU73CeODkhQcUEfePy/K2QCv7htuVZeRI+3SVyW4A==" Feb 19 00:13:23 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 19 00:13:23 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:23 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 00:13:23 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 19 00:13:23 volumio volumio[26178]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 19 00:13:23 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:23 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 00:13:23 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 19 00:13:23 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 19 00:13:23 volumio go-librespot[26350]: time="2026-02-19T00:13:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 00:13:23 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 19 00:13:23 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 19 00:13:23 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 19 00:13:23 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 19 00:13:23 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 19 00:13:23 volumio volumio[26178]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 19 00:13:23 volumio volumio[26178]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 00:13:23 volumio volumio[26178]: info: [1771434803204] CoreMusicLibrary::Adding element Last_100 Feb 19 00:13:23 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 00:13:23 volumio volumio[26178]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 00:13:23 volumio volumio[26178]: info: [1771434803218] CoreMusicLibrary::Adding element Webradio Feb 19 00:13:23 volumio go-librespot[26350]: time="2026-02-19T00:13:23+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 19 00:13:23 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 00:13:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:13:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:13:23 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 19 00:13:23 volumio volumio[26178]: info: Initializing BBC Radios Feb 19 00:13:23 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 19 00:13:23 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 00:13:23 volumio volumio[26178]: info: Creating Spotify config file Feb 19 00:13:23 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:23 volumio sudo[26390]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 19 00:13:23 volumio sudo[26390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 19 00:13:23 volumio sudo[26390]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:24 volumio volumio[26302]: Starting albumart workers Feb 19 00:13:24 volumio volumio[26303]: Starting albumart workers Feb 19 00:13:24 volumio volumio[26304]: Starting albumart workers Feb 19 00:13:24 volumio volumio[26178]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 00:13:24 volumio volumio[26178]: info: [1771434804919] CoreMusicLibrary::Adding element YouTube Music Feb 19 00:13:24 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 00:13:24 volumio volumio[26178]: Cannot find translation for source YouTube Music Feb 19 00:13:24 volumio volumio[26178]: info: Volumio Calling Home Feb 19 00:13:25 volumio sudo[26407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 19 00:13:25 volumio sudo[26407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:25 volumio sudo[26407]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:25 volumio volumio[26178]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 19 00:13:25 volumio volumio[26178]: info: Discovery: Found device Volumio Feb 19 00:13:25 volumio volumio[26178]: info: CoreCommandRouter::volumioGetState Feb 19 00:13:25 volumio volumio[26178]: info: CorePlayQueue::getTrack 0 Feb 19 00:13:25 volumio volumio[26178]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 19 00:13:25 volumio volumio[26178]: info: Discovery: Found device Volumio Feb 19 00:13:25 volumio volumio[26178]: info: CoreCommandRouter::volumioGetState Feb 19 00:13:25 volumio volumio[26178]: info: CorePlayQueue::getTrack 0 Feb 19 00:13:25 volumio volumio[26178]: info: MPD Permissions set Feb 19 00:13:25 volumio volumio[26178]: info: MPD Permissions set Feb 19 00:13:26 volumio volumio[26178]: info: Upmpdcli Daemon Started Feb 19 00:13:26 volumio volumio[26178]: 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 19 00:13:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 19 00:13:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:26 volumio volumio[26178]: info: Spotify config file written Feb 19 00:13:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:26 volumio go-librespot[26427]: go-librespot daemon starting... Feb 19 00:13:26 volumio go-librespot[26435]: time="2026-02-19T00:13:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:13:26 volumio go-librespot[26435]: time="2026-02-19T00:13:26+07:00" level=debug msg="app state loaded" Feb 19 00:13:26 volumio go-librespot[26435]: time="2026-02-19T00:13:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:13:26 volumio sudo[26434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 19 00:13:26 volumio sudo[26434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:26 volumio volumio[26178]: info: Volumio called home Feb 19 00:13:26 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 19 00:13:26 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 19 00:13:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:26 volumio go-librespot[26442]: go-librespot daemon starting... Feb 19 00:13:26 volumio sudo[26434]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:26 volumio go-librespot[26443]: time="2026-02-19T00:13:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:13:26 volumio go-librespot[26443]: time="2026-02-19T00:13:26+07:00" level=debug msg="app state loaded" Feb 19 00:13:26 volumio go-librespot[26443]: time="2026-02-19T00:13:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:13:26 volumio volumio[26178]: info: No need to fix Spotify hosts Feb 19 00:13:27 volumio volumio[26178]: info: Starting Shairport Sync Feb 19 00:13:27 volumio volumio[26178]: info: Starting Shairport Sync Feb 19 00:13:27 volumio volumio[26178]: info: Starting Shairport Sync Feb 19 00:13:27 volumio sudo[26461]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 19 00:13:27 volumio sudo[26461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:27 volumio go-librespot[26443]: time="2026-02-19T00:13:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 19 00:13:27 volumio go-librespot[26443]: time="2026-02-19T00:13:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 19 00:13:27 volumio go-librespot[26443]: time="2026-02-19T00:13:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 19 00:13:27 volumio sudo[26463]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 19 00:13:27 volumio sudo[26463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:27 volumio go-librespot[26443]: time="2026-02-19T00:13:27+07:00" level=info msg="zeroconf server listening on port 34319" Feb 19 00:13:27 volumio sudo[26465]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 19 00:13:27 volumio sudo[26465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:27 volumio volumio[26178]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 19 00:13:27 volumio volumio[26178]: SPOTIFY: BQArMt4ud5dZCrWODNfi7luu5BUpgw4TN-9Xn1CmYoDIaAyXXdcuCSNfjjd9LiPj_wXTd6uCujPf46pJ-kSYLAwQUj7kerSPZ3zkFesRGRp5ql7Xp3dNobwL6MSD0uARpHR7YloRVQNSQwqLJ3wGgUnEZ-9zEMC1PPHq1gfMEYKujqpjDpYBXkxkIGjXj26n1UK8fTnUnIYKXNzY23vXakqzh0rnz_uTbzt1cPDfeVVlTTw5R_csVcIpru8YLTs7j6DgiKneCbd_kIvIw_Dg3d_5qRlAlBhoMJ2dj_fGD-BwhheT5BNdynVz Feb 19 00:13:27 volumio volumio[26178]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 19 00:13:27 volumio volumio[26178]: info: New Spotify access token = BQArMt4ud5dZCrWODNfi7luu5BUpgw4TN-9Xn1CmYoDIaAyXXdcuCSNfjjd9LiPj_wXTd6uCujPf46pJ-kSYLAwQUj7kerSPZ3zkFesRGRp5ql7Xp3dNobwL6MSD0uARpHR7YloRVQNSQwqLJ3wGgUnEZ-9zEMC1PPHq1gfMEYKujqpjDpYBXkxkIGjXj26n1UK8fTnUnIYKXNzY23vXakqzh0rnz_uTbzt1cPDfeVVlTTw5R_csVcIpru8YLTs7j6DgiKneCbd_kIvIw_Dg3d_5qRlAlBhoMJ2dj_fGD-BwhheT5BNdynVz Feb 19 00:13:27 volumio volumio[26178]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 19 00:13:27 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 19 00:13:27 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 19 00:13:27 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 19 00:13:27 volumio systemd[1]: shairport-sync.service: Consumed 2.272s CPU time. Feb 19 00:13:27 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 19 00:13:27 volumio sudo[26463]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:27 volumio sudo[26461]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:27 volumio sudo[26465]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:27 volumio go-librespot[26443]: time="2026-02-19T00:13:27+07:00" level=debug msg="obtained new client token: AABUSo4pHQOJR1SRZ8MfZpvuac1qyfoEtt9fh3LU6HI/25jEVbTVMxAOHgA5dnzvT4RDOn7DY2uIEX26GdmFoPAurZgarrW/vcKkqtqVEUg0GdimbAcC6uEEkvU0hNx+1Ti7rAOAnkPjpDdehly1uTLf1eznV1DiBceM5kRRR12M1fVXANCpVqeFMr3dDFiJb9eS1LxCn4JDBmu2dqmiiCMvd7DfRDse5PUF48hNytDQ3TM3yLFQT3LYsQ==" Feb 19 00:13:27 volumio volumio[26178]: info: CoreCommandRouter::volumioGetState Feb 19 00:13:27 volumio volumio[26178]: info: CorePlayQueue::getTrack 0 Feb 19 00:13:27 volumio go-librespot[26443]: time="2026-02-19T00:13:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 00:13:27 volumio go-librespot[26443]: time="2026-02-19T00:13:27+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 19 00:13:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:13:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:13:28 volumio volumio[26178]: info: Shairport-Sync Started Feb 19 00:13:28 volumio volumio[26178]: Error adding Membership: Error: addMembership EINVAL Feb 19 00:13:28 volumio volumio[26178]: info: Shairport-Sync Started Feb 19 00:13:28 volumio volumio[26178]: info: Shairport-Sync Started Feb 19 00:13:28 volumio volumio[26178]: 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 19 00:13:28 volumio volumio[26178]: info: Spotify Successfully logged in Feb 19 00:13:28 volumio volumio[26178]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 00:13:28 volumio volumio[26178]: info: [1771434808115] CoreMusicLibrary::Adding element Spotify Feb 19 00:13:28 volumio volumio[26178]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 00:13:28 volumio volumio[26178]: Cannot find translation for source YouTube Music Feb 19 00:13:28 volumio volumio[26178]: Cannot find translation for source Spotify Feb 19 00:13:28 volumio volumio[26178]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 19 00:13:28 volumio volumio[26178]: info: CoreCommandRouter::volumioRetrievevolume Feb 19 00:13:28 volumio volumio[26178]: info: VolumeController:: Volume=100 Mute =false Feb 19 00:13:28 volumio volumio[26178]: info: CoreCommandRouter::volumioGetState Feb 19 00:13:28 volumio volumio[26178]: info: CorePlayQueue::getTrack 0 Feb 19 00:13:28 volumio volumio[26178]: info: CoreStateMachine::pushState Feb 19 00:13:28 volumio volumio[26178]: info: CorePlayQueue::getTrack 0 Feb 19 00:13:28 volumio volumio[26178]: info: CoreCommandRouter::volumioPushState Feb 19 00:13:30 volumio volumio[26178]: info: go-librespot daemon successfully initialized Feb 19 00:13:30 volumio mpd[26405]: 2026-02-19T00:13:30 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 19 00:13:30 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 19 00:13:30 volumio sudo[26376]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:30 volumio sudo[26365]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:30 volumio volumio[26178]: error: MPD error: The expression evaluated to a falsy value: Feb 19 00:13:30 volumio volumio[26178]: assert.ok(self.idling) Feb 19 00:13:30 volumio volumio[26178]: error: The expression evaluated to a falsy value: Feb 19 00:13:30 volumio volumio[26178]: assert.ok(self.idling) Feb 19 00:13:30 volumio volumio[26178]: error: updateQueue error: null Feb 19 00:13:30 volumio volumio[26178]: info: MPD running with PID26405 Feb 19 00:13:30 volumio volumio[26178]: ,establishing connection Feb 19 00:13:30 volumio volumio[26178]: info: Completed starting Core Plugins Feb 19 00:13:30 volumio volumio[26178]: info: ------------------------------------------- Feb 19 00:13:30 volumio volumio[26178]: info: ----- MyVolumio plugins startup ---- Feb 19 00:13:30 volumio volumio[26178]: info: ------------------------------------------- Feb 19 00:13:30 volumio volumio[26178]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 19 00:13:30 volumio volumio[26178]: error: updateQueue error: null Feb 19 00:13:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 19 00:13:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:31 volumio go-librespot[26506]: go-librespot daemon starting... Feb 19 00:13:31 volumio go-librespot[26507]: time="2026-02-19T00:13:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:13:31 volumio go-librespot[26507]: time="2026-02-19T00:13:31+07:00" level=debug msg="app state loaded" Feb 19 00:13:31 volumio go-librespot[26507]: time="2026-02-19T00:13:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:13:31 volumio go-librespot[26507]: time="2026-02-19T00:13:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 19 00:13:31 volumio go-librespot[26507]: time="2026-02-19T00:13:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 19 00:13:31 volumio go-librespot[26507]: time="2026-02-19T00:13:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 19 00:13:31 volumio go-librespot[26507]: time="2026-02-19T00:13:31+07:00" level=info msg="zeroconf server listening on port 45569" Feb 19 00:13:31 volumio go-librespot[26507]: time="2026-02-19T00:13:31+07:00" level=debug msg="obtained new client token: AAAKZQF8KQg33/uhJWNBVparN0wfZ5Rjdj+d/60F9gWUHdjGjWxf8sMztp2tBjnAI8SGCiRKWT4FOFnm+0iD07xcun1212Hrdt9sd9S5/xEuylTs4pNmIWoC8jLBf6N3o9FoXezjeOAeu1wkrF76N9xWmhErvm3vUENmkz19gJbB+tCLUfBdD0JeznEM9vN2mwbRSvf+NbAK1L1wIRe2nZdHlWzwOhbIB18xZus9tf5PkZC/jTayBeQYKA==" Feb 19 00:13:32 volumio go-librespot[26507]: time="2026-02-19T00:13:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 00:13:32 volumio go-librespot[26507]: time="2026-02-19T00:13:32+07:00" level=debug msg="completed keyexchange" Feb 19 00:13:32 volumio go-librespot[26507]: time="2026-02-19T00:13:32+07:00" level=debug msg="completed challenge" Feb 19 00:13:32 volumio go-librespot[26507]: time="2026-02-19T00:13:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 19 00:13:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:13:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:13:33 volumio volumio[26178]: info: Initializing connection to go-librespot Websocket Feb 19 00:13:33 volumio volumio[26178]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 00:13:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 19 00:13:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:35 volumio go-librespot[26519]: go-librespot daemon starting... Feb 19 00:13:35 volumio go-librespot[26520]: time="2026-02-19T00:13:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:13:35 volumio go-librespot[26520]: time="2026-02-19T00:13:35+07:00" level=debug msg="app state loaded" Feb 19 00:13:35 volumio go-librespot[26520]: time="2026-02-19T00:13:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:13:35 volumio volumio[26178]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 19 00:13:35 volumio go-librespot[26520]: time="2026-02-19T00:13:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 19 00:13:35 volumio go-librespot[26520]: time="2026-02-19T00:13:35+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 19 00:13:35 volumio go-librespot[26520]: time="2026-02-19T00:13:35+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 19 00:13:35 volumio go-librespot[26520]: time="2026-02-19T00:13:35+07:00" level=info msg="zeroconf server listening on port 39871" Feb 19 00:13:36 volumio go-librespot[26520]: time="2026-02-19T00:13:36+07:00" level=debug msg="obtained new client token: AAAtpPffjsNG19gWHdvl1vi0aj+URPyVFFL/B6iZFVZbGIWuB76stmEBA964vnVV63C3CTqXe3rur3lXxLG5m4nzwSHVTcakc5vhiKxCH/J2Hx56xOrrpwgGG7dZy7xD12iv/N2CXaz8fnXGHxw8nX/C35FrBRz1bKAOWUPtE9us+YMSSVe895/p4jkLbALnUuMIt44R/zWaHSYxljeIIQ0OqUJeHIFGHXYY67sF2XMlY6C5Z+Ajymk=" Feb 19 00:13:36 volumio go-librespot[26520]: time="2026-02-19T00:13:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 00:13:36 volumio volumio[26178]: info: Initializing connection to go-librespot Websocket Feb 19 00:13:36 volumio go-librespot[26520]: time="2026-02-19T00:13:36+07:00" level=debug msg="new websocket client" Feb 19 00:13:36 volumio volumio[26178]: info: Connection to go-librespot Websocket established Feb 19 00:13:36 volumio go-librespot[26520]: time="2026-02-19T00:13:36+07:00" level=debug msg="completed keyexchange" Feb 19 00:13:36 volumio go-librespot[26520]: time="2026-02-19T00:13:36+07:00" level=debug msg="completed challenge" Feb 19 00:13:36 volumio go-librespot[26520]: time="2026-02-19T00:13:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 19 00:13:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:13:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:13:36 volumio volumio[26178]: info: Connection to go-librespot Websocket closed Feb 19 00:13:39 volumio volumio[26178]: info: Getting Spotify volume Feb 19 00:13:39 volumio volumio[26178]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 19 00:13:39 volumio volumio[26178]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 00:13:39 volumio volumio[26178]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 19 00:13:39 volumio volumio[26178]: errno: -111, Feb 19 00:13:39 volumio volumio[26178]: code: 'ECONNREFUSED', Feb 19 00:13:39 volumio volumio[26178]: syscall: 'connect', Feb 19 00:13:39 volumio volumio[26178]: address: '127.0.0.1', Feb 19 00:13:39 volumio volumio[26178]: port: 9879, Feb 19 00:13:39 volumio volumio[26178]: response: undefined Feb 19 00:13:39 volumio volumio[26178]: } Feb 19 00:13:39 volumio volumio[26178]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 19 00:13:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 19 00:13:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:39 volumio go-librespot[26539]: go-librespot daemon starting... Feb 19 00:13:39 volumio go-librespot[26540]: time="2026-02-19T00:13:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:13:39 volumio go-librespot[26540]: time="2026-02-19T00:13:39+07:00" level=debug msg="app state loaded" Feb 19 00:13:39 volumio go-librespot[26540]: time="2026-02-19T00:13:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:13:40 volumio go-librespot[26540]: time="2026-02-19T00:13:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 19 00:13:40 volumio go-librespot[26540]: time="2026-02-19T00:13:40+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 19 00:13:40 volumio go-librespot[26540]: time="2026-02-19T00:13:40+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 19 00:13:40 volumio go-librespot[26540]: time="2026-02-19T00:13:40+07:00" level=info msg="zeroconf server listening on port 35481" Feb 19 00:13:40 volumio go-librespot[26540]: time="2026-02-19T00:13:40+07:00" level=debug msg="obtained new client token: AACUan+P21IRQzToZqbkvQzOYnTPH+obEWnuu2KdAW9oR+YxtDw2hOlVJ4TywFS1fr/TWBmN3RG2sxG6FQTD+WlhafLGK4BmGjiASTsPk5xHYhRC2yjE+DThJcSk3u7wsI331Ph0V4pH2liGG6alQaae/yDNXQKpG9uNC0bVZFd09g7u/E7tuqmMmIl8HTQCoTzB+UzT/RDigJzdpq2SnCnkFKG+7kthYC7J736x2qDJmgKGpilHxRyrFg==" Feb 19 00:13:40 volumio go-librespot[26540]: time="2026-02-19T00:13:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 00:13:40 volumio go-librespot[26540]: time="2026-02-19T00:13:40+07:00" level=debug msg="completed keyexchange" Feb 19 00:13:40 volumio go-librespot[26540]: time="2026-02-19T00:13:40+07:00" level=debug msg="completed challenge" Feb 19 00:13:40 volumio sudo[26563]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-19 00:12' Feb 19 00:13:40 volumio sudo[26563]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:40 volumio go-librespot[26540]: time="2026-02-19T00:13:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 19 00:13:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:13:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:13:41 volumio sudo[26563]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:41 volumio volumio-remote-updater[25144]: [2026-02-19 00:13:41] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 19 00:13:41 volumio volumio-remote-updater[25144]: [2026-02-19 00:13:41] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 19 00:13:41 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:13:41 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 19 00:13:41 volumio systemd[1]: volumio.service: Consumed 49.339s CPU time. Feb 19 00:13:41 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 19 00:13:41 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 19 00:13:41 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22643. Feb 19 00:13:41 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 19 00:13:41 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 19 00:13:41 volumio systemd[1]: volumio.service: Consumed 49.339s CPU time. Feb 19 00:13:41 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 19 00:13:41 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 19 00:13:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 19 00:13:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:44 volumio go-librespot[26598]: go-librespot daemon starting... Feb 19 00:13:44 volumio go-librespot[26599]: time="2026-02-19T00:13:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:13:44 volumio go-librespot[26599]: time="2026-02-19T00:13:44+07:00" level=debug msg="app state loaded" Feb 19 00:13:44 volumio go-librespot[26599]: time="2026-02-19T00:13:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:13:44 volumio go-librespot[26599]: time="2026-02-19T00:13:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 19 00:13:44 volumio go-librespot[26599]: time="2026-02-19T00:13:44+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 19 00:13:44 volumio go-librespot[26599]: time="2026-02-19T00:13:44+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 19 00:13:44 volumio go-librespot[26599]: time="2026-02-19T00:13:44+07:00" level=info msg="zeroconf server listening on port 33563" Feb 19 00:13:44 volumio go-librespot[26599]: time="2026-02-19T00:13:44+07:00" level=debug msg="obtained new client token: AADkgGkoZEMiOabvuR1FRpYiUvuwty0z9gA+H4KycvHntEnqz5usFtC6hoZXlERl/y0pSuq7KwWty+mvqxuJUteYQz+0FY4sRqIhiucBe0QuZa8XpODKZ4pCQ51uwDWtJWFTTKWrUG/QPFs3KN6nKH85igZMtXGBRhdvEEMu0KS9g5o6jfobdgJxkFe0JELgjUvpd6dm7x6X5+lpO2UOW2UjBoSRveXKFk3GIxJAbLUpnoi764VBD1Uygg==" Feb 19 00:13:45 volumio go-librespot[26599]: time="2026-02-19T00:13:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 00:13:45 volumio go-librespot[26599]: time="2026-02-19T00:13:45+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 19 00:13:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:13:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:13:45 volumio volumio[26583]: info: ------------------------------------------- Feb 19 00:13:45 volumio volumio[26583]: info: ----- Volumio3 ---- Feb 19 00:13:45 volumio volumio[26583]: info: ------------------------------------------- Feb 19 00:13:45 volumio volumio[26583]: info: ----- System startup ---- Feb 19 00:13:45 volumio volumio[26583]: info: ------------------------------------------- Feb 19 00:13:46 volumio volumio-remote-updater[25144]: [2026-02-19 00:13:46] [connect] Successful connection Feb 19 00:13:46 volumio volumio[26583]: info: MYVOLUMIO Environment detected Feb 19 00:13:46 volumio volumio[26583]: info: Plugin folders cleanup Feb 19 00:13:46 volumio volumio[26583]: info: Scanning into folder /volumio/app/plugins/ Feb 19 00:13:46 volumio volumio[26583]: info: Scanning category audio_interface Feb 19 00:13:46 volumio volumio[26583]: info: Scanning category miscellanea Feb 19 00:13:46 volumio volumio[26583]: info: Scanning category music_service Feb 19 00:13:46 volumio volumio[26583]: info: Scanning category plugins.json Feb 19 00:13:46 volumio volumio[26583]: info: Scanning category system_controller Feb 19 00:13:46 volumio volumio[26583]: info: Scanning category user_interface Feb 19 00:13:46 volumio volumio[26583]: info: Scanning into folder /data/plugins/ Feb 19 00:13:46 volumio volumio[26583]: info: Scanning category music_service Feb 19 00:13:46 volumio volumio[26583]: info: Plugin folders cleanup completed Feb 19 00:13:46 volumio volumio[26583]: info: ------------------------------------------- Feb 19 00:13:46 volumio volumio[26583]: info: ----- Core plugins startup ---- Feb 19 00:13:46 volumio volumio[26583]: info: ------------------------------------------- Feb 19 00:13:46 volumio volumio[26583]: info: Loading plugins from folder /volumio/app/plugins/ Feb 19 00:13:46 volumio volumio[26583]: info: Adding plugin upnp to MyMusic Plugins Feb 19 00:13:46 volumio volumio[26583]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 19 00:13:46 volumio volumio[26583]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 19 00:13:46 volumio volumio[26583]: info: Loading plugins from folder /data/plugins/ Feb 19 00:13:46 volumio volumio[26583]: info: Loading plugin "system"... Feb 19 00:13:46 volumio volumio[26583]: info: Loading plugin "appearance"... Feb 19 00:13:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 19 00:13:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:48 volumio go-librespot[26618]: go-librespot daemon starting... Feb 19 00:13:48 volumio go-librespot[26619]: time="2026-02-19T00:13:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:13:48 volumio go-librespot[26619]: time="2026-02-19T00:13:48+07:00" level=debug msg="app state loaded" Feb 19 00:13:48 volumio go-librespot[26619]: time="2026-02-19T00:13:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:13:48 volumio volumio[26583]: info: Loading plugin "network"... Feb 19 00:13:48 volumio volumio[26583]: info: Refreshing Cached IP Addresses Feb 19 00:13:48 volumio sudo[26627]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 19 00:13:48 volumio sudo[26627]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:48 volumio sudo[26629]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 19 00:13:48 volumio sudo[26629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:48 volumio go-librespot[26619]: time="2026-02-19T00:13:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 19 00:13:48 volumio go-librespot[26619]: time="2026-02-19T00:13:48+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 19 00:13:48 volumio go-librespot[26619]: time="2026-02-19T00:13:48+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 19 00:13:48 volumio volumio[26583]: info: Loading plugin "services"... Feb 19 00:13:48 volumio volumio[26583]: info: Loading plugin "alsa_controller"... Feb 19 00:13:48 volumio sudo[26629]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:48 volumio go-librespot[26619]: time="2026-02-19T00:13:48+07:00" level=info msg="zeroconf server listening on port 33195" Feb 19 00:13:48 volumio sudo[26627]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:48 volumio sudo[26637]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 19 00:13:48 volumio sudo[26637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:13:49 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 19 00:13:49 volumio volumio[26583]: info: Loading plugin "wizard"... Feb 19 00:13:49 volumio volumio[26583]: info: Loading plugin "networkfs"... Feb 19 00:13:49 volumio volumio[26583]: info: Starting Udev Watcher for removable devices Feb 19 00:13:49 volumio go-librespot[26619]: time="2026-02-19T00:13:49+07:00" level=debug msg="obtained new client token: AABq5pVbAGRmEY38FlBxuVVD2tUb/pUOebFO++khn1UlU6GtxdrrH2qdTxaZTQBPc8FGC2g9JCKO/ltqc99RHHr1oX+n6RAoETd3ZY8sP1jhkv/FYhiM4KzByLyk9+AjkkPZOHfo+WE7NgSYXCZzPf5n/gEIuDNqhm+8ssV+z+OL5FEVfe/tZdJrN7QASXx1KuezHNJzJWLnIjZ7gHZFgpoMsSisECND4blSAyWneJCnuli4mzHQ9T0=" Feb 19 00:13:49 volumio volumio[26583]: info: Ignoring mount for partition: boot Feb 19 00:13:49 volumio volumio[26583]: info: Ignoring mount for partition: volumio Feb 19 00:13:49 volumio volumio[26583]: info: Ignoring mount for partition: volumio_data Feb 19 00:13:49 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 19 00:13:49 volumio volumio[26583]: info: Loading plugin "volumio_command_line_client"... Feb 19 00:13:49 volumio volumio[26583]: info: Loading plugin "upnp"... Feb 19 00:13:49 volumio volumio[26583]: info: [1771434829256] Starting Upmpd Daemon Feb 19 00:13:49 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 19 00:13:49 volumio volumio[26583]: info: Loading plugin "my_music"... Feb 19 00:13:49 volumio volumio[26583]: info: Loading plugin "mpd"... Feb 19 00:13:49 volumio go-librespot[26619]: time="2026-02-19T00:13:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 00:13:49 volumio go-librespot[26619]: time="2026-02-19T00:13:49+07:00" level=debug msg="completed keyexchange" Feb 19 00:13:49 volumio go-librespot[26619]: time="2026-02-19T00:13:49+07:00" level=debug msg="completed challenge" Feb 19 00:13:49 volumio go-librespot[26619]: time="2026-02-19T00:13:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 19 00:13:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:13:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:13:49 volumio volumio[26583]: info: Loading plugin "upnp_browser"... Feb 19 00:13:51 volumio sudo[26637]: pam_unix(sudo:session): session closed for user root Feb 19 00:13:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 19 00:13:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:52 volumio go-librespot[26660]: go-librespot daemon starting... Feb 19 00:13:52 volumio go-librespot[26661]: time="2026-02-19T00:13:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:13:52 volumio go-librespot[26661]: time="2026-02-19T00:13:52+07:00" level=debug msg="app state loaded" Feb 19 00:13:52 volumio go-librespot[26661]: time="2026-02-19T00:13:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:13:52 volumio volumio[26583]: info: Starting UPNP Browser Feb 19 00:13:52 volumio volumio[26583]: info: Loading plugin "alarm-clock"... Feb 19 00:13:53 volumio go-librespot[26661]: time="2026-02-19T00:13:53+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 19 00:13:53 volumio go-librespot[26661]: time="2026-02-19T00:13:53+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 19 00:13:53 volumio go-librespot[26661]: time="2026-02-19T00:13:53+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 19 00:13:53 volumio volumio[26583]: info: Loading plugin "airplay_emulation"... Feb 19 00:13:53 volumio go-librespot[26661]: time="2026-02-19T00:13:53+07:00" level=info msg="zeroconf server listening on port 33793" Feb 19 00:13:53 volumio volumio[26583]: info: Starting Shairport Sync Feb 19 00:13:53 volumio volumio[26583]: info: Loading plugin "last_100"... Feb 19 00:13:53 volumio volumio[26583]: info: Loading plugin "webradio"... Feb 19 00:13:53 volumio go-librespot[26661]: time="2026-02-19T00:13:53+07:00" level=debug msg="obtained new client token: AAC39iepOo5jiTxfthqihAdQ24T2EbRQhrCYZDKooDGIf2Ye7A7r+8xZzaYX4vZCLJgn29BDa7mtqTE7C6Macbuvm+5k9uH2B1/jX43YHMWOt0JI+JEmcYvwQL+vE4hISuGAN2l6sHXOv6OCSxMmnMr58rtcpvUE8YCnKhWSs1tLZQAqFLzoMveowT/36LBPy6B2W4emx6ED5UXV69UgHxZuVxwN1GdLx4/8bbp/twWJymxjvuBwC61rPw==" Feb 19 00:13:53 volumio volumio[26583]: info: Loading plugin "i2s_dacs"... Feb 19 00:13:53 volumio volumio[26583]: info: Loading plugin "volumiodiscovery"... Feb 19 00:13:53 volumio go-librespot[26661]: time="2026-02-19T00:13:53+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 19 00:13:53 volumio volumio[26583]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 19 00:13:53 volumio volumio[26583]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 19 00:13:53 volumio volumio[26583]: *** WARNING *** For more information see Feb 19 00:13:53 volumio volumio[26583]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 19 00:13:53 volumio volumio[26583]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 19 00:13:53 volumio volumio[26583]: *** WARNING *** For more information see Feb 19 00:13:53 volumio node[26583]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 19 00:13:53 volumio node[26583]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 19 00:13:53 volumio node[26583]: *** WARNING *** For more information see Feb 19 00:13:53 volumio node[26583]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 19 00:13:53 volumio node[26583]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 19 00:13:53 volumio node[26583]: *** WARNING *** For more information see Feb 19 00:13:53 volumio volumio[26583]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 19 00:13:53 volumio volumio[26583]: info: Discovery: Started advertising with name: Volumio Feb 19 00:13:53 volumio go-librespot[26661]: time="2026-02-19T00:13:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 19 00:13:53 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 19 00:13:53 volumio volumio[26583]: info: Loading plugin "spop"... Feb 19 00:13:53 volumio go-librespot[26661]: time="2026-02-19T00:13:53+07:00" level=debug msg="completed keyexchange" Feb 19 00:13:53 volumio go-librespot[26661]: time="2026-02-19T00:13:53+07:00" level=debug msg="completed challenge" Feb 19 00:13:53 volumio go-librespot[26661]: time="2026-02-19T00:13:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 19 00:13:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:13:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:13:55 volumio volumio[26583]: info: Loading plugin "ytcr"... Feb 19 00:13:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 19 00:13:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:13:56 volumio go-librespot[26670]: go-librespot daemon starting... Feb 19 00:13:56 volumio go-librespot[26671]: time="2026-02-19T00:13:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:13:56 volumio go-librespot[26671]: time="2026-02-19T00:13:56+07:00" level=debug msg="app state loaded" Feb 19 00:13:56 volumio go-librespot[26671]: time="2026-02-19T00:13:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:13:57 volumio go-librespot[26671]: time="2026-02-19T00:13:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 19 00:13:57 volumio go-librespot[26671]: time="2026-02-19T00:13:57+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 19 00:13:57 volumio go-librespot[26671]: time="2026-02-19T00:13:57+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 19 00:13:57 volumio go-librespot[26671]: time="2026-02-19T00:13:57+07:00" level=info msg="zeroconf server listening on port 43929" Feb 19 00:13:57 volumio go-librespot[26671]: time="2026-02-19T00:13:57+07:00" level=debug msg="obtained new client token: AAA5Dj/SIOmeO4Cqxj2Es0R3dbrCNX5GLyADE8+A6doDascaquKzJ08bivkrJdEZnKk2vojpk5p87HHf/UJ3TVpm4mEvjhNP9kcUJeFD0Bp6AdvaO2zq9tGdoavBo4/zgFoc1yP67Y6YuXIjf7fcSGk8hbEJsFOCJP/uGrIagWJ1dY9HxUklPn19+/8oxFN8mAJEYNTf5i55Al0BBF33Jb0GPOLBn1CacvxfiypvjB2lTyY1ESEG9X2RPw==" Feb 19 00:13:57 volumio go-librespot[26671]: time="2026-02-19T00:13:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 00:13:57 volumio go-librespot[26671]: time="2026-02-19T00:13:57+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 19 00:13:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:13:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:13:58 volumio volumio[26583]: info: Loading plugin "ytmusic"... Feb 19 00:13:58 volumio volumio-remote-updater[25144]: [2026-02-19 00:13:58] [connect] Successful connection Feb 19 00:13:59 volumio volumio[26583]: info: Loading plugin "outputs"... Feb 19 00:13:59 volumio volumio[26583]: info: Loading plugin "albumart"... Feb 19 00:13:59 volumio volumio[26583]: info: Plugin example_plugin is not enabled Feb 19 00:13:59 volumio volumio[26583]: info: Loading plugin "inputs"... Feb 19 00:13:59 volumio volumio[26583]: info: Loading plugin "updater_comm"... Feb 19 00:13:59 volumio volumio[26583]: info: Plugin mpdemulation is not enabled Feb 19 00:13:59 volumio volumio[26583]: info: Loading plugin "rest_api"... Feb 19 00:13:59 volumio volumio[26583]: info: Loading plugin "websocket"... Feb 19 00:13:59 volumio volumio[26583]: info: Starting Socket.io Server version 1.7.4 Feb 19 00:13:59 volumio volumio[26583]: info: Loading plugin "RoonBridge"... Feb 19 00:13:59 volumio volumio[26583]: info: Applying required configuration parameters for plugin RoonBridge Feb 19 00:13:59 volumio volumio[26583]: info: Loading i18n strings for locale en Feb 19 00:14:00 volumio volumio[26583]: Updating browse sources language Feb 19 00:14:00 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 00:14:00 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 00:14:00 volumio volumio[26583]: info: CoreCommandRouter::initPlayerControls Feb 19 00:14:00 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:00 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:00 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:00 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:00 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:00 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:00 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:00 volumio volumio[26692]: Forking 3 albumart workers Feb 19 00:14:00 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:00 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 00:14:00 volumio volumio[26583]: Express server listening on port 3000 Feb 19 00:14:00 volumio volumio[26583]: [Metrics] WebUI: 16s 34.05ms Feb 19 00:14:00 volumio volumio[26583]: info: CoreStateMachine::resetVolumioState Feb 19 00:14:00 volumio volumio[26583]: info: CoreStateMachine::getcurrentVolume Feb 19 00:14:00 volumio volumio[26583]: info: CoreCommandRouter::volumioRetrievevolume Feb 19 00:14:00 volumio sudo[26734]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 19 00:14:00 volumio sudo[26734]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:14:00 volumio sudo[26734]: pam_unix(sudo:session): session closed for user root Feb 19 00:14:00 volumio sudo[26736]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 19 00:14:00 volumio sudo[26736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:14:00 volumio sudo[26736]: pam_unix(sudo:session): session closed for user root Feb 19 00:14:00 volumio volumio[26583]: info: Volumio Network Manager: Network status updated: 1 Feb 19 00:14:00 volumio volumio[26583]: info: VolumeController:: Volume=100 Mute =false Feb 19 00:14:00 volumio volumio[26583]: info: CoreStateMachine::pushState Feb 19 00:14:00 volumio volumio[26583]: info: CorePlayQueue::getTrack 0 Feb 19 00:14:00 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 19 00:14:00 volumio volumio[26583]: info: CoreCommandRouter::volumioPushState Feb 19 00:14:00 volumio volumio[26583]: info: CoreStateMachine::updateTrackBlock Feb 19 00:14:00 volumio volumio[26583]: info: CorePlayQueue::getTrackBlock Feb 19 00:14:00 volumio volumio[26583]: info: CoreCommandRouter::volumioRetrievevolume Feb 19 00:14:00 volumio volumio-remote-updater[25144]: [2026-02-19 00:14:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771434838 101 Feb 19 00:14:01 volumio volumio[26583]: 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 19 00:14:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 19 00:14:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:14:01 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 00:14:01 volumio volumio[26583]: info: Reloading queue from file Feb 19 00:14:01 volumio volumio[26583]: info: CoreStateMachine::setRepeat null single undefined Feb 19 00:14:01 volumio volumio[26583]: info: CoreStateMachine::pushState Feb 19 00:14:01 volumio volumio[26583]: info: CorePlayQueue::getTrack 0 Feb 19 00:14:01 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 19 00:14:01 volumio volumio[26583]: info: CoreCommandRouter::volumioPushState Feb 19 00:14:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:14:01 volumio go-librespot[26749]: go-librespot daemon starting... Feb 19 00:14:01 volumio volumio[26583]: info: CoreStateMachine::setRandom null Feb 19 00:14:01 volumio volumio[26583]: info: CoreStateMachine::pushState Feb 19 00:14:01 volumio volumio[26583]: info: CorePlayQueue::getTrack 0 Feb 19 00:14:01 volumio volumio[26583]: info: CoreCommandRouter::volumioPushState Feb 19 00:14:01 volumio volumio[26583]: info: Setting Device type: Raspberry PI Feb 19 00:14:01 volumio go-librespot[26751]: time="2026-02-19T00:14:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:14:01 volumio go-librespot[26751]: time="2026-02-19T00:14:01+07:00" level=debug msg="app state loaded" Feb 19 00:14:01 volumio go-librespot[26751]: time="2026-02-19T00:14:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:14:01 volumio volumio[26583]: info: Completed loading Core Plugins Feb 19 00:14:01 volumio volumio[26583]: info: Preparing to generate the ALSA configuration file Feb 19 00:14:01 volumio volumio[26583]: info: VolumeController:: Volume=100 Mute =false Feb 19 00:14:01 volumio volumio[26583]: info: CoreStateMachine::pushState Feb 19 00:14:01 volumio volumio[26583]: info: CorePlayQueue::getTrack 0 Feb 19 00:14:01 volumio volumio[26583]: info: CoreCommandRouter::volumioPushState Feb 19 00:14:01 volumio volumio[26583]: info: Asound.conf file unchanged, so no further update is needed Feb 19 00:14:01 volumio volumio[26583]: info: Output device has changed, restarting MPD Feb 19 00:14:01 volumio sudo[26761]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 19 00:14:01 volumio sudo[26761]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:14:01 volumio volumio[26583]: info: Output device has changed, restarting Shairport Sync Feb 19 00:14:01 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:01 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 00:14:01 volumio sudo[26764]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 19 00:14:01 volumio sudo[26764]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:14:01 volumio sudo[26764]: pam_unix(sudo:session): session closed for user root Feb 19 00:14:01 volumio volumio[26583]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 19 00:14:01 volumio volumio[26583]: info: ___________ START PLUGINS ___________ Feb 19 00:14:01 volumio sudo[26761]: pam_unix(sudo:session): session closed for user root Feb 19 00:14:01 volumio sudo[26766]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 19 00:14:01 volumio sudo[26766]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:14:01 volumio volumio[26583]: info: ControllerMpd::onStart: Initializing MPD Feb 19 00:14:01 volumio volumio[26583]: info: Creating MPD Configuration file Feb 19 00:14:01 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 00:14:01 volumio volumio[26583]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 00:14:01 volumio volumio[26583]: info: [1771434841864] CoreMusicLibrary::Adding element Media Servers Feb 19 00:14:01 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 00:14:01 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 19 00:14:01 volumio go-librespot[26751]: time="2026-02-19T00:14:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 19 00:14:01 volumio go-librespot[26751]: time="2026-02-19T00:14:01+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 19 00:14:01 volumio go-librespot[26751]: time="2026-02-19T00:14:01+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 19 00:14:01 volumio volumio[26583]: info: UPNP Browser: Client initialized successfully Feb 19 00:14:01 volumio sudo[26778]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 19 00:14:01 volumio sudo[26776]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 19 00:14:01 volumio sudo[26778]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:14:01 volumio sudo[26776]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:14:01 volumio go-librespot[26751]: time="2026-02-19T00:14:01+07:00" level=info msg="zeroconf server listening on port 46107" Feb 19 00:14:02 volumio sudo[26776]: pam_unix(sudo:session): session closed for user root Feb 19 00:14:02 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 19 00:14:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 19 00:14:02 volumio systemd[1]: mpd.service: Consumed 7.068s CPU time. Feb 19 00:14:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 19 00:14:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 19 00:14:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 19 00:14:02 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:02 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 00:14:02 volumio go-librespot[26751]: time="2026-02-19T00:14:02+07:00" level=debug msg="obtained new client token: AADTUObM0VSNodg1cLQ2FSIn0ENQjvAKAHuhR/AjBQxybQ/5WMJWXaIMHR+uf6HTSaEl4+a+AXUGUlKq6/rJRCl9wXNAngHDdBanYHFCuYcQdsK1QmqtT1+FdQgH1r7QaEn0VjIFOu4XLkpyrW5CqC9PSmI4T8/TsCqwCqDnohL486mT8VNvpOhYUHOeryuIhmscZRmx4x66Bx+5wdXsE5OeYPTtm+JXeXk3+AEs9ENllT1n4Tm6XH4=" Feb 19 00:14:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 19 00:14:02 volumio volumio[26583]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 19 00:14:02 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:02 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 00:14:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 19 00:14:02 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 19 00:14:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 19 00:14:02 volumio volumio[26583]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 19 00:14:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 19 00:14:02 volumio volumio[26583]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 00:14:02 volumio volumio[26583]: info: [1771434842336] CoreMusicLibrary::Adding element Last_100 Feb 19 00:14:02 volumio go-librespot[26751]: time="2026-02-19T00:14:02+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 19 00:14:02 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 00:14:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 19 00:14:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 19 00:14:02 volumio volumio[26583]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 00:14:02 volumio volumio[26583]: info: [1771434842361] CoreMusicLibrary::Adding element Webradio Feb 19 00:14:02 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 00:14:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 19 00:14:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 19 00:14:02 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 19 00:14:02 volumio go-librespot[26751]: time="2026-02-19T00:14:02+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Feb 19 00:14:02 volumio volumio[26583]: info: Initializing BBC Radios Feb 19 00:14:02 volumio go-librespot[26751]: time="2026-02-19T00:14:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 19 00:14:02 volumio go-librespot[26751]: time="2026-02-19T00:14:02+07:00" level=debug msg="completed keyexchange" Feb 19 00:14:02 volumio go-librespot[26751]: time="2026-02-19T00:14:02+07:00" level=debug msg="completed challenge" Feb 19 00:14:02 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 19 00:14:02 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 00:14:02 volumio volumio[26583]: info: Creating Spotify config file Feb 19 00:14:02 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:02 volumio go-librespot[26751]: time="2026-02-19T00:14:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 19 00:14:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:14:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:14:02 volumio sudo[26792]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 19 00:14:02 volumio sudo[26792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 19 00:14:02 volumio sudo[26792]: pam_unix(sudo:session): session closed for user root Feb 19 00:14:03 volumio volumio[26707]: Starting albumart workers Feb 19 00:14:03 volumio volumio[26702]: Starting albumart workers Feb 19 00:14:03 volumio volumio[26703]: Starting albumart workers Feb 19 00:14:03 volumio volumio[26583]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 00:14:03 volumio volumio[26583]: info: [1771434843992] CoreMusicLibrary::Adding element YouTube Music Feb 19 00:14:03 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 00:14:03 volumio volumio[26583]: Cannot find translation for source YouTube Music Feb 19 00:14:04 volumio volumio[26583]: info: Volumio Calling Home Feb 19 00:14:04 volumio sudo[26809]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 19 00:14:04 volumio sudo[26809]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:14:04 volumio sudo[26809]: pam_unix(sudo:session): session closed for user root Feb 19 00:14:04 volumio volumio[26583]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 19 00:14:04 volumio volumio[26583]: info: Discovery: Found device Volumio Feb 19 00:14:04 volumio volumio[26583]: info: CoreCommandRouter::volumioGetState Feb 19 00:14:04 volumio volumio[26583]: info: CorePlayQueue::getTrack 0 Feb 19 00:14:04 volumio volumio[26583]: info: MPD Permissions set Feb 19 00:14:04 volumio volumio[26583]: info: MPD Permissions set Feb 19 00:14:04 volumio volumio[26583]: info: Upmpdcli Daemon Started Feb 19 00:14:04 volumio volumio[26583]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 19 00:14:04 volumio volumio[26583]: info: Discovery: Found device Volumio Feb 19 00:14:04 volumio volumio[26583]: info: CoreCommandRouter::volumioGetState Feb 19 00:14:04 volumio volumio[26583]: info: CorePlayQueue::getTrack 0 Feb 19 00:14:04 volumio volumio[26583]: info: Volumio called home Feb 19 00:14:04 volumio volumio[26583]: info: Spotify config file written Feb 19 00:14:05 volumio volumio[26583]: 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 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:05 volumio sudo[26816]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 19 00:14:05 volumio sudo[26816]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 00:14:05 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 00:14:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:14:05 volumio volumio[26583]: info: No need to fix Spotify hosts Feb 19 00:14:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:14:05 volumio go-librespot[26828]: go-librespot daemon starting... Feb 19 00:14:05 volumio sudo[26816]: pam_unix(sudo:session): session closed for user root Feb 19 00:14:05 volumio go-librespot[26829]: time="2026-02-19T00:14:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:14:05 volumio go-librespot[26829]: time="2026-02-19T00:14:05+07:00" level=debug msg="app state loaded" Feb 19 00:14:05 volumio go-librespot[26829]: time="2026-02-19T00:14:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:14:06 volumio go-librespot[26829]: time="2026-02-19T00:14:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 19 00:14:06 volumio go-librespot[26829]: time="2026-02-19T00:14:06+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 19 00:14:06 volumio go-librespot[26829]: time="2026-02-19T00:14:06+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 19 00:14:06 volumio go-librespot[26829]: time="2026-02-19T00:14:06+07:00" level=info msg="zeroconf server listening on port 39741" Feb 19 00:14:06 volumio go-librespot[26829]: time="2026-02-19T00:14:06+07:00" level=debug msg="obtained new client token: AABORknRIUtj/S5LGh91cjlF4Go2eiGX+It1cZjxqbiFrngPqbMstdHvZJC2Ifwsl+jECBQ5n9NhxBlqlKuuUPmeR5x2iL1opUEwGRRYdiKWtso1homtpWUQgMQ/XJaUV64CFEIPibEGmFtwGIGnKYLPpMeBNNKmaDOD/x11sMe0KYFteEJ+qLC86YJOaN8ZUVgnmBVOMbupmzSEc8u0VN77RcT8n5432Fj9wvBqIdVFBe5gOQCcTU8RXQ==" Feb 19 00:14:06 volumio volumio[26583]: info: Starting Shairport Sync Feb 19 00:14:06 volumio volumio[26583]: info: Starting Shairport Sync Feb 19 00:14:06 volumio volumio[26583]: info: Starting Shairport Sync Feb 19 00:14:06 volumio go-librespot[26829]: time="2026-02-19T00:14:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 00:14:06 volumio sudo[26855]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 19 00:14:06 volumio sudo[26855]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:14:06 volumio sudo[26857]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 19 00:14:06 volumio sudo[26857]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:14:06 volumio sudo[26859]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 19 00:14:06 volumio sudo[26859]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:14:06 volumio go-librespot[26829]: time="2026-02-19T00:14:06+07:00" level=debug msg="completed keyexchange" Feb 19 00:14:06 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 19 00:14:06 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 19 00:14:06 volumio go-librespot[26829]: time="2026-02-19T00:14:06+07:00" level=debug msg="completed challenge" Feb 19 00:14:06 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 19 00:14:06 volumio systemd[1]: shairport-sync.service: Consumed 2.155s CPU time. Feb 19 00:14:06 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 19 00:14:06 volumio go-librespot[26829]: time="2026-02-19T00:14:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 19 00:14:06 volumio sudo[26855]: pam_unix(sudo:session): session closed for user root Feb 19 00:14:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:14:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:14:06 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 19 00:14:06 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 19 00:14:06 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 19 00:14:07 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 19 00:14:07 volumio sudo[26857]: pam_unix(sudo:session): session closed for user root Feb 19 00:14:07 volumio sudo[26859]: pam_unix(sudo:session): session closed for user root Feb 19 00:14:07 volumio volumio[26583]: info: Shairport-Sync Started Feb 19 00:14:07 volumio volumio[26583]: Error adding Membership: Error: addMembership EINVAL Feb 19 00:14:07 volumio volumio[26583]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 19 00:14:07 volumio volumio[26583]: SPOTIFY: BQCOzFImqMeLjOFdiV9fkD55iBP6pF4DfalrK_QubWFeMYqEun2akho5Z35gy4lg4TuL7SQUkPyd4iPonSsH_7w7xU3njqIL1bR-jCoqNsdaGA9Qa_-0LNUZf-hBxxIkLkwZv1Zi7osNhqiUXhs_IJiNr_0V-jNyrW8GrnRYd0U9j10gbD3BlP-tR31cqLksw4QTZTtpZ2VONxCi3lnVqKVFRkcu68Ze4oBeAWbPQ7T7KCHRle2KmSHdb8o8oMSoniKjaeplur4JgpNE7KDLH85eqbcqvIgq3lUPdR8OaBhu2IkejNj1_-Ld Feb 19 00:14:07 volumio volumio[26583]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 19 00:14:07 volumio volumio[26583]: info: New Spotify access token = BQCOzFImqMeLjOFdiV9fkD55iBP6pF4DfalrK_QubWFeMYqEun2akho5Z35gy4lg4TuL7SQUkPyd4iPonSsH_7w7xU3njqIL1bR-jCoqNsdaGA9Qa_-0LNUZf-hBxxIkLkwZv1Zi7osNhqiUXhs_IJiNr_0V-jNyrW8GrnRYd0U9j10gbD3BlP-tR31cqLksw4QTZTtpZ2VONxCi3lnVqKVFRkcu68Ze4oBeAWbPQ7T7KCHRle2KmSHdb8o8oMSoniKjaeplur4JgpNE7KDLH85eqbcqvIgq3lUPdR8OaBhu2IkejNj1_-Ld Feb 19 00:14:07 volumio volumio[26583]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 19 00:14:07 volumio volumio[26583]: info: Shairport-Sync Started Feb 19 00:14:07 volumio volumio[26583]: info: Shairport-Sync Started Feb 19 00:14:07 volumio volumio[26583]: info: CoreCommandRouter::volumioGetState Feb 19 00:14:07 volumio volumio[26583]: info: CorePlayQueue::getTrack 0 Feb 19 00:14:07 volumio volumio[26583]: 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 19 00:14:07 volumio volumio[26583]: info: Spotify Successfully logged in Feb 19 00:14:07 volumio volumio[26583]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 00:14:07 volumio volumio[26583]: info: [1771434847589] CoreMusicLibrary::Adding element Spotify Feb 19 00:14:07 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 00:14:07 volumio volumio[26583]: Cannot find translation for source YouTube Music Feb 19 00:14:07 volumio volumio[26583]: Cannot find translation for source Spotify Feb 19 00:14:08 volumio volumio[26583]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 19 00:14:08 volumio volumio[26583]: info: CoreCommandRouter::volumioRetrievevolume Feb 19 00:14:08 volumio volumio[26583]: info: VolumeController:: Volume=100 Mute =false Feb 19 00:14:08 volumio volumio[26583]: info: CoreCommandRouter::volumioGetState Feb 19 00:14:08 volumio volumio[26583]: info: CorePlayQueue::getTrack 0 Feb 19 00:14:08 volumio volumio[26583]: info: CoreStateMachine::pushState Feb 19 00:14:08 volumio volumio[26583]: info: CorePlayQueue::getTrack 0 Feb 19 00:14:08 volumio volumio[26583]: info: CoreCommandRouter::volumioPushState Feb 19 00:14:09 volumio volumio[26583]: info: go-librespot daemon successfully initialized Feb 19 00:14:09 volumio mpd[26807]: 2026-02-19T00:14:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 19 00:14:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 19 00:14:09 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 19 00:14:09 volumio sudo[26766]: pam_unix(sudo:session): session closed for user root Feb 19 00:14:09 volumio sudo[26778]: pam_unix(sudo:session): session closed for user root Feb 19 00:14:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:14:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:14:09 volumio go-librespot[26898]: go-librespot daemon starting... Feb 19 00:14:10 volumio go-librespot[26901]: time="2026-02-19T00:14:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:14:10 volumio go-librespot[26901]: time="2026-02-19T00:14:10+07:00" level=debug msg="app state loaded" Feb 19 00:14:10 volumio go-librespot[26901]: time="2026-02-19T00:14:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:14:10 volumio volumio[26583]: error: MPD error: The expression evaluated to a falsy value: Feb 19 00:14:10 volumio volumio[26583]: assert.ok(self.idling) Feb 19 00:14:10 volumio volumio[26583]: error: The expression evaluated to a falsy value: Feb 19 00:14:10 volumio volumio[26583]: assert.ok(self.idling) Feb 19 00:14:10 volumio volumio[26583]: info: MPD running with PID26807 Feb 19 00:14:10 volumio volumio[26583]: ,establishing connection Feb 19 00:14:10 volumio volumio[26583]: error: updateQueue error: null Feb 19 00:14:10 volumio volumio[26583]: info: Completed starting Core Plugins Feb 19 00:14:10 volumio volumio[26583]: info: ------------------------------------------- Feb 19 00:14:10 volumio volumio[26583]: info: ----- MyVolumio plugins startup ---- Feb 19 00:14:10 volumio volumio[26583]: info: ------------------------------------------- Feb 19 00:14:10 volumio volumio[26583]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 19 00:14:10 volumio volumio[26583]: error: updateQueue error: null Feb 19 00:14:10 volumio go-librespot[26901]: time="2026-02-19T00:14:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 19 00:14:10 volumio go-librespot[26901]: time="2026-02-19T00:14:10+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 19 00:14:10 volumio go-librespot[26901]: time="2026-02-19T00:14:10+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 19 00:14:10 volumio go-librespot[26901]: time="2026-02-19T00:14:10+07:00" level=info msg="zeroconf server listening on port 34895" Feb 19 00:14:10 volumio go-librespot[26901]: time="2026-02-19T00:14:10+07:00" level=debug msg="obtained new client token: AADgNE7aJsnuFS8ggX1XN0Y32UstVumFXt/2ww/T7DryUGTlQSPD7aTKNz1e5Hu2ty3QcPxByrSR8K5LOwp7AbS0WkejmsppNTQW02m7/Vli40TuW+R10rqo3UY9UbDqsHEw5OktXhfBXiewzlWVNPHCmJZ+3P2wpG8CPjz09va0Fisvf94pb9rBgQsLyX9/NiBW4xPQ5N3xjMXphTFO57dmDQ39XSxrumAEBtKpaUeyTl1p0F+kWl/27A==" Feb 19 00:14:10 volumio go-librespot[26901]: time="2026-02-19T00:14:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 00:14:10 volumio go-librespot[26901]: time="2026-02-19T00:14:10+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 19 00:14:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:14:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:14:12 volumio volumio[26583]: info: Initializing connection to go-librespot Websocket Feb 19 00:14:12 volumio volumio[26583]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 00:14:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 19 00:14:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:14:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:14:14 volumio go-librespot[26909]: go-librespot daemon starting... Feb 19 00:14:14 volumio go-librespot[26910]: time="2026-02-19T00:14:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:14:14 volumio go-librespot[26910]: time="2026-02-19T00:14:14+07:00" level=debug msg="app state loaded" Feb 19 00:14:14 volumio go-librespot[26910]: time="2026-02-19T00:14:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:14:14 volumio go-librespot[26910]: time="2026-02-19T00:14: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 19 00:14:14 volumio go-librespot[26910]: time="2026-02-19T00:14: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 19 00:14:14 volumio go-librespot[26910]: time="2026-02-19T00:14: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 19 00:14:14 volumio go-librespot[26910]: time="2026-02-19T00:14:14+07:00" level=info msg="zeroconf server listening on port 37787" Feb 19 00:14:14 volumio go-librespot[26910]: time="2026-02-19T00:14:14+07:00" level=debug msg="obtained new client token: AADAb4HPiQ7Wn0XoHJNq7IgarVqJMCt7iwWhbVxj3hBoRB5E850upTNPU927Si9PMFdk5mVNCAikwd7I1VzJxqn6fvjZ83oqCr9BzDCDlQ6wOVL9NRVIoO7laecMsXoFz4G2h/UMp9aIxypZNCm6H3J8z71TI85ih3EGAlfg3qZBwnGvJ5tUiNnR3UX2kOypd4IOWVU1hNc3AJvT4I8ZXWp9uJ0ejjOXVNpZ4mxbv7jQULTrH/DHx4E0BQ==" Feb 19 00:14:14 volumio volumio[26583]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 19 00:14:15 volumio go-librespot[26910]: time="2026-02-19T00:14:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 00:14:15 volumio go-librespot[26910]: time="2026-02-19T00:14:15+07:00" level=debug msg="completed keyexchange" Feb 19 00:14:15 volumio go-librespot[26910]: time="2026-02-19T00:14:15+07:00" level=debug msg="completed challenge" Feb 19 00:14:15 volumio go-librespot[26910]: time="2026-02-19T00:14:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 19 00:14:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:14:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:14:15 volumio volumio[26583]: info: Initializing connection to go-librespot Websocket Feb 19 00:14:15 volumio volumio[26583]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 00:14:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 19 00:14:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:14:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:14:18 volumio go-librespot[26917]: go-librespot daemon starting... Feb 19 00:14:18 volumio go-librespot[26918]: time="2026-02-19T00:14:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:14:18 volumio go-librespot[26918]: time="2026-02-19T00:14:18+07:00" level=debug msg="app state loaded" Feb 19 00:14:18 volumio go-librespot[26918]: time="2026-02-19T00:14:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:14:18 volumio volumio[26583]: info: Initializing connection to go-librespot Websocket Feb 19 00:14:18 volumio go-librespot[26918]: time="2026-02-19T00:14:18+07:00" level=debug msg="new websocket client" Feb 19 00:14:18 volumio volumio[26583]: info: Connection to go-librespot Websocket established Feb 19 00:14:18 volumio go-librespot[26918]: time="2026-02-19T00:14: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-gew1.spotify.com:80]" Feb 19 00:14:18 volumio go-librespot[26918]: time="2026-02-19T00:14:18+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 19 00:14:18 volumio go-librespot[26918]: time="2026-02-19T00:14:18+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 19 00:14:18 volumio go-librespot[26918]: time="2026-02-19T00:14:18+07:00" level=info msg="zeroconf server listening on port 37637" Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 19 00:14:19 volumio volumio[26583]: info: Adding plugin bluetooth to MyMusic Plugins Feb 19 00:14:19 volumio volumio[26583]: info: Adding plugin multiroom to MyMusic Plugins Feb 19 00:14:19 volumio volumio[26583]: info: Adding plugin metavolumio to MyMusic Plugins Feb 19 00:14:19 volumio volumio[26583]: info: Adding plugin cd_controller to MyMusic Plugins Feb 19 00:14:19 volumio volumio[26583]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 19 00:14:19 volumio volumio[26583]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 19 00:14:19 volumio volumio[26583]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 19 00:14:19 volumio volumio[26583]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 19 00:14:19 volumio go-librespot[26918]: time="2026-02-19T00:14:19+07:00" level=debug msg="obtained new client token: AABIOr+B34AUDu1argzk4gnnOWXh/TRj8HfUHcW6hw5rCXvfJJcmK3hh6GIfORsAre05wboq3oF7aTFsr0/qNtdnwlOCt6VlaZHyY7La5/cJHDrnLBVrPQcxcCUdUOdeKeHhygCoRpadLm0EH5GH9Bpmx00VAy/h2IGlAoapqkumu9gd2H7vHtneKS+aFfjQL3tHSeh/exnF2+y3qK0z1PTs0TCSWyukiLyHuf5UL3OnJ6DC6G9vu4s=" Feb 19 00:14:19 volumio go-librespot[26918]: time="2026-02-19T00:14:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 00:14:19 volumio go-librespot[26918]: time="2026-02-19T00:14:19+07:00" level=debug msg="completed keyexchange" Feb 19 00:14:19 volumio go-librespot[26918]: time="2026-02-19T00:14:19+07:00" level=debug msg="completed challenge" Feb 19 00:14:19 volumio go-librespot[26918]: time="2026-02-19T00:14:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 19 00:14:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:14:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:14:20 volumio volumio[26583]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 19 00:14:20 volumio volumio[26583]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 19 00:14:20 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 00:14:20 volumio volumio[26583]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 00:14:20 volumio volumio[26583]: info: Starting MyVolumio Remote Streaming Endpoints Feb 19 00:14:20 volumio volumio[26583]: info: MyVolumio login type: Token Feb 19 00:14:21 volumio volumio[26583]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 19 00:14:21 volumio volumio[26583]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 19 00:14:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 19 00:14:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:14:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 00:14:22 volumio go-librespot[26940]: go-librespot daemon starting... Feb 19 00:14:22 volumio go-librespot[26941]: time="2026-02-19T00:14:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 00:14:22 volumio go-librespot[26941]: time="2026-02-19T00:14:22+07:00" level=debug msg="app state loaded" Feb 19 00:14:22 volumio go-librespot[26941]: time="2026-02-19T00:14:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 00:14:22 volumio volumio[26583]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 19 00:14:22 volumio volumio[26583]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 19 00:14:22 volumio volumio[26583]: info: Streaming services startup Feb 19 00:14:22 volumio volumio[26583]: info: Starting Streaming Daemon Feb 19 00:14:22 volumio sudo[26948]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 19 00:14:22 volumio sudo[26948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 00:14:22 volumio volumio[26583]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 19 00:14:22 volumio sudo[26948]: pam_unix(sudo:session): session closed for user root Feb 19 00:14:23 volumio volumio[26583]: info: Getting Spotify volume Feb 19 00:14:23 volumio volumio[26583]: info: Connection to go-librespot Websocket closed Feb 19 00:14:23 volumio volumio[26583]: error: Cannot start Volumio Streaming Daemon Feb 19 00:14:23 volumio volumio[26583]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 19 00:14:23 volumio volumio[26583]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 19 00:14:23 volumio volumio[26583]: 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 19 00:14:23 volumio go-librespot[26941]: time="2026-02-19T00:14:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 19 00:14:23 volumio go-librespot[26941]: time="2026-02-19T00:14:23+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 19 00:14:23 volumio go-librespot[26941]: time="2026-02-19T00:14:23+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 19 00:14:23 volumio go-librespot[26941]: time="2026-02-19T00:14:23+07:00" level=info msg="zeroconf server listening on port 40987" Feb 19 00:14:23 volumio volumio[26583]: info: CoreCommandRouter::volumioGetState Feb 19 00:14:23 volumio volumio[26583]: info: CorePlayQueue::getTrack 0 Feb 19 00:14:23 volumio volumio[26583]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 19 00:14:23 volumio volumio[26583]: SPOTIFY: SPOTIFY VOLUME undefined Feb 19 00:14:23 volumio volumio[26583]: SPOTIFY: VOLUMIO VOLUME 100 Feb 19 00:14:23 volumio volumio[26583]: info: Aligning Spotify Volume to Volumio Volume Feb 19 00:14:23 volumio volumio[26583]: info: CoreCommandRouter::volumioGetState Feb 19 00:14:23 volumio volumio[26583]: info: CorePlayQueue::getTrack 0 Feb 19 00:14:23 volumio volumio[26583]: info: Setting Spotify Volume from Volumio: 100 Feb 19 00:14:23 volumio go-librespot[26941]: time="2026-02-19T00:14:23+07:00" level=debug msg="obtained new client token: AAB973wmtfgSLlt9a/Q9/uMPpFK+RHKVuuVrASc1brP1WBEcVifcGUYtEtMsHkrFSEdl3Pe0yPkpqZ/y12HrBbXcMj6gDXQJ0V6nv/YE+2rkvGg67isQchifoiQfooioBGLNRlxpT5DK5gKwKEFZR9IYhH5f9vogxJf+0lgjfiVrfDI2kx2J/2UKuQ0uIR3kLUK9OOrKzMI3C5DYxZQajX26Av8igtP75LHLdfl2peotEwtkEIzvxv8c6Q==" Feb 19 00:14:23 volumio go-librespot[26941]: time="2026-02-19T00:14:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 00:14:23 volumio go-librespot[26941]: time="2026-02-19T00:14:23+07:00" level=debug msg="completed keyexchange" Feb 19 00:14:23 volumio go-librespot[26941]: time="2026-02-19T00:14:23+07:00" level=debug msg="completed challenge" Feb 19 00:14:23 volumio go-librespot[26941]: time="2026-02-19T00:14: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 19 00:14:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 00:14:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 00:14:23 volumio volumio[26583]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 19 00:14:23 volumio volumio[26583]: Error: socket hang up Feb 19 00:14:23 volumio volumio[26583]: at connResetException (node:internal/errors:720:14) Feb 19 00:14:23 volumio volumio[26583]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 19 00:14:23 volumio volumio[26583]: at Socket.emit (node:events:526:35) Feb 19 00:14:23 volumio volumio[26583]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 19 00:14:23 volumio volumio[26583]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 19 00:14:23 volumio volumio[26583]: code: 'ECONNRESET', Feb 19 00:14:23 volumio volumio[26583]: response: undefined Feb 19 00:14:23 volumio volumio[26583]: } Feb 19 00:14:23 volumio volumio[26583]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 19 00:14:25 volumio sudo[26969]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-19 00:13' Feb 19 00:14:25 volumio sudo[26969]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"