Feb 17 09:14:02 volumio volumio[3126]: info: Getting Spotify volume Feb 17 09:14:02 volumio volumio[3126]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:14:02 volumio volumio[3126]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:14:02 volumio volumio[3126]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 17 09:14:02 volumio volumio[3126]: errno: -111, Feb 17 09:14:02 volumio volumio[3126]: code: 'ECONNREFUSED', Feb 17 09:14:02 volumio volumio[3126]: syscall: 'connect', Feb 17 09:14:02 volumio volumio[3126]: address: '127.0.0.1', Feb 17 09:14:02 volumio volumio[3126]: port: 9879, Feb 17 09:14:02 volumio volumio[3126]: response: undefined Feb 17 09:14:02 volumio volumio[3126]: } Feb 17 09:14:02 volumio volumio[3126]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:14:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 17 09:14:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:02 volumio go-librespot[3472]: go-librespot daemon starting... Feb 17 09:14:02 volumio go-librespot[3474]: time="2026-02-17T09:14:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:02 volumio go-librespot[3474]: time="2026-02-17T09:14:02+07:00" level=debug msg="app state loaded" Feb 17 09:14:02 volumio go-librespot[3474]: time="2026-02-17T09:14:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:03 volumio go-librespot[3474]: time="2026-02-17T09:14:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:03 volumio go-librespot[3474]: time="2026-02-17T09:14:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:03 volumio go-librespot[3474]: time="2026-02-17T09:14:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:03 volumio go-librespot[3474]: time="2026-02-17T09:14:03+07:00" level=info msg="zeroconf server listening on port 37421" Feb 17 09:14:03 volumio go-librespot[3474]: time="2026-02-17T09:14:03+07:00" level=debug msg="obtained new client token: AAD+uzR/00jZRt4k/SdGXC6fmwbhC/4m0Ra6zDKPEOkSdBebxml1OZas5iPo5VVWKJLc+RBFFzkoZfM6IzfPVVdYyzhV4l8NNaF8TfG+PzQ3zv+jarbZEZYxs2wNDLLpZSPio4OZlOb8A8Tt0l5H8lCQAzdxrviajm4VybT+oSO5YgcFD9HxYavvvc/ZKfTRKa7E/2TpzWsBots0P/CYbutuYmSzSGYxjUwgioA2EmkHzQLVjqHardE=" Feb 17 09:14:03 volumio go-librespot[3474]: time="2026-02-17T09:14:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:03 volumio go-librespot[3474]: time="2026-02-17T09:14:03+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:03 volumio go-librespot[3474]: time="2026-02-17T09:14:03+07:00" level=debug msg="completed challenge" Feb 17 09:14:03 volumio go-librespot[3474]: time="2026-02-17T09:14:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:14:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:03 volumio sudo[3497]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 09:13' Feb 17 09:14:03 volumio sudo[3497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:03 volumio sudo[3497]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:04 volumio volumio-remote-updater[25144]: [2026-02-17 09:14:04] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 17 09:14:04 volumio volumio-remote-updater[25144]: [2026-02-17 09:14:04] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 17 09:14:04 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:04 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 17 09:14:04 volumio systemd[1]: volumio.service: Consumed 49.217s CPU time. Feb 17 09:14:04 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 09:14:04 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 09:14:04 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 20168. Feb 17 09:14:04 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 09:14:04 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 17 09:14:04 volumio systemd[1]: volumio.service: Consumed 49.217s CPU time. Feb 17 09:14:04 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 17 09:14:04 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 09:14:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 17 09:14:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:06 volumio go-librespot[3524]: go-librespot daemon starting... Feb 17 09:14:06 volumio go-librespot[3525]: time="2026-02-17T09:14:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:06 volumio go-librespot[3525]: time="2026-02-17T09:14:06+07:00" level=debug msg="app state loaded" Feb 17 09:14:06 volumio go-librespot[3525]: time="2026-02-17T09:14:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:07 volumio go-librespot[3525]: time="2026-02-17T09:14:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:07 volumio go-librespot[3525]: time="2026-02-17T09:14:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:07 volumio go-librespot[3525]: time="2026-02-17T09:14:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:07 volumio go-librespot[3525]: time="2026-02-17T09:14:07+07:00" level=info msg="zeroconf server listening on port 42741" Feb 17 09:14:07 volumio go-librespot[3525]: time="2026-02-17T09:14:07+07:00" level=debug msg="obtained new client token: AADRBwr6LFWxT9p6aFyMG4O3cvI2dOPW9igErS9QsRSK50PyGZQRpbrcwkoL1hALpcDfTl7hyIIPfw8Y85L+HeHtIGhd/0EEn1LU+OTYri70MwslS0DK58wi4hNTA4oJeuoy8HVdBQql5mMLYS0mYJg9BIdF+8u16NNTA3rfnBvjNGlOeW352kNuVx57xogGGATOgmDo2PK12Po6bMYzoqvGuH6UXsPGkSvv6Nt2v0iGHctrWAvOjskGOQ==" Feb 17 09:14:07 volumio go-librespot[3525]: time="2026-02-17T09:14:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:07 volumio go-librespot[3525]: time="2026-02-17T09:14:07+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:07 volumio go-librespot[3525]: time="2026-02-17T09:14:07+07:00" level=debug msg="completed challenge" Feb 17 09:14:07 volumio volumio[3509]: info: ------------------------------------------- Feb 17 09:14:08 volumio volumio[3509]: info: ----- Volumio3 ---- Feb 17 09:14:08 volumio volumio[3509]: info: ------------------------------------------- Feb 17 09:14:08 volumio volumio[3509]: info: ----- System startup ---- Feb 17 09:14:08 volumio volumio[3509]: info: ------------------------------------------- Feb 17 09:14:08 volumio go-librespot[3525]: time="2026-02-17T09:14:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:14:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:09 volumio volumio-remote-updater[25144]: [2026-02-17 09:14:09] [connect] Successful connection Feb 17 09:14:09 volumio volumio[3509]: info: MYVOLUMIO Environment detected Feb 17 09:14:09 volumio volumio[3509]: info: Plugin folders cleanup Feb 17 09:14:09 volumio volumio[3509]: info: Scanning into folder /volumio/app/plugins/ Feb 17 09:14:09 volumio volumio[3509]: info: Scanning category audio_interface Feb 17 09:14:09 volumio volumio[3509]: info: Scanning category miscellanea Feb 17 09:14:09 volumio volumio[3509]: info: Scanning category music_service Feb 17 09:14:09 volumio volumio[3509]: info: Scanning category plugins.json Feb 17 09:14:09 volumio volumio[3509]: info: Scanning category system_controller Feb 17 09:14:09 volumio volumio[3509]: info: Scanning category user_interface Feb 17 09:14:09 volumio volumio[3509]: info: Scanning into folder /data/plugins/ Feb 17 09:14:09 volumio volumio[3509]: info: Scanning category music_service Feb 17 09:14:09 volumio volumio[3509]: info: Plugin folders cleanup completed Feb 17 09:14:09 volumio volumio[3509]: info: ------------------------------------------- Feb 17 09:14:09 volumio volumio[3509]: info: ----- Core plugins startup ---- Feb 17 09:14:09 volumio volumio[3509]: info: ------------------------------------------- Feb 17 09:14:09 volumio volumio[3509]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 09:14:09 volumio volumio[3509]: info: Adding plugin upnp to MyMusic Plugins Feb 17 09:14:09 volumio volumio[3509]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 09:14:09 volumio volumio[3509]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 09:14:09 volumio volumio[3509]: info: Loading plugins from folder /data/plugins/ Feb 17 09:14:09 volumio volumio[3509]: info: Loading plugin "system"... Feb 17 09:14:09 volumio volumio[3509]: info: Loading plugin "appearance"... Feb 17 09:14:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 17 09:14:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:11 volumio go-librespot[3545]: go-librespot daemon starting... Feb 17 09:14:11 volumio go-librespot[3546]: time="2026-02-17T09:14:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:11 volumio go-librespot[3546]: time="2026-02-17T09:14:11+07:00" level=debug msg="app state loaded" Feb 17 09:14:11 volumio go-librespot[3546]: time="2026-02-17T09:14:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:11 volumio volumio[3509]: info: Loading plugin "network"... Feb 17 09:14:11 volumio volumio[3509]: info: Refreshing Cached IP Addresses Feb 17 09:14:11 volumio sudo[3555]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 09:14:11 volumio sudo[3555]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:11 volumio sudo[3555]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:11 volumio sudo[3557]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 09:14:11 volumio sudo[3557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:11 volumio volumio[3509]: info: Loading plugin "services"... Feb 17 09:14:11 volumio volumio[3509]: info: Loading plugin "alsa_controller"... Feb 17 09:14:11 volumio sudo[3557]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:11 volumio sudo[3565]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 09:14:11 volumio sudo[3565]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:11 volumio go-librespot[3546]: time="2026-02-17T09:14:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:11 volumio go-librespot[3546]: time="2026-02-17T09:14:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:11 volumio go-librespot[3546]: time="2026-02-17T09:14:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:11 volumio go-librespot[3546]: time="2026-02-17T09:14:11+07:00" level=info msg="zeroconf server listening on port 37517" Feb 17 09:14:11 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:14:11 volumio volumio[3509]: info: Loading plugin "wizard"... Feb 17 09:14:11 volumio volumio[3509]: info: Loading plugin "networkfs"... Feb 17 09:14:11 volumio volumio[3509]: info: Starting Udev Watcher for removable devices Feb 17 09:14:11 volumio volumio[3509]: info: Ignoring mount for partition: boot Feb 17 09:14:11 volumio volumio[3509]: info: Ignoring mount for partition: volumio Feb 17 09:14:11 volumio volumio[3509]: info: Ignoring mount for partition: volumio_data Feb 17 09:14:11 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:14:11 volumio volumio[3509]: info: Loading plugin "volumio_command_line_client"... Feb 17 09:14:11 volumio go-librespot[3546]: time="2026-02-17T09:14:11+07:00" level=debug msg="obtained new client token: AAABXbLPiiX/CJkfqLqNvmXS5pH+b5GjkyFvF4TXWmHH05yBhZDxLGxH15hJo25O0gK7KdU7ysDxKrzso901N00e9+K9fB5eoh5rJYpuipGR9MEdL8E0bGocyrMHHcbnc3a6z68pMh+T0NNf/E5WYFytFEdVY6EaK9h+yBzKvYsetjSGUn0WBYi85mTaEQlZ+QYO39BfMEgQ3AGPeqwwvICEQ1dJ6Q4UU+AexATUSGSI6jmtH62eX0nk+A==" Feb 17 09:14:11 volumio volumio[3509]: info: Loading plugin "upnp"... Feb 17 09:14:11 volumio volumio[3509]: info: [1771294451933] Starting Upmpd Daemon Feb 17 09:14:11 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:14:11 volumio volumio[3509]: info: Loading plugin "my_music"... Feb 17 09:14:11 volumio volumio[3509]: info: Loading plugin "mpd"... Feb 17 09:14:12 volumio go-librespot[3546]: time="2026-02-17T09:14:12+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 17 09:14:12 volumio go-librespot[3546]: time="2026-02-17T09:14:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 09:14:12 volumio volumio[3509]: info: Loading plugin "upnp_browser"... Feb 17 09:14:12 volumio go-librespot[3546]: time="2026-02-17T09:14:12+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:12 volumio go-librespot[3546]: time="2026-02-17T09:14:12+07:00" level=debug msg="completed challenge" Feb 17 09:14:12 volumio go-librespot[3546]: time="2026-02-17T09:14:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:14:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:14 volumio sudo[3565]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:15 volumio volumio[3509]: info: Starting UPNP Browser Feb 17 09:14:15 volumio volumio[3509]: info: Loading plugin "alarm-clock"... Feb 17 09:14:15 volumio volumio[3509]: info: Loading plugin "airplay_emulation"... Feb 17 09:14:15 volumio volumio[3509]: info: Starting Shairport Sync Feb 17 09:14:15 volumio volumio[3509]: info: Loading plugin "last_100"... Feb 17 09:14:15 volumio volumio[3509]: info: Loading plugin "webradio"... Feb 17 09:14:16 volumio volumio[3509]: info: Loading plugin "i2s_dacs"... Feb 17 09:14:16 volumio volumio[3509]: info: Loading plugin "volumiodiscovery"... Feb 17 09:14:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Feb 17 09:14:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:16 volumio volumio[3509]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 09:14:16 volumio volumio[3509]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:14:16 volumio volumio[3509]: *** WARNING *** For more information see Feb 17 09:14:16 volumio volumio[3509]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 09:14:16 volumio volumio[3509]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:14:16 volumio volumio[3509]: *** WARNING *** For more information see Feb 17 09:14:16 volumio node[3509]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 09:14:16 volumio node[3509]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:14:16 volumio node[3509]: *** WARNING *** For more information see Feb 17 09:14:16 volumio node[3509]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 09:14:16 volumio node[3509]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:14:16 volumio node[3509]: *** WARNING *** For more information see Feb 17 09:14:16 volumio volumio[3509]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 09:14:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:16 volumio go-librespot[3589]: go-librespot daemon starting... Feb 17 09:14:16 volumio volumio[3509]: info: Discovery: Started advertising with name: Volumio Feb 17 09:14:16 volumio go-librespot[3590]: time="2026-02-17T09:14:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:16 volumio go-librespot[3590]: time="2026-02-17T09:14:16+07:00" level=debug msg="app state loaded" Feb 17 09:14:16 volumio go-librespot[3590]: time="2026-02-17T09:14:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:16 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:14:16 volumio volumio[3509]: info: Loading plugin "spop"... Feb 17 09:14:16 volumio go-librespot[3590]: time="2026-02-17T09:14:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 09:14:16 volumio go-librespot[3590]: time="2026-02-17T09:14:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 09:14:16 volumio go-librespot[3590]: time="2026-02-17T09:14:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 09:14:16 volumio go-librespot[3590]: time="2026-02-17T09:14:16+07:00" level=info msg="zeroconf server listening on port 35719" Feb 17 09:14:16 volumio go-librespot[3590]: time="2026-02-17T09:14:16+07:00" level=debug msg="obtained new client token: AABwjoE8qlACABLY+n9D7LK/bb/AySsdp+VjFr/JHl+VfwKzT8bQaotjIyfa5wAW0b84H5ALluqJFoTIAuz/ZzT+CYRfiq3OUT0JmifBOcCWPtZFLvxIHg0FXwTwt7zXIg3OBtlGSdW2cKt8/vyjBw/Dh54VgRDcx78UsVVTvOp0Gnilzw0hQct3ZsoiK6dXYmm5R96WXqb1AgXYNwtjEE04P2P2zHgYdZFfHwtI4sYUpP1JNpaVEbRe+A==" Feb 17 09:14:17 volumio go-librespot[3590]: time="2026-02-17T09:14:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:17 volumio go-librespot[3590]: time="2026-02-17T09:14:17+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:17 volumio go-librespot[3590]: time="2026-02-17T09:14:17+07:00" level=debug msg="completed challenge" Feb 17 09:14:17 volumio go-librespot[3590]: time="2026-02-17T09:14:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:14:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:18 volumio volumio[3509]: info: Loading plugin "ytcr"... Feb 17 09:14:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Feb 17 09:14:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:20 volumio go-librespot[3599]: go-librespot daemon starting... Feb 17 09:14:20 volumio go-librespot[3600]: time="2026-02-17T09:14:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:20 volumio go-librespot[3600]: time="2026-02-17T09:14:20+07:00" level=debug msg="app state loaded" Feb 17 09:14:20 volumio go-librespot[3600]: time="2026-02-17T09:14:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:20 volumio volumio[3509]: info: Loading plugin "ytmusic"... Feb 17 09:14:20 volumio go-librespot[3600]: time="2026-02-17T09:14:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:20 volumio go-librespot[3600]: time="2026-02-17T09:14:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:20 volumio go-librespot[3600]: time="2026-02-17T09:14:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:20 volumio go-librespot[3600]: time="2026-02-17T09:14:20+07:00" level=info msg="zeroconf server listening on port 38865" Feb 17 09:14:21 volumio go-librespot[3600]: time="2026-02-17T09:14:21+07:00" level=debug msg="obtained new client token: AABRcF1XxU/USxEelAc23TF/cc47L3L3l+SMGcI3nH/5ZQjwNnM/931C+4dZPDKhN5pJM0iKVuPsC1ukAWdqO2XkhjcxaYolHYPKpU/p13XCibj3OIB8KF8vgQVTsv4njKiIUR/3jH6799nSIw9Tfh1YAAPyJUtJtljyRFLjkP19YM+B3yPTUM545cYzCO0mziu9RHadsH2p2jELB5UGZX3pCWkmyAYlAynyt+1npJcwCrhHmPcvHp4=" Feb 17 09:14:21 volumio go-librespot[3600]: time="2026-02-17T09:14:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:21 volumio go-librespot[3600]: time="2026-02-17T09:14:21+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:21 volumio go-librespot[3600]: time="2026-02-17T09:14:21+07:00" level=debug msg="completed challenge" Feb 17 09:14:21 volumio go-librespot[3600]: time="2026-02-17T09:14:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:14:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:21 volumio volumio-remote-updater[25144]: [2026-02-17 09:14:21] [connect] Successful connection Feb 17 09:14:21 volumio volumio[3509]: info: Loading plugin "outputs"... Feb 17 09:14:21 volumio volumio[3509]: info: Loading plugin "albumart"... Feb 17 09:14:21 volumio volumio[3509]: info: Plugin example_plugin is not enabled Feb 17 09:14:21 volumio volumio[3509]: info: Loading plugin "inputs"... Feb 17 09:14:21 volumio volumio[3509]: info: Loading plugin "updater_comm"... Feb 17 09:14:22 volumio volumio[3509]: info: Plugin mpdemulation is not enabled Feb 17 09:14:22 volumio volumio[3509]: info: Loading plugin "rest_api"... Feb 17 09:14:22 volumio volumio[3509]: info: Loading plugin "websocket"... Feb 17 09:14:22 volumio volumio[3509]: info: Starting Socket.io Server version 1.7.4 Feb 17 09:14:22 volumio volumio[3509]: info: Loading plugin "RoonBridge"... Feb 17 09:14:22 volumio volumio[3509]: info: Applying required configuration parameters for plugin RoonBridge Feb 17 09:14:22 volumio volumio[3509]: info: Loading i18n strings for locale en Feb 17 09:14:22 volumio volumio[3509]: Updating browse sources language Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::initPlayerControls Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:22 volumio volumio[3621]: Forking 3 albumart workers Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:14:22 volumio volumio[3509]: Express server listening on port 3000 Feb 17 09:14:22 volumio volumio[3509]: [Metrics] WebUI: 15s 953.99ms Feb 17 09:14:23 volumio volumio[3509]: info: CoreStateMachine::resetVolumioState Feb 17 09:14:23 volumio volumio[3509]: info: CoreStateMachine::getcurrentVolume Feb 17 09:14:23 volumio volumio[3509]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:14:23 volumio sudo[3663]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 09:14:23 volumio sudo[3663]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:23 volumio sudo[3663]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:23 volumio sudo[3665]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 09:14:23 volumio sudo[3665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:23 volumio sudo[3665]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:23 volumio volumio[3509]: info: Volumio Network Manager: Network status updated: 1 Feb 17 09:14:23 volumio volumio[3509]: info: VolumeController:: Volume=100 Mute =false Feb 17 09:14:23 volumio volumio[3509]: info: CoreStateMachine::pushState Feb 17 09:14:23 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:23 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 09:14:23 volumio volumio[3509]: info: CoreCommandRouter::volumioPushState Feb 17 09:14:23 volumio volumio[3509]: info: CoreStateMachine::updateTrackBlock Feb 17 09:14:23 volumio volumio[3509]: info: CorePlayQueue::getTrackBlock Feb 17 09:14:23 volumio volumio[3509]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:14:23 volumio volumio-remote-updater[25144]: [2026-02-17 09:14:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771294461 101 Feb 17 09:14:23 volumio volumio[3509]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 17 09:14:23 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:14:23 volumio volumio[3509]: info: Reloading queue from file Feb 17 09:14:23 volumio volumio[3509]: info: CoreStateMachine::setRepeat null single undefined Feb 17 09:14:23 volumio volumio[3509]: info: CoreStateMachine::pushState Feb 17 09:14:23 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:23 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 09:14:23 volumio volumio[3509]: info: CoreCommandRouter::volumioPushState Feb 17 09:14:23 volumio volumio[3509]: info: CoreStateMachine::setRandom null Feb 17 09:14:23 volumio volumio[3509]: info: CoreStateMachine::pushState Feb 17 09:14:23 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:23 volumio volumio[3509]: info: CoreCommandRouter::volumioPushState Feb 17 09:14:23 volumio volumio[3509]: info: Setting Device type: Raspberry PI Feb 17 09:14:24 volumio volumio[3509]: info: Completed loading Core Plugins Feb 17 09:14:24 volumio volumio[3509]: info: Preparing to generate the ALSA configuration file Feb 17 09:14:24 volumio volumio[3509]: info: VolumeController:: Volume=100 Mute =false Feb 17 09:14:24 volumio volumio[3509]: info: CoreStateMachine::pushState Feb 17 09:14:24 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::volumioPushState Feb 17 09:14:24 volumio volumio[3509]: info: Asound.conf file unchanged, so no further update is needed Feb 17 09:14:24 volumio volumio[3509]: info: Output device has changed, restarting MPD Feb 17 09:14:24 volumio volumio[3509]: info: Output device has changed, restarting Shairport Sync Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:14:24 volumio sudo[3682]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 09:14:24 volumio sudo[3682]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:24 volumio sudo[3684]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 09:14:24 volumio sudo[3687]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 09:14:24 volumio sudo[3684]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:24 volumio volumio[3509]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:14:24 volumio sudo[3687]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:24 volumio volumio[3509]: info: ___________ START PLUGINS ___________ Feb 17 09:14:24 volumio volumio[3509]: info: ControllerMpd::onStart: Initializing MPD Feb 17 09:14:24 volumio volumio[3509]: info: Creating MPD Configuration file Feb 17 09:14:24 volumio sudo[3684]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:24 volumio sudo[3682]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:14:24 volumio volumio[3509]: info: [1771294464460] CoreMusicLibrary::Adding element Media Servers Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:14:24 volumio volumio[3509]: info: UPNP Browser: Client initialized successfully Feb 17 09:14:24 volumio sudo[3695]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 09:14:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Feb 17 09:14:24 volumio sudo[3695]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:24 volumio sudo[3695]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:14:24 volumio sudo[3697]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 09:14:24 volumio sudo[3697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:24 volumio go-librespot[3699]: go-librespot daemon starting... Feb 17 09:14:24 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 09:14:24 volumio go-librespot[3703]: time="2026-02-17T09:14:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:24 volumio go-librespot[3703]: time="2026-02-17T09:14:24+07:00" level=debug msg="app state loaded" Feb 17 09:14:24 volumio go-librespot[3703]: time="2026-02-17T09:14:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:24 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 09:14:24 volumio volumio[3509]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:14:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 09:14:24 volumio systemd[1]: mpd.service: Consumed 7.047s CPU time. Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:14:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 09:14:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 09:14:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 09:14:24 volumio volumio[3509]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:14:24 volumio volumio[3509]: info: [1771294464825] CoreMusicLibrary::Adding element Last_100 Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:14:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:14:24 volumio volumio[3509]: info: [1771294464840] CoreMusicLibrary::Adding element Webradio Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:14:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:14:24 volumio volumio[3509]: info: Initializing BBC Radios Feb 17 09:14:24 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 09:14:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 09:14:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 09:14:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 09:14:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 09:14:25 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 09:14:25 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 09:14:25 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:14:25 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:14:25 volumio volumio[3509]: info: Creating Spotify config file Feb 17 09:14:25 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:25 volumio go-librespot[3703]: time="2026-02-17T09:14:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:25 volumio go-librespot[3703]: time="2026-02-17T09:14:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:25 volumio go-librespot[3703]: time="2026-02-17T09:14:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:25 volumio go-librespot[3703]: time="2026-02-17T09:14:25+07:00" level=info msg="zeroconf server listening on port 43335" Feb 17 09:14:25 volumio sudo[3728]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 09:14:25 volumio sudo[3728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 09:14:25 volumio sudo[3728]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:25 volumio go-librespot[3703]: time="2026-02-17T09:14:25+07:00" level=debug msg="obtained new client token: AADkuZ6QRM71S7CqaLaoEVhGbm1jnXwoANfw5asA263TjTbu7asdijLq6wrcE2DSrKUHgc0ozquMmYF0Huiad143qoW6r5Al8I2V1P3fV8pLHHAQx/k5TMx3CXx9mh57mPNm7rzQhbp/cACKII3soaueMpHVp5EuM7lmJ704CMTURKXuUVQxJe0koqw1rfbDDxqIuNoa6X/1upDJ61cdVKcnPaiSTGjloz+nLOjOgROu4WD2BAPVHgb1Tw==" Feb 17 09:14:25 volumio go-librespot[3703]: time="2026-02-17T09:14:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:26 volumio go-librespot[3703]: time="2026-02-17T09:14:26+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:26 volumio go-librespot[3703]: time="2026-02-17T09:14:26+07:00" level=debug msg="completed challenge" Feb 17 09:14:26 volumio go-librespot[3703]: time="2026-02-17T09:14:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:14:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:26 volumio volumio[3509]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:14:26 volumio volumio[3509]: info: [1771294466267] CoreMusicLibrary::Adding element YouTube Music Feb 17 09:14:26 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:14:26 volumio volumio[3509]: Cannot find translation for source YouTube Music Feb 17 09:14:26 volumio volumio[3509]: info: Volumio Calling Home Feb 17 09:14:26 volumio sudo[3738]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 09:14:26 volumio sudo[3738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:26 volumio sudo[3738]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:26 volumio volumio[3631]: Starting albumart workers Feb 17 09:14:26 volumio volumio[3632]: Starting albumart workers Feb 17 09:14:26 volumio volumio[3634]: Starting albumart workers Feb 17 09:14:27 volumio volumio[3509]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 09:14:27 volumio volumio[3509]: info: Discovery: Found device Volumio Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::volumioGetState Feb 17 09:14:27 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:27 volumio volumio[3509]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 09:14:27 volumio volumio[3509]: info: Discovery: Found device Volumio Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::volumioGetState Feb 17 09:14:27 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:27 volumio volumio[3509]: info: MPD Permissions set Feb 17 09:14:27 volumio volumio[3509]: info: MPD Permissions set Feb 17 09:14:27 volumio volumio[3509]: info: Upmpdcli Daemon Started Feb 17 09:14:27 volumio volumio[3509]: info: Spotify config file written Feb 17 09:14:27 volumio volumio[3509]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 17 09:14:27 volumio sudo[3746]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 09:14:27 volumio sudo[3746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: No need to fix Spotify hosts Feb 17 09:14:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:27 volumio go-librespot[3758]: go-librespot daemon starting... Feb 17 09:14:27 volumio sudo[3746]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:27 volumio go-librespot[3759]: time="2026-02-17T09:14:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:27 volumio go-librespot[3759]: time="2026-02-17T09:14:27+07:00" level=debug msg="app state loaded" Feb 17 09:14:27 volumio go-librespot[3759]: time="2026-02-17T09:14:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:28 volumio go-librespot[3759]: time="2026-02-17T09:14:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:28 volumio go-librespot[3759]: time="2026-02-17T09:14:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:28 volumio go-librespot[3759]: time="2026-02-17T09:14:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:28 volumio go-librespot[3759]: time="2026-02-17T09:14:28+07:00" level=info msg="zeroconf server listening on port 44669" Feb 17 09:14:28 volumio go-librespot[3759]: time="2026-02-17T09:14:28+07:00" level=debug msg="obtained new client token: AACcaiI4CjWKjU0bllGG+AmTYCb5/cR9FRiWqsXLEqVSA/gzcame0n4UbzeCxkTUPQvqvqp4QhyTVr9Yo9zlZ8hQ2Y3MiEN9FEiiphqckFC1EKoB94wIIPQlACg4PjvsKi4jsgjUPbDjn0/bKGp8ZnTtKevw2/hfbNW0tIwlttPE4QU46JeDdQVjqBR641ZsvynbWRvfaO0FyWJb1qv2ux+971JsIsiqzmkiLqoP8zQYRVBHCF45xjSIKA==" Feb 17 09:14:28 volumio go-librespot[3759]: time="2026-02-17T09:14:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:29 volumio go-librespot[3759]: time="2026-02-17T09:14:29+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:29 volumio go-librespot[3759]: time="2026-02-17T09:14:29+07:00" level=debug msg="completed challenge" Feb 17 09:14:29 volumio go-librespot[3759]: time="2026-02-17T09:14:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:14:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:29 volumio volumio[3509]: info: Volumio called home Feb 17 09:14:29 volumio volumio[3509]: info: Starting Shairport Sync Feb 17 09:14:29 volumio volumio[3509]: info: Starting Shairport Sync Feb 17 09:14:29 volumio volumio[3509]: info: Starting Shairport Sync Feb 17 09:14:29 volumio sudo[3787]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:14:29 volumio sudo[3787]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:29 volumio sudo[3789]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:14:29 volumio sudo[3789]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:29 volumio sudo[3792]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:14:29 volumio sudo[3792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:29 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 09:14:29 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 09:14:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:14:29 volumio systemd[1]: shairport-sync.service: Consumed 2.272s CPU time. Feb 17 09:14:29 volumio volumio[3509]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 09:14:29 volumio volumio[3509]: SPOTIFY: BQBz-mGbDXypweTAHOPwkd444Gp8E1UAahNAEvBDcOatvnOi9rNIHK8Vmncrw0u5nD7JyirHjqwyAVvJEVQpfpxw0AiBOwxms2GEKx1bNKBYHNIrUyUEIIGzDg_qGnvGKco3-cT42B9ISjGT7vQVbSzihxZjW72J5IrBm4E3ygFwOIKm71JY0Zsf-p2TUfjQpzS7LWRppmo1n-GMPBrK3Z7ws7rk2yf8l_M--ejvE8bKqO5YAMHKLIJXm9-N4Qjv3b8MiIUZEsTOAI-bMz0Xkf-du0zz6QLZBTBH3MDz6bdWr9IdZWqfJsS1 Feb 17 09:14:29 volumio volumio[3509]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 09:14:29 volumio volumio[3509]: info: New Spotify access token = BQBz-mGbDXypweTAHOPwkd444Gp8E1UAahNAEvBDcOatvnOi9rNIHK8Vmncrw0u5nD7JyirHjqwyAVvJEVQpfpxw0AiBOwxms2GEKx1bNKBYHNIrUyUEIIGzDg_qGnvGKco3-cT42B9ISjGT7vQVbSzihxZjW72J5IrBm4E3ygFwOIKm71JY0Zsf-p2TUfjQpzS7LWRppmo1n-GMPBrK3Z7ws7rk2yf8l_M--ejvE8bKqO5YAMHKLIJXm9-N4Qjv3b8MiIUZEsTOAI-bMz0Xkf-du0zz6QLZBTBH3MDz6bdWr9IdZWqfJsS1 Feb 17 09:14:29 volumio volumio[3509]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 09:14:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:14:29 volumio volumio[3509]: info: CoreCommandRouter::volumioGetState Feb 17 09:14:29 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:29 volumio sudo[3787]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:29 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 09:14:29 volumio volumio[3509]: info: Shairport-Sync Started Feb 17 09:14:29 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 09:14:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:14:29 volumio volumio[3509]: Error adding Membership: Error: addMembership EINVAL Feb 17 09:14:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:14:29 volumio sudo[3792]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:29 volumio sudo[3789]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:29 volumio volumio[3509]: info: Shairport-Sync Started Feb 17 09:14:30 volumio volumio[3509]: info: Shairport-Sync Started Feb 17 09:14:30 volumio volumio[3509]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 17 09:14:30 volumio volumio[3509]: info: Spotify Successfully logged in Feb 17 09:14:30 volumio volumio[3509]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:14:30 volumio volumio[3509]: info: [1771294470084] CoreMusicLibrary::Adding element Spotify Feb 17 09:14:30 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:14:30 volumio volumio[3509]: Cannot find translation for source YouTube Music Feb 17 09:14:30 volumio volumio[3509]: Cannot find translation for source Spotify Feb 17 09:14:30 volumio volumio[3509]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 09:14:30 volumio volumio[3509]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:14:31 volumio volumio[3509]: info: VolumeController:: Volume=100 Mute =false Feb 17 09:14:31 volumio volumio[3509]: info: CoreCommandRouter::volumioGetState Feb 17 09:14:31 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:31 volumio volumio[3509]: info: CoreStateMachine::pushState Feb 17 09:14:31 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:31 volumio volumio[3509]: info: CoreCommandRouter::volumioPushState Feb 17 09:14:32 volumio volumio[3509]: info: go-librespot daemon successfully initialized Feb 17 09:14:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Feb 17 09:14:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:32 volumio go-librespot[3836]: go-librespot daemon starting... Feb 17 09:14:32 volumio go-librespot[3837]: time="2026-02-17T09:14:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:32 volumio go-librespot[3837]: time="2026-02-17T09:14:32+07:00" level=debug msg="app state loaded" Feb 17 09:14:32 volumio go-librespot[3837]: time="2026-02-17T09:14:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:32 volumio mpd[3735]: 2026-02-17T09:14:32 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 09:14:32 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 09:14:32 volumio sudo[3697]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:32 volumio sudo[3687]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:32 volumio volumio[3509]: error: MPD error: The expression evaluated to a falsy value: Feb 17 09:14:32 volumio volumio[3509]: assert.ok(self.idling) Feb 17 09:14:32 volumio volumio[3509]: error: The expression evaluated to a falsy value: Feb 17 09:14:32 volumio volumio[3509]: assert.ok(self.idling) Feb 17 09:14:32 volumio volumio[3509]: info: MPD running with PID3735 Feb 17 09:14:32 volumio volumio[3509]: ,establishing connection Feb 17 09:14:32 volumio volumio[3509]: error: updateQueue error: null Feb 17 09:14:32 volumio volumio[3509]: info: Completed starting Core Plugins Feb 17 09:14:32 volumio volumio[3509]: info: ------------------------------------------- Feb 17 09:14:32 volumio volumio[3509]: info: ----- MyVolumio plugins startup ---- Feb 17 09:14:32 volumio volumio[3509]: info: ------------------------------------------- Feb 17 09:14:32 volumio volumio[3509]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 09:14:32 volumio volumio[3509]: error: updateQueue error: null Feb 17 09:14:32 volumio go-librespot[3837]: time="2026-02-17T09:14:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 09:14:32 volumio go-librespot[3837]: time="2026-02-17T09:14:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 09:14:32 volumio go-librespot[3837]: time="2026-02-17T09:14:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 09:14:32 volumio go-librespot[3837]: time="2026-02-17T09:14:32+07:00" level=info msg="zeroconf server listening on port 46625" Feb 17 09:14:33 volumio go-librespot[3837]: time="2026-02-17T09:14:33+07:00" level=debug msg="obtained new client token: AAAs80VfG5kwGM/47VOTrt6+BObFiWHRhgTaj60lvL5KIETqRHP8EihHrh+yDX//Adgwz3hKpld4+1x8iWFAoF/c8C+foamKVy8HoIEeLc+eWrpZmdtk1nSe3CozmD83ZjPyEKT4yrlq98hBK5onK7lCleQ9+dSkoKauNn28/K5MHhl6q5K97jHZJzDQNfKwS/o/wDJpeo+w6XAQn3eqT6OnLNAhY3FpCBwqKyqam4ho++UP60jz5ZM=" Feb 17 09:14:33 volumio go-librespot[3837]: time="2026-02-17T09:14:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:33 volumio go-librespot[3837]: time="2026-02-17T09:14:33+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:33 volumio go-librespot[3837]: time="2026-02-17T09:14:33+07:00" level=debug msg="completed challenge" Feb 17 09:14:33 volumio go-librespot[3837]: time="2026-02-17T09:14:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:14:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:35 volumio volumio[3509]: info: Initializing connection to go-librespot Websocket Feb 17 09:14:35 volumio volumio[3509]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:14:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Feb 17 09:14:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:36 volumio go-librespot[3849]: go-librespot daemon starting... Feb 17 09:14:36 volumio go-librespot[3850]: time="2026-02-17T09:14:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:36 volumio go-librespot[3850]: time="2026-02-17T09:14:36+07:00" level=debug msg="app state loaded" Feb 17 09:14:36 volumio go-librespot[3850]: time="2026-02-17T09:14:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:37 volumio go-librespot[3850]: time="2026-02-17T09:14:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:37 volumio go-librespot[3850]: time="2026-02-17T09:14:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:37 volumio go-librespot[3850]: time="2026-02-17T09:14:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:37 volumio go-librespot[3850]: time="2026-02-17T09:14:37+07:00" level=info msg="zeroconf server listening on port 46483" Feb 17 09:14:37 volumio go-librespot[3850]: time="2026-02-17T09:14:37+07:00" level=debug msg="obtained new client token: AABAHiT6qVpB0fhX7XRdpzQnV2WgBXyYh1/NIU9LG8XqliAF2FonSdZYPl86kjg1Su2ye/cFTGHz3RUBaySvSN4qk1RmtZcSQV7dOLIz3r9XR9JZ9GNl+4YYntIIp0bK5cDvqpWQIk/C5IIE+7z8lHhlZZx+1YMwk7vb/mjj/hdwoUxf7fwGXtxuWxuVd25BrrI4P0ucp7apRt3JJw1bc2NuieDv0/8wdc8JqeQb1Vs+0Rb6L7ge3nKlGw==" Feb 17 09:14:37 volumio go-librespot[3850]: time="2026-02-17T09:14:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:37 volumio go-librespot[3850]: time="2026-02-17T09:14:37+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:37 volumio go-librespot[3850]: time="2026-02-17T09:14:37+07:00" level=debug msg="completed challenge" Feb 17 09:14:37 volumio volumio[3509]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 09:14:37 volumio go-librespot[3850]: time="2026-02-17T09:14:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:14:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:38 volumio volumio[3509]: info: Initializing connection to go-librespot Websocket Feb 17 09:14:38 volumio volumio[3509]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:14:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Feb 17 09:14:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:40 volumio go-librespot[3857]: go-librespot daemon starting... Feb 17 09:14:40 volumio go-librespot[3858]: time="2026-02-17T09:14:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:40 volumio go-librespot[3858]: time="2026-02-17T09:14:40+07:00" level=debug msg="app state loaded" Feb 17 09:14:40 volumio go-librespot[3858]: time="2026-02-17T09:14:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:41 volumio volumio[3509]: info: Initializing connection to go-librespot Websocket Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=debug msg="new websocket client" Feb 17 09:14:41 volumio volumio[3509]: info: Connection to go-librespot Websocket established Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=info msg="zeroconf server listening on port 41949" Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=debug msg="obtained new client token: AAAdXdqLs2FWWGjZWBANmGxySExNqDGpaITV53GkbYhZyidr/gfrYZop6kLl/zkm62br+xHy+8m/ZkdbZsxodSC3slMr/93DCNjqka7lLfcg/jaeuJQ50vzmoSI2MDbA2sajnXm7eFH+tB2+VJxf0yCJHwrVgl6W8FK+s4xWzkQCRTT4BAEKlEhqnnmxxXR3Agni0DfRZkfT7WE0Y1Y7gwBu978DkZvLLbDmtLJlKlH1gealrmTtj2KHHA==" Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=debug msg="completed challenge" Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 09:14:41 volumio volumio[3509]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 09:14:41 volumio volumio[3509]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 09:14:41 volumio volumio[3509]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 09:14:41 volumio volumio[3509]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 09:14:41 volumio volumio[3509]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 17 09:14:41 volumio volumio[3509]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 09:14:41 volumio volumio[3509]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:14:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:43 volumio volumio[3509]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 09:14:43 volumio volumio[3509]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 09:14:43 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:14:43 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:14:43 volumio volumio[3509]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 09:14:43 volumio volumio[3509]: info: MyVolumio login type: Token Feb 17 09:14:43 volumio volumio[3509]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 09:14:43 volumio volumio[3509]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 09:14:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Feb 17 09:14:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:45 volumio go-librespot[3879]: go-librespot daemon starting... Feb 17 09:14:45 volumio go-librespot[3880]: time="2026-02-17T09:14:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:45 volumio go-librespot[3880]: time="2026-02-17T09:14:45+07:00" level=debug msg="app state loaded" Feb 17 09:14:45 volumio go-librespot[3880]: time="2026-02-17T09:14:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:45 volumio volumio[3509]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 09:14:45 volumio volumio[3509]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 09:14:45 volumio volumio[3509]: info: Streaming services startup Feb 17 09:14:45 volumio volumio[3509]: info: Starting Streaming Daemon Feb 17 09:14:45 volumio sudo[3888]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 09:14:45 volumio sudo[3888]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:45 volumio volumio[3509]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 09:14:45 volumio go-librespot[3880]: time="2026-02-17T09:14:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:45 volumio go-librespot[3880]: time="2026-02-17T09:14:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:45 volumio go-librespot[3880]: time="2026-02-17T09:14:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:45 volumio sudo[3888]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:45 volumio go-librespot[3880]: time="2026-02-17T09:14:45+07:00" level=info msg="zeroconf server listening on port 38373" Feb 17 09:14:45 volumio volumio[3509]: info: Getting Spotify volume Feb 17 09:14:45 volumio volumio[3509]: info: Connection to go-librespot Websocket closed Feb 17 09:14:45 volumio volumio[3509]: error: Cannot start Volumio Streaming Daemon Feb 17 09:14:45 volumio volumio[3509]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 17 09:14:45 volumio volumio[3509]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 17 09:14:45 volumio volumio[3509]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 17 09:14:45 volumio go-librespot[3880]: time="2026-02-17T09:14:45+07:00" level=debug msg="obtained new client token: AACc1s3HU3izotBzHVCqauAyyruTDafFcDSjYhdDLjRpc7m6lJK3HvG6wLwAdcbEY49jqNZ7ClU4Vo60NHzzZB1ThDQvbSSl5vj9bCRM94iJV4sA85llDHtnEGWlHZ1/x9S8J6A3a05NH7PlizQt71al86CESugG9tRAtodKXwvSR1Lb+5wJCWkw70b0tEp5pPGWkFeGlHCTCK6TtcZWLlYyC4ydi3aItnuePnmCbWpOSBv0pTVbCnNO/A==" Feb 17 09:14:46 volumio go-librespot[3880]: time="2026-02-17T09:14:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:46 volumio volumio[3509]: info: CoreCommandRouter::volumioGetState Feb 17 09:14:46 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:46 volumio volumio[3509]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 17 09:14:46 volumio volumio[3509]: SPOTIFY: SPOTIFY VOLUME undefined Feb 17 09:14:46 volumio volumio[3509]: SPOTIFY: VOLUMIO VOLUME 100 Feb 17 09:14:46 volumio volumio[3509]: info: Aligning Spotify Volume to Volumio Volume Feb 17 09:14:46 volumio volumio[3509]: info: CoreCommandRouter::volumioGetState Feb 17 09:14:46 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:46 volumio volumio[3509]: info: Setting Spotify Volume from Volumio: 100 Feb 17 09:14:46 volumio go-librespot[3880]: time="2026-02-17T09:14:46+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:46 volumio go-librespot[3880]: time="2026-02-17T09:14:46+07:00" level=debug msg="completed challenge" Feb 17 09:14:46 volumio go-librespot[3880]: time="2026-02-17T09:14:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:14:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:46 volumio volumio[3509]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:14:46 volumio volumio[3509]: Error: socket hang up Feb 17 09:14:46 volumio volumio[3509]: at connResetException (node:internal/errors:720:14) Feb 17 09:14:46 volumio volumio[3509]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 17 09:14:46 volumio volumio[3509]: at Socket.emit (node:events:526:35) Feb 17 09:14:46 volumio volumio[3509]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 17 09:14:46 volumio volumio[3509]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 17 09:14:46 volumio volumio[3509]: code: 'ECONNRESET', Feb 17 09:14:46 volumio volumio[3509]: response: undefined Feb 17 09:14:46 volumio volumio[3509]: } Feb 17 09:14:46 volumio volumio[3509]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:14:47 volumio sudo[3908]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 09:13' Feb 17 09:14:47 volumio sudo[3908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:48 volumio sudo[3908]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Feb 17 09:14:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:49 volumio go-librespot[3916]: go-librespot daemon starting... Feb 17 09:14:49 volumio go-librespot[3917]: time="2026-02-17T09:14:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:49 volumio go-librespot[3917]: time="2026-02-17T09:14:49+07:00" level=debug msg="app state loaded" Feb 17 09:14:49 volumio go-librespot[3917]: time="2026-02-17T09:14:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:49 volumio go-librespot[3917]: time="2026-02-17T09:14:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:49 volumio go-librespot[3917]: time="2026-02-17T09:14:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:49 volumio go-librespot[3917]: time="2026-02-17T09:14:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:49 volumio go-librespot[3917]: time="2026-02-17T09:14:49+07:00" level=info msg="zeroconf server listening on port 38001" Feb 17 09:14:50 volumio go-librespot[3917]: time="2026-02-17T09:14:50+07:00" level=debug msg="obtained new client token: AAAXdkskWBEH1Zy9xX9caEL+ZS8tuYkrTIyzjd+EPwuZYmgyaC5Aoc4qWgkPX6PD+BtUJbTkeYeMFVxg4iWukyvg4w6WWusMCAJqF6QEx0BJcKL/mguIezoGuKZRT+m2Gdek36HO5q/dwbjuLtkgzE0FmMxCQtUxfiHKzLHQAq9iGWyGHriKLCMT8BUhZhCX2A0PsgjDaw+KvoH0diL6g+J/ALnyCJ990xl9D60Q31R76qKneBAM+xA=" Feb 17 09:14:50 volumio go-librespot[3917]: time="2026-02-17T09:14:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:50 volumio go-librespot[3917]: time="2026-02-17T09:14:50+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:50 volumio go-librespot[3917]: time="2026-02-17T09:14:50+07:00" level=debug msg="completed challenge" Feb 17 09:14:50 volumio go-librespot[3917]: time="2026-02-17T09:14:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:14:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Feb 17 09:14:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:53 volumio go-librespot[3938]: go-librespot daemon starting... Feb 17 09:14:53 volumio go-librespot[3939]: time="2026-02-17T09:14:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:53 volumio go-librespot[3939]: time="2026-02-17T09:14:53+07:00" level=debug msg="app state loaded" Feb 17 09:14:53 volumio go-librespot[3939]: time="2026-02-17T09:14:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:54 volumio go-librespot[3939]: time="2026-02-17T09:14:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:54 volumio go-librespot[3939]: time="2026-02-17T09:14:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:54 volumio go-librespot[3939]: time="2026-02-17T09:14:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:54 volumio go-librespot[3939]: time="2026-02-17T09:14:54+07:00" level=info msg="zeroconf server listening on port 33485" Feb 17 09:14:54 volumio go-librespot[3939]: time="2026-02-17T09:14:54+07:00" level=debug msg="obtained new client token: AAA0v8SnxcqVywP1vUfiYYiYvLBGAfxJYgQlr7Ym3LNIVTtGpCKRRVGTCtXSqvA9yp4sHn7iRcVIUQli4KiO+ja8FO3h5FVWyRSY/1kF2bcQTS/N2gdWcKm606odXHPTvd9b72nH331YkLuRa4xEnoepkkW6kNMDP90Hy51H6Mi8mxCdmjgdoYRu55T3B5VF7yR5Hi32L3rdhB6aohYoRIBxcjWsbO+SMKcyK/ibQ6csSvybpN6zYP4hmg==" Feb 17 09:14:54 volumio go-librespot[3939]: time="2026-02-17T09:14:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:54 volumio go-librespot[3939]: time="2026-02-17T09:14:54+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:54 volumio go-librespot[3939]: time="2026-02-17T09:14:54+07:00" level=debug msg="completed challenge" Feb 17 09:14:54 volumio go-librespot[3939]: time="2026-02-17T09:14:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:14:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Feb 17 09:14:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:57 volumio go-librespot[3948]: go-librespot daemon starting... Feb 17 09:14:57 volumio go-librespot[3949]: time="2026-02-17T09:14:57+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:57 volumio go-librespot[3949]: time="2026-02-17T09:14:57+07:00" level=debug msg="app state loaded" Feb 17 09:14:57 volumio go-librespot[3949]: time="2026-02-17T09:14:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:58 volumio go-librespot[3949]: time="2026-02-17T09:14:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:58 volumio go-librespot[3949]: time="2026-02-17T09:14:58+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:58 volumio go-librespot[3949]: time="2026-02-17T09:14:58+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:58 volumio go-librespot[3949]: time="2026-02-17T09:14:58+07:00" level=info msg="zeroconf server listening on port 33577" Feb 17 09:14:58 volumio go-librespot[3949]: time="2026-02-17T09:14:58+07:00" level=debug msg="obtained new client token: AAAOgUPkD5e4GsNMHupz83DZSxoIF6hqQOSsmRA1GLAWOhi++CIpuzcLiBecbRJdTJ4IUt4g4QKhLoZVUW1ATkDUXWk9OHz4O95eRowYqPtW0qBR3WQsKxKvybnpJQ/8dDkYa+oQQpY0agFzqgzjZcnoLRv6tCB8YbYwJctxlmoLNynE57BoAVA4ghGyvLdbTA3WYGCp/aOM897tUGgd2Smltoiaw+j9N7aHHkhIP96f12tEMzRMCNjNsQ==" Feb 17 09:14:58 volumio go-librespot[3949]: time="2026-02-17T09:14:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:58 volumio go-librespot[3949]: time="2026-02-17T09:14:58+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:58 volumio go-librespot[3949]: time="2026-02-17T09:14:58+07:00" level=debug msg="completed challenge" Feb 17 09:14:58 volumio go-librespot[3949]: time="2026-02-17T09:14:58+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:14:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:15:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Feb 17 09:15:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:02 volumio go-librespot[3970]: go-librespot daemon starting... Feb 17 09:15:02 volumio go-librespot[3971]: time="2026-02-17T09:15:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:15:02 volumio go-librespot[3971]: time="2026-02-17T09:15:02+07:00" level=debug msg="app state loaded" Feb 17 09:15:02 volumio go-librespot[3971]: time="2026-02-17T09:15:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:15:02 volumio go-librespot[3971]: time="2026-02-17T09:15:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:15:02 volumio go-librespot[3971]: time="2026-02-17T09:15:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:15:02 volumio go-librespot[3971]: time="2026-02-17T09:15:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:15:02 volumio go-librespot[3971]: time="2026-02-17T09:15:02+07:00" level=info msg="zeroconf server listening on port 38999" Feb 17 09:15:02 volumio go-librespot[3971]: time="2026-02-17T09:15:02+07:00" level=debug msg="obtained new client token: AABq5mUfnXXQOdxiqxjRRmzU1GVEqi3cfr+aSHswjb/g/3/Yr1dKQSQ+X7BK/R1NX8T9svjv7qbqioDQHKmVoA06sOzD3RCJqtXDMi4U8WWDvdBTItqF4PgF2jqKJY5qTW4yyRzrkdOhokOybdkpuRpawWj/HAVCd4g55nb4CYY4VneTZShZ6v0ukRjTxu2MPs8Xd8G/zC8r++MAZ2zgNxOOBRkk10Cxgne9n9zPKq21LjKK9w6cYMxonQ==" Feb 17 09:15:02 volumio go-librespot[3971]: time="2026-02-17T09:15:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:15:03 volumio go-librespot[3971]: time="2026-02-17T09:15:03+07:00" level=debug msg="completed keyexchange" Feb 17 09:15:03 volumio go-librespot[3971]: time="2026-02-17T09:15:03+07:00" level=debug msg="completed challenge" Feb 17 09:15:03 volumio go-librespot[3971]: time="2026-02-17T09:15:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:15:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:15:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:15:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Feb 17 09:15:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:06 volumio go-librespot[3978]: go-librespot daemon starting... Feb 17 09:15:06 volumio go-librespot[3979]: time="2026-02-17T09:15:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:15:06 volumio go-librespot[3979]: time="2026-02-17T09:15:06+07:00" level=debug msg="app state loaded" Feb 17 09:15:06 volumio go-librespot[3979]: time="2026-02-17T09:15:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:15:06 volumio go-librespot[3979]: time="2026-02-17T09:15:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:15:06 volumio go-librespot[3979]: time="2026-02-17T09:15:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:15:06 volumio go-librespot[3979]: time="2026-02-17T09:15:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:15:06 volumio go-librespot[3979]: time="2026-02-17T09:15:06+07:00" level=info msg="zeroconf server listening on port 33887" Feb 17 09:15:07 volumio go-librespot[3979]: time="2026-02-17T09:15:07+07:00" level=debug msg="obtained new client token: AACSXImkNYhOci/yaC8+6qsKT0t7Rv2GXFc1mwtcpZJ7x4JnjrpP0EJ5wMPm7uoHUvlyM5rN2Tw97fOBlOuRQt9mn2O1F0HD5ryPgBV3Lq2eQDelYeX/oH4NF8pWs7blpGXhgvPdy6G9rtKxpG5OoUX6rPjEc+lEmsw/5qnQS7/JcrRBvlPcVKzjgJoPFQdoLKF9e+nra3EK391dW08rpytmvtZ9r0MdDb0644AbWteX23U3+3vPRzY=" Feb 17 09:15:07 volumio go-librespot[3979]: time="2026-02-17T09:15:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:15:07 volumio go-librespot[3979]: time="2026-02-17T09:15:07+07:00" level=debug msg="completed keyexchange" Feb 17 09:15:07 volumio go-librespot[3979]: time="2026-02-17T09:15:07+07:00" level=debug msg="completed challenge" Feb 17 09:15:07 volumio go-librespot[3979]: time="2026-02-17T09:15:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:15:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:15:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:15:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Feb 17 09:15:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:10 volumio go-librespot[3986]: go-librespot daemon starting... Feb 17 09:15:10 volumio go-librespot[3987]: time="2026-02-17T09:15:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:15:10 volumio go-librespot[3987]: time="2026-02-17T09:15:10+07:00" level=debug msg="app state loaded" Feb 17 09:15:10 volumio go-librespot[3987]: time="2026-02-17T09:15:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:15:11 volumio go-librespot[3987]: time="2026-02-17T09:15:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:15:11 volumio go-librespot[3987]: time="2026-02-17T09:15:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:15:11 volumio go-librespot[3987]: time="2026-02-17T09:15:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:15:11 volumio go-librespot[3987]: time="2026-02-17T09:15:11+07:00" level=info msg="zeroconf server listening on port 44831" Feb 17 09:15:11 volumio go-librespot[3987]: time="2026-02-17T09:15:11+07:00" level=debug msg="obtained new client token: AABPYIA6px9gTnCzTDDCEoMjwCTikME1OBLbV5AEC7Q9Knq1D4SU6L45Gf3B+vISHFVua2LYnZ2znM4zyX7e+YtsWebhHzCxOI/b2g9q8USRGOuZeLQbow7zSvwpvWXbO+9q/oFvi6SQ+1F9dRTLoTNnNqP+XUlAjIV4ARuHQemBSeJYVGVLBJquW22uZEZV4RHs1L5fRUQXa2rLpHb+LuA4mBl/qeMTT+pumwm6RRfJASPa442oAC70qA==" Feb 17 09:15:11 volumio go-librespot[3987]: time="2026-02-17T09:15:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:15:11 volumio go-librespot[3987]: time="2026-02-17T09:15:11+07:00" level=debug msg="completed keyexchange" Feb 17 09:15:11 volumio go-librespot[3987]: time="2026-02-17T09:15:11+07:00" level=debug msg="completed challenge" Feb 17 09:15:11 volumio go-librespot[3987]: time="2026-02-17T09:15:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:15:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:15:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:15:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Feb 17 09:15:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:14 volumio go-librespot[4009]: go-librespot daemon starting... Feb 17 09:15:14 volumio go-librespot[4010]: time="2026-02-17T09:15:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:15:14 volumio go-librespot[4010]: time="2026-02-17T09:15:14+07:00" level=debug msg="app state loaded" Feb 17 09:15:14 volumio go-librespot[4010]: time="2026-02-17T09:15:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:15:15 volumio go-librespot[4010]: time="2026-02-17T09:15:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 09:15:15 volumio go-librespot[4010]: time="2026-02-17T09:15:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 09:15:15 volumio go-librespot[4010]: time="2026-02-17T09:15:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 09:15:15 volumio go-librespot[4010]: time="2026-02-17T09:15:15+07:00" level=info msg="zeroconf server listening on port 45867" Feb 17 09:15:15 volumio go-librespot[4010]: time="2026-02-17T09:15:15+07:00" level=debug msg="obtained new client token: AABjA0i5TQmKg0ucBhBJGOikdkGG9FQz7wnAjPUUc0Xje7lgc50h/mueIPQVsR/zn0we1bQc8RlwGpTRUfLBpdKyR6apW9ycTYvkjMn8fH4+sSxIa8MPyEH0f7bfg3mo+kosK/olPIAfD9nZmQWF6SxEjvXfDraXfNd5b9VJ2pavIsEUJC0S3TnRejr7p8RIm6aWzVU0kL98x2WsXs/0Z2ZCwjaInNBeB3uADt2uxJxGU37ifImAs3qsbw==" Feb 17 09:15:15 volumio go-librespot[4010]: time="2026-02-17T09:15:15+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 17 09:15:15 volumio go-librespot[4010]: time="2026-02-17T09:15:15+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 17 09:15:15 volumio go-librespot[4010]: time="2026-02-17T09:15:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 17 09:15:16 volumio volumio-remote-updater[25144]: [2026-02-17 09:15:16] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 17 09:15:16 volumio volumio-remote-updater[25144]: [2026-02-17 09:15:16] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 17 09:15:16 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:15:16 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 17 09:15:16 volumio systemd[1]: volumio.service: Consumed 57.285s CPU time. Feb 17 09:15:16 volumio go-librespot[4010]: time="2026-02-17T09:15:16+07:00" level=debug msg="completed keyexchange" Feb 17 09:15:16 volumio go-librespot[4010]: time="2026-02-17T09:15:16+07:00" level=debug msg="completed challenge" Feb 17 09:15:16 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 09:15:16 volumio go-librespot[4010]: time="2026-02-17T09:15:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:15:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:15:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:15:16 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 20169. Feb 17 09:15:16 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 17 09:15:16 volumio systemd[1]: volumio.service: Consumed 57.285s CPU time. Feb 17 09:15:16 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 17 09:15:16 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 09:15:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Feb 17 09:15:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:19 volumio go-librespot[4037]: go-librespot daemon starting... Feb 17 09:15:19 volumio go-librespot[4038]: time="2026-02-17T09:15:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:15:19 volumio go-librespot[4038]: time="2026-02-17T09:15:19+07:00" level=debug msg="app state loaded" Feb 17 09:15:19 volumio go-librespot[4038]: time="2026-02-17T09:15:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:15:19 volumio volumio[4027]: info: ------------------------------------------- Feb 17 09:15:19 volumio volumio[4027]: info: ----- Volumio3 ---- Feb 17 09:15:19 volumio volumio[4027]: info: ------------------------------------------- Feb 17 09:15:19 volumio volumio[4027]: info: ----- System startup ---- Feb 17 09:15:19 volumio volumio[4027]: info: ------------------------------------------- Feb 17 09:15:19 volumio go-librespot[4038]: time="2026-02-17T09:15:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:15:19 volumio go-librespot[4038]: time="2026-02-17T09:15:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:15:19 volumio go-librespot[4038]: time="2026-02-17T09:15:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:15:19 volumio go-librespot[4038]: time="2026-02-17T09:15:19+07:00" level=info msg="zeroconf server listening on port 37689" Feb 17 09:15:20 volumio go-librespot[4038]: time="2026-02-17T09:15:20+07:00" level=debug msg="obtained new client token: AADkr1/P3bvLNbhJZ4zEz63PEQRxwAtM45mfNXfmeQGSMF4YDdkiHOj/wIXFU+bfjOTP6EdYjCI+1l8Jsikdw7958HgjU8bXKNraHAywy7SGBBcNfEdR7atp0EFVvo9m4qq140Rfj/7L+thTmwVAHXvRYpwEfTIP5g4Tx2wSwKRTIwgSiXq2+xx/Yi2saxR7bHinJDQrUa/q2srpZ8hINpM9a4O8PHb6yySduekIaIVYQLgJnA40ao4=" Feb 17 09:15:20 volumio go-librespot[4038]: time="2026-02-17T09:15:20+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 17 09:15:20 volumio go-librespot[4038]: time="2026-02-17T09:15:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 09:15:20 volumio go-librespot[4038]: time="2026-02-17T09:15:20+07:00" level=debug msg="completed keyexchange" Feb 17 09:15:20 volumio go-librespot[4038]: time="2026-02-17T09:15:20+07:00" level=debug msg="completed challenge" Feb 17 09:15:20 volumio go-librespot[4038]: time="2026-02-17T09:15:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:15:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:15:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:15:21 volumio volumio-remote-updater[25144]: [2026-02-17 09:15:21] [connect] Successful connection Feb 17 09:15:21 volumio volumio[4027]: info: MYVOLUMIO Environment detected Feb 17 09:15:21 volumio volumio[4027]: info: Plugin folders cleanup Feb 17 09:15:21 volumio volumio[4027]: info: Scanning into folder /volumio/app/plugins/ Feb 17 09:15:21 volumio volumio[4027]: info: Scanning category audio_interface Feb 17 09:15:21 volumio volumio[4027]: info: Scanning category miscellanea Feb 17 09:15:21 volumio volumio[4027]: info: Scanning category music_service Feb 17 09:15:21 volumio volumio[4027]: info: Scanning category plugins.json Feb 17 09:15:21 volumio volumio[4027]: info: Scanning category system_controller Feb 17 09:15:21 volumio volumio[4027]: info: Scanning category user_interface Feb 17 09:15:21 volumio volumio[4027]: info: Scanning into folder /data/plugins/ Feb 17 09:15:21 volumio volumio[4027]: info: Scanning category music_service Feb 17 09:15:21 volumio volumio[4027]: info: Plugin folders cleanup completed Feb 17 09:15:21 volumio volumio[4027]: info: ------------------------------------------- Feb 17 09:15:21 volumio volumio[4027]: info: ----- Core plugins startup ---- Feb 17 09:15:21 volumio volumio[4027]: info: ------------------------------------------- Feb 17 09:15:21 volumio volumio[4027]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 09:15:21 volumio volumio[4027]: info: Adding plugin upnp to MyMusic Plugins Feb 17 09:15:21 volumio volumio[4027]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 09:15:21 volumio volumio[4027]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 09:15:21 volumio volumio[4027]: info: Loading plugins from folder /data/plugins/ Feb 17 09:15:21 volumio volumio[4027]: info: Loading plugin "system"... Feb 17 09:15:21 volumio volumio[4027]: info: Loading plugin "appearance"... Feb 17 09:15:23 volumio volumio[4027]: info: Loading plugin "network"... Feb 17 09:15:23 volumio volumio[4027]: info: Refreshing Cached IP Addresses Feb 17 09:15:23 volumio sudo[4058]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 09:15:23 volumio sudo[4058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:15:23 volumio volumio[4027]: info: Loading plugin "services"... Feb 17 09:15:23 volumio sudo[4060]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 09:15:23 volumio sudo[4060]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:15:23 volumio volumio[4027]: info: Loading plugin "alsa_controller"... Feb 17 09:15:23 volumio sudo[4058]: pam_unix(sudo:session): session closed for user root Feb 17 09:15:23 volumio sudo[4060]: pam_unix(sudo:session): session closed for user root Feb 17 09:15:23 volumio sudo[4071]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 09:15:23 volumio sudo[4071]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:15:23 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:15:23 volumio volumio[4027]: info: Loading plugin "wizard"... Feb 17 09:15:23 volumio volumio[4027]: info: Loading plugin "networkfs"... Feb 17 09:15:23 volumio volumio[4027]: info: Starting Udev Watcher for removable devices Feb 17 09:15:23 volumio volumio[4027]: info: Ignoring mount for partition: boot Feb 17 09:15:23 volumio volumio[4027]: info: Ignoring mount for partition: volumio Feb 17 09:15:23 volumio volumio[4027]: info: Ignoring mount for partition: volumio_data Feb 17 09:15:23 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:15:23 volumio volumio[4027]: info: Loading plugin "volumio_command_line_client"... Feb 17 09:15:23 volumio volumio[4027]: info: Loading plugin "upnp"... Feb 17 09:15:23 volumio volumio[4027]: info: [1771294523690] Starting Upmpd Daemon Feb 17 09:15:23 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:15:23 volumio volumio[4027]: info: Loading plugin "my_music"... Feb 17 09:15:23 volumio volumio[4027]: info: Loading plugin "mpd"... Feb 17 09:15:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Feb 17 09:15:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:23 volumio go-librespot[4091]: go-librespot daemon starting... Feb 17 09:15:23 volumio go-librespot[4092]: time="2026-02-17T09:15:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:15:23 volumio go-librespot[4092]: time="2026-02-17T09:15:23+07:00" level=debug msg="app state loaded" Feb 17 09:15:23 volumio go-librespot[4092]: time="2026-02-17T09:15:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:15:24 volumio volumio[4027]: info: Loading plugin "upnp_browser"... Feb 17 09:15:24 volumio go-librespot[4092]: time="2026-02-17T09:15:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:15:24 volumio go-librespot[4092]: time="2026-02-17T09:15:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:15:24 volumio go-librespot[4092]: time="2026-02-17T09:15:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:15:24 volumio go-librespot[4092]: time="2026-02-17T09:15:24+07:00" level=info msg="zeroconf server listening on port 35201" Feb 17 09:15:24 volumio go-librespot[4092]: time="2026-02-17T09:15:24+07:00" level=debug msg="obtained new client token: AADbaNAuCTijGNz+ymMIAezfES00V2f6emksnFtXe49Ux1mCERD9vpH+/JZuBkA46w48q/h7MJ3Un4wTWRwhhSEbjegLDPyIpZ4OhMp2OXFxxCizYt2VYUlLFwu/eeBMRdrQirPw5iQ6k7m3thlughUBloXJhTIklyk5STWrWHRqp4nD3SLPTurBtnlEaeSarFksOmPg58P4/gsKL6rFFI+zliVo84aBOgNCJPo4aF4BMg4sz8X+K200Qg==" Feb 17 09:15:24 volumio go-librespot[4092]: time="2026-02-17T09:15:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:15:24 volumio go-librespot[4092]: time="2026-02-17T09:15:24+07:00" level=debug msg="completed keyexchange" Feb 17 09:15:24 volumio go-librespot[4092]: time="2026-02-17T09:15:24+07:00" level=debug msg="completed challenge" Feb 17 09:15:24 volumio go-librespot[4092]: time="2026-02-17T09:15:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:15:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:15:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:15:26 volumio sudo[4071]: pam_unix(sudo:session): session closed for user root Feb 17 09:15:27 volumio volumio[4027]: info: Starting UPNP Browser Feb 17 09:15:27 volumio volumio[4027]: info: Loading plugin "alarm-clock"... Feb 17 09:15:27 volumio volumio[4027]: info: Loading plugin "airplay_emulation"... Feb 17 09:15:27 volumio volumio[4027]: info: Starting Shairport Sync Feb 17 09:15:27 volumio volumio[4027]: info: Loading plugin "last_100"... Feb 17 09:15:27 volumio volumio[4027]: info: Loading plugin "webradio"... Feb 17 09:15:27 volumio volumio[4027]: info: Loading plugin "i2s_dacs"... Feb 17 09:15:27 volumio volumio[4027]: info: Loading plugin "volumiodiscovery"... Feb 17 09:15:27 volumio volumio[4027]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 09:15:27 volumio volumio[4027]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:15:27 volumio node[4027]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 09:15:27 volumio volumio[4027]: *** WARNING *** For more information see Feb 17 09:15:27 volumio volumio[4027]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 09:15:27 volumio volumio[4027]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:15:27 volumio volumio[4027]: *** WARNING *** For more information see Feb 17 09:15:27 volumio node[4027]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:15:27 volumio node[4027]: *** WARNING *** For more information see Feb 17 09:15:27 volumio node[4027]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 09:15:27 volumio node[4027]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:15:27 volumio node[4027]: *** WARNING *** For more information see Feb 17 09:15:27 volumio volumio[4027]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 09:15:27 volumio volumio[4027]: info: Discovery: Started advertising with name: Volumio Feb 17 09:15:28 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:15:28 volumio volumio[4027]: info: Loading plugin "spop"... Feb 17 09:15:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Feb 17 09:15:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:28 volumio go-librespot[4103]: go-librespot daemon starting... Feb 17 09:15:28 volumio go-librespot[4104]: time="2026-02-17T09:15:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:15:28 volumio go-librespot[4104]: time="2026-02-17T09:15:28+07:00" level=debug msg="app state loaded" Feb 17 09:15:28 volumio go-librespot[4104]: time="2026-02-17T09:15:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:15:28 volumio go-librespot[4104]: time="2026-02-17T09:15:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:15:28 volumio go-librespot[4104]: time="2026-02-17T09:15:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:15:28 volumio go-librespot[4104]: time="2026-02-17T09:15:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:15:28 volumio go-librespot[4104]: time="2026-02-17T09:15:28+07:00" level=info msg="zeroconf server listening on port 45189" Feb 17 09:15:28 volumio go-librespot[4104]: time="2026-02-17T09:15:28+07:00" level=debug msg="obtained new client token: AAAfU000JftxZAhYGbkHmZvafi72uOY5F9v1DKwdLiur7c11+d4AsJQAakw/5NWDDrL6c7M5U3ptHRJcOxTACl90ms6cxFqqHqq0dO95DoQLX08BW3Cblnlok9D4omyREM3rdZZAmiCfPdEVq25kn0gzxFAWlgRip54m3kXO8N/UHCwjh1d9+ROb8Y4UOblOqYyCkuJL/6oBC/tnSm/kXaLw9mQub6+zKXF6sr/4dew4TFg6SGtFc6Fyog==" Feb 17 09:15:29 volumio go-librespot[4104]: time="2026-02-17T09:15:29+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 17 09:15:29 volumio go-librespot[4104]: time="2026-02-17T09:15:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 09:15:29 volumio go-librespot[4104]: time="2026-02-17T09:15:29+07:00" level=debug msg="completed keyexchange" Feb 17 09:15:29 volumio go-librespot[4104]: time="2026-02-17T09:15:29+07:00" level=debug msg="completed challenge" Feb 17 09:15:29 volumio go-librespot[4104]: time="2026-02-17T09:15:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:15:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:15:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:15:29 volumio volumio[4027]: info: Loading plugin "ytcr"... Feb 17 09:15:32 volumio volumio[4027]: info: Loading plugin "ytmusic"... Feb 17 09:15:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Feb 17 09:15:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:32 volumio go-librespot[4111]: go-librespot daemon starting... Feb 17 09:15:32 volumio go-librespot[4112]: time="2026-02-17T09:15:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:15:32 volumio go-librespot[4112]: time="2026-02-17T09:15:32+07:00" level=debug msg="app state loaded" Feb 17 09:15:32 volumio go-librespot[4112]: time="2026-02-17T09:15:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:15:33 volumio go-librespot[4112]: time="2026-02-17T09:15:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:15:33 volumio go-librespot[4112]: time="2026-02-17T09:15:33+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:15:33 volumio go-librespot[4112]: time="2026-02-17T09:15:33+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:15:33 volumio go-librespot[4112]: time="2026-02-17T09:15:33+07:00" level=info msg="zeroconf server listening on port 33099" Feb 17 09:15:33 volumio volumio-remote-updater[25144]: [2026-02-17 09:15:33] [connect] Successful connection Feb 17 09:15:33 volumio go-librespot[4112]: time="2026-02-17T09:15:33+07:00" level=debug msg="obtained new client token: AAAxL/dwtJSuJrot20GdOSG4d/qlrhKdPPQgMNm2p7vo+oSFChp2e6zemCA25yhoGPX+WlIqwVFtQ10CrtoIOS+fz7CnBQe3i2WgRdWMOlla+HolnwuGb/oYPLNmWuIDPKP0oPtJQ7S2ej0RprbRT1nuLegf6tdpXZjcanBTkAFB/I+Fu0ER18aZ3EBYzvLEyhh81+YcPrSbSp8TxxSe8mEVYmWnr3iDpCIPMmZtmBrAOfU8eNfbz6fUxA==" Feb 17 09:15:33 volumio volumio[4027]: info: Loading plugin "outputs"... Feb 17 09:15:33 volumio volumio[4027]: info: Loading plugin "albumart"... Feb 17 09:15:33 volumio volumio[4027]: info: Plugin example_plugin is not enabled Feb 17 09:15:33 volumio volumio[4027]: info: Loading plugin "inputs"... Feb 17 09:15:33 volumio volumio[4027]: info: Loading plugin "updater_comm"... Feb 17 09:15:33 volumio go-librespot[4112]: time="2026-02-17T09:15:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:15:33 volumio go-librespot[4112]: time="2026-02-17T09:15:33+07:00" level=debug msg="completed keyexchange" Feb 17 09:15:33 volumio go-librespot[4112]: time="2026-02-17T09:15:33+07:00" level=debug msg="completed challenge" Feb 17 09:15:33 volumio go-librespot[4112]: time="2026-02-17T09:15:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:15:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:15:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:15:33 volumio volumio[4027]: info: Plugin mpdemulation is not enabled Feb 17 09:15:33 volumio volumio[4027]: info: Loading plugin "rest_api"... Feb 17 09:15:33 volumio volumio[4027]: info: Loading plugin "websocket"... Feb 17 09:15:33 volumio volumio[4027]: info: Starting Socket.io Server version 1.7.4 Feb 17 09:15:33 volumio volumio[4027]: info: Loading plugin "RoonBridge"... Feb 17 09:15:34 volumio volumio[4027]: info: Applying required configuration parameters for plugin RoonBridge Feb 17 09:15:34 volumio volumio[4027]: info: Loading i18n strings for locale en Feb 17 09:15:34 volumio volumio[4027]: Updating browse sources language Feb 17 09:15:34 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:15:34 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:15:34 volumio volumio[4133]: Forking 3 albumart workers Feb 17 09:15:34 volumio volumio[4027]: info: CoreCommandRouter::initPlayerControls Feb 17 09:15:34 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:34 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:34 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:34 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:34 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:34 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:34 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:34 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:34 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:15:34 volumio volumio[4027]: Express server listening on port 3000 Feb 17 09:15:34 volumio volumio[4027]: [Metrics] WebUI: 15s 965.35ms Feb 17 09:15:34 volumio volumio[4027]: info: CoreStateMachine::resetVolumioState Feb 17 09:15:34 volumio volumio[4027]: info: CoreStateMachine::getcurrentVolume Feb 17 09:15:34 volumio volumio[4027]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:15:35 volumio sudo[4176]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 09:15:35 volumio sudo[4176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:15:35 volumio sudo[4176]: pam_unix(sudo:session): session closed for user root Feb 17 09:15:35 volumio sudo[4177]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 09:15:35 volumio sudo[4177]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:15:35 volumio sudo[4177]: pam_unix(sudo:session): session closed for user root Feb 17 09:15:35 volumio volumio[4027]: info: Volumio Network Manager: Network status updated: 1 Feb 17 09:15:35 volumio volumio[4027]: info: VolumeController:: Volume=100 Mute =false Feb 17 09:15:35 volumio volumio[4027]: info: CoreStateMachine::pushState Feb 17 09:15:35 volumio volumio[4027]: info: CorePlayQueue::getTrack 0 Feb 17 09:15:35 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 09:15:35 volumio volumio[4027]: info: CoreCommandRouter::volumioPushState Feb 17 09:15:35 volumio volumio[4027]: info: CoreStateMachine::updateTrackBlock Feb 17 09:15:35 volumio volumio[4027]: info: CorePlayQueue::getTrackBlock Feb 17 09:15:35 volumio volumio[4027]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:15:35 volumio volumio-remote-updater[25144]: [2026-02-17 09:15:35] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771294533 101 Feb 17 09:15:35 volumio volumio[4027]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 17 09:15:35 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:15:35 volumio volumio[4027]: info: Reloading queue from file Feb 17 09:15:35 volumio volumio[4027]: info: CoreStateMachine::setRepeat null single undefined Feb 17 09:15:35 volumio volumio[4027]: info: CoreStateMachine::pushState Feb 17 09:15:35 volumio volumio[4027]: info: CorePlayQueue::getTrack 0 Feb 17 09:15:35 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 09:15:35 volumio volumio[4027]: info: CoreCommandRouter::volumioPushState Feb 17 09:15:35 volumio volumio[4027]: info: CoreStateMachine::setRandom null Feb 17 09:15:35 volumio volumio[4027]: info: CoreStateMachine::pushState Feb 17 09:15:35 volumio volumio[4027]: info: CorePlayQueue::getTrack 0 Feb 17 09:15:35 volumio volumio[4027]: info: CoreCommandRouter::volumioPushState Feb 17 09:15:35 volumio volumio[4027]: info: Setting Device type: Raspberry PI Feb 17 09:15:35 volumio volumio[4027]: info: Completed loading Core Plugins Feb 17 09:15:35 volumio volumio[4027]: info: Preparing to generate the ALSA configuration file Feb 17 09:15:35 volumio volumio[4027]: info: VolumeController:: Volume=100 Mute =false Feb 17 09:15:35 volumio volumio[4027]: info: CoreStateMachine::pushState Feb 17 09:15:35 volumio volumio[4027]: info: CorePlayQueue::getTrack 0 Feb 17 09:15:35 volumio volumio[4027]: info: CoreCommandRouter::volumioPushState Feb 17 09:15:36 volumio volumio[4027]: info: Asound.conf file unchanged, so no further update is needed Feb 17 09:15:36 volumio volumio[4027]: info: Output device has changed, restarting MPD Feb 17 09:15:36 volumio volumio[4027]: info: Output device has changed, restarting Shairport Sync Feb 17 09:15:36 volumio sudo[4194]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 09:15:36 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:36 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:15:36 volumio sudo[4194]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:15:36 volumio volumio[4027]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:15:36 volumio sudo[4196]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 09:15:36 volumio volumio[4027]: info: ___________ START PLUGINS ___________ Feb 17 09:15:36 volumio sudo[4196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:15:36 volumio volumio[4027]: info: ControllerMpd::onStart: Initializing MPD Feb 17 09:15:36 volumio sudo[4198]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 09:15:36 volumio volumio[4027]: info: Creating MPD Configuration file Feb 17 09:15:36 volumio sudo[4198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:15:36 volumio sudo[4194]: pam_unix(sudo:session): session closed for user root Feb 17 09:15:36 volumio sudo[4196]: pam_unix(sudo:session): session closed for user root Feb 17 09:15:36 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:15:36 volumio volumio[4027]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:15:36 volumio volumio[4027]: info: [1771294536275] CoreMusicLibrary::Adding element Media Servers Feb 17 09:15:36 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:15:36 volumio sudo[4207]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 09:15:36 volumio sudo[4209]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 09:15:36 volumio sudo[4207]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:15:36 volumio sudo[4207]: pam_unix(sudo:session): session closed for user root Feb 17 09:15:36 volumio sudo[4209]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:15:36 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 09:15:36 volumio volumio[4027]: info: UPNP Browser: Client initialized successfully Feb 17 09:15:36 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:36 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:15:36 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 09:15:36 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 09:15:36 volumio systemd[1]: mpd.service: Consumed 7.116s CPU time. Feb 17 09:15:36 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 09:15:36 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 09:15:36 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 09:15:36 volumio volumio[4027]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:15:36 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:36 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:15:36 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 09:15:36 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 09:15:36 volumio volumio[4027]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:15:36 volumio volumio[4027]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:15:36 volumio volumio[4027]: info: [1771294536651] CoreMusicLibrary::Adding element Last_100 Feb 17 09:15:36 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:15:36 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 09:15:36 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 09:15:36 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 09:15:36 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 09:15:36 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 09:15:36 volumio volumio[4027]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:15:36 volumio volumio[4027]: info: [1771294536685] CoreMusicLibrary::Adding element Webradio Feb 17 09:15:36 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:15:36 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:15:36 volumio volumio[4027]: info: Initializing BBC Radios Feb 17 09:15:36 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 09:15:36 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 09:15:36 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:15:36 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:15:36 volumio volumio[4027]: info: Creating Spotify config file Feb 17 09:15:36 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Feb 17 09:15:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:37 volumio go-librespot[4237]: go-librespot daemon starting... Feb 17 09:15:37 volumio sudo[4227]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 09:15:37 volumio sudo[4227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 09:15:37 volumio sudo[4227]: pam_unix(sudo:session): session closed for user root Feb 17 09:15:37 volumio go-librespot[4238]: time="2026-02-17T09:15:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:15:37 volumio volumio[4144]: Starting albumart workers Feb 17 09:15:38 volumio go-librespot[4238]: time="2026-02-17T09:15:38+07:00" level=info msg="zeroconf server listening on port 44303" Feb 17 09:15:38 volumio volumio[4143]: Starting albumart workers Feb 17 09:15:38 volumio volumio[4027]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:15:38 volumio volumio[4027]: info: [1771294538205] CoreMusicLibrary::Adding element YouTube Music Feb 17 09:15:38 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:15:38 volumio volumio[4027]: Cannot find translation for source YouTube Music Feb 17 09:15:38 volumio volumio[4027]: info: Volumio Calling Home Feb 17 09:15:38 volumio volumio[4145]: Starting albumart workers Feb 17 09:15:38 volumio sudo[4248]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 09:15:38 volumio sudo[4248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:15:38 volumio sudo[4248]: pam_unix(sudo:session): session closed for user root Feb 17 09:15:39 volumio volumio[4027]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 09:15:39 volumio volumio[4027]: info: Discovery: Found device Volumio Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::volumioGetState Feb 17 09:15:39 volumio volumio[4027]: info: CorePlayQueue::getTrack 0 Feb 17 09:15:39 volumio volumio[4027]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 09:15:39 volumio volumio[4027]: info: Discovery: Found device Volumio Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::volumioGetState Feb 17 09:15:39 volumio volumio[4027]: info: CorePlayQueue::getTrack 0 Feb 17 09:15:39 volumio volumio[4027]: info: MPD Permissions set Feb 17 09:15:39 volumio volumio[4027]: info: MPD Permissions set Feb 17 09:15:39 volumio volumio[4027]: info: Upmpdcli Daemon Started Feb 17 09:15:39 volumio volumio[4027]: info: Spotify config file written Feb 17 09:15:39 volumio volumio[4027]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 17 09:15:39 volumio sudo[4255]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 09:15:39 volumio sudo[4255]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:39 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:15:39 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:15:39 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 17 09:15:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:39 volumio volumio[4027]: info: No need to fix Spotify hosts Feb 17 09:15:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:39 volumio go-librespot[4272]: go-librespot daemon starting... Feb 17 09:15:39 volumio sudo[4255]: pam_unix(sudo:session): session closed for user root Feb 17 09:15:40 volumio go-librespot[4273]: time="2026-02-17T09:15:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:15:40 volumio go-librespot[4273]: time="2026-02-17T09:15:40+07:00" level=debug msg="app state loaded" Feb 17 09:15:40 volumio go-librespot[4273]: time="2026-02-17T09:15:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:15:40 volumio go-librespot[4273]: time="2026-02-17T09:15: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 09:15:40 volumio go-librespot[4273]: time="2026-02-17T09:15:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 09:15:40 volumio go-librespot[4273]: time="2026-02-17T09:15:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 09:15:40 volumio go-librespot[4273]: time="2026-02-17T09:15:40+07:00" level=info msg="zeroconf server listening on port 33669" Feb 17 09:15:40 volumio volumio[4027]: info: Volumio called home Feb 17 09:15:40 volumio volumio[4027]: info: Starting Shairport Sync Feb 17 09:15:40 volumio volumio[4027]: info: Starting Shairport Sync Feb 17 09:15:40 volumio volumio[4027]: info: Starting Shairport Sync Feb 17 09:15:40 volumio sudo[4293]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:15:40 volumio sudo[4293]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:15:40 volumio sudo[4295]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:15:40 volumio sudo[4295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:15:40 volumio go-librespot[4273]: time="2026-02-17T09:15:40+07:00" level=debug msg="obtained new client token: AAA0YFpMQf2dZk6KW35LT6cPXnVx3+umR9xzXTSWR9Vyp3BeEaH1C9beEg2loto+rgzfr4tgdKVtqL/iBEC+Fk6toAWNrXU9p7QmI4Mz1YJ51dgcvg9k5AtgBktrB79k8aTA8dyKzMRurvZ8QtZiNWCI0AEOlwMnXPXS2U88DlosBS+UuBwOh7xiW0q478/daKEVW0sVxwCr7AH8f/wr05/l+HPv43wH9SZDK/1poDbMgoqT09K5do+RvQ==" Feb 17 09:15:40 volumio sudo[4298]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:15:41 volumio sudo[4298]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:15:41 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 09:15:41 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 09:15:41 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:15:41 volumio systemd[1]: shairport-sync.service: Consumed 2.491s CPU time. Feb 17 09:15:41 volumio go-librespot[4273]: time="2026-02-17T09:15:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:15:41 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:15:41 volumio sudo[4293]: pam_unix(sudo:session): session closed for user root Feb 17 09:15:41 volumio go-librespot[4273]: time="2026-02-17T09:15:41+07:00" level=debug msg="completed keyexchange" Feb 17 09:15:41 volumio sudo[4295]: pam_unix(sudo:session): session closed for user root Feb 17 09:15:41 volumio go-librespot[4273]: time="2026-02-17T09:15:41+07:00" level=debug msg="completed challenge" Feb 17 09:15:41 volumio volumio[4027]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 09:15:41 volumio volumio[4027]: SPOTIFY: BQD5DtwzxrIE2J9F3Y-bw9kODlic0c3YNxVj0nqfWwZe-Dexi6M5HSX0hjuhkprSwmBhKvtliB1PqEjnkTC8E0bsSTS-GgqP82lPphkiIt0ur6iwm_Zts8vM6TEhsBnxBcXtcGsr-HycVwmZSz_xd7NbfcrScDBgjA7w28fLImKIEQq3N3287zisslHSmCoRzVCqV8rWjI3WGBarQ8UfOhD39vegMA-cExMovkjr8bkk-kluF80h2BV9hrmgomWLodDs7287xOTsgX1cJfQONxEt4Zq85NelOfSFQ4iP9xmuFHxmvHm4_q44 Feb 17 09:15:41 volumio volumio[4027]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 09:15:41 volumio volumio[4027]: info: New Spotify access token = BQD5DtwzxrIE2J9F3Y-bw9kODlic0c3YNxVj0nqfWwZe-Dexi6M5HSX0hjuhkprSwmBhKvtliB1PqEjnkTC8E0bsSTS-GgqP82lPphkiIt0ur6iwm_Zts8vM6TEhsBnxBcXtcGsr-HycVwmZSz_xd7NbfcrScDBgjA7w28fLImKIEQq3N3287zisslHSmCoRzVCqV8rWjI3WGBarQ8UfOhD39vegMA-cExMovkjr8bkk-kluF80h2BV9hrmgomWLodDs7287xOTsgX1cJfQONxEt4Zq85NelOfSFQ4iP9xmuFHxmvHm4_q44 Feb 17 09:15:41 volumio volumio[4027]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 09:15:41 volumio volumio[4027]: info: Shairport-Sync Started Feb 17 09:15:41 volumio go-librespot[4273]: time="2026-02-17T09:15:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:15:41 volumio volumio[4027]: Error adding Membership: Error: addMembership EINVAL Feb 17 09:15:41 volumio volumio[4027]: info: Shairport-Sync Started Feb 17 09:15:41 volumio volumio[4027]: info: CoreCommandRouter::volumioGetState Feb 17 09:15:41 volumio volumio[4027]: info: CorePlayQueue::getTrack 0 Feb 17 09:15:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:15:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:15:41 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 09:15:41 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 09:15:41 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:15:41 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:15:41 volumio sudo[4298]: pam_unix(sudo:session): session closed for user root Feb 17 09:15:41 volumio volumio[4027]: info: Shairport-Sync Started Feb 17 09:15:41 volumio volumio[4027]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 17 09:15:41 volumio volumio[4027]: info: Spotify Successfully logged in Feb 17 09:15:41 volumio volumio[4027]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:15:41 volumio volumio[4027]: info: [1771294541676] CoreMusicLibrary::Adding element Spotify Feb 17 09:15:41 volumio volumio[4027]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:15:41 volumio volumio[4027]: Cannot find translation for source YouTube Music Feb 17 09:15:41 volumio volumio[4027]: Cannot find translation for source Spotify Feb 17 09:15:42 volumio volumio[4027]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 09:15:42 volumio volumio[4027]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:15:42 volumio volumio[4027]: info: VolumeController:: Volume=100 Mute =false Feb 17 09:15:42 volumio volumio[4027]: info: CoreCommandRouter::volumioGetState Feb 17 09:15:42 volumio volumio[4027]: info: CorePlayQueue::getTrack 0 Feb 17 09:15:42 volumio volumio[4027]: info: CoreStateMachine::pushState Feb 17 09:15:42 volumio volumio[4027]: info: CorePlayQueue::getTrack 0 Feb 17 09:15:42 volumio volumio[4027]: info: CoreCommandRouter::volumioPushState Feb 17 09:15:43 volumio volumio[4027]: info: go-librespot daemon successfully initialized Feb 17 09:15:44 volumio mpd[4245]: 2026-02-17T09:15:44 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 09:15:44 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 09:15:44 volumio sudo[4209]: pam_unix(sudo:session): session closed for user root Feb 17 09:15:44 volumio sudo[4198]: pam_unix(sudo:session): session closed for user root Feb 17 09:15:44 volumio volumio[4027]: error: MPD error: The expression evaluated to a falsy value: Feb 17 09:15:44 volumio volumio[4027]: assert.ok(self.idling) Feb 17 09:15:44 volumio volumio[4027]: error: The expression evaluated to a falsy value: Feb 17 09:15:44 volumio volumio[4027]: assert.ok(self.idling) Feb 17 09:15:44 volumio volumio[4027]: info: MPD running with PID4245 Feb 17 09:15:44 volumio volumio[4027]: ,establishing connection Feb 17 09:15:44 volumio volumio[4027]: error: updateQueue error: null Feb 17 09:15:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 17 09:15:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:44 volumio volumio[4027]: info: Completed starting Core Plugins Feb 17 09:15:44 volumio volumio[4027]: info: ------------------------------------------- Feb 17 09:15:44 volumio volumio[4027]: info: ----- MyVolumio plugins startup ---- Feb 17 09:15:44 volumio volumio[4027]: info: ------------------------------------------- Feb 17 09:15:44 volumio volumio[4027]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 09:15:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:44 volumio volumio[4027]: error: updateQueue error: null Feb 17 09:15:44 volumio go-librespot[4338]: go-librespot daemon starting... Feb 17 09:15:44 volumio go-librespot[4339]: time="2026-02-17T09:15:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:15:44 volumio go-librespot[4339]: time="2026-02-17T09:15:44+07:00" level=debug msg="app state loaded" Feb 17 09:15:44 volumio go-librespot[4339]: time="2026-02-17T09:15:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:15:45 volumio go-librespot[4339]: time="2026-02-17T09:15:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 09:15:45 volumio go-librespot[4339]: time="2026-02-17T09:15:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 09:15:45 volumio go-librespot[4339]: time="2026-02-17T09:15:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 09:15:45 volumio go-librespot[4339]: time="2026-02-17T09:15:45+07:00" level=info msg="zeroconf server listening on port 46245" Feb 17 09:15:45 volumio go-librespot[4339]: time="2026-02-17T09:15:45+07:00" level=debug msg="obtained new client token: AABP8kFkaG1fB8fzzI4A80KZHTdznCUJVDw1dfiHJI0rVM1Sx2aRO+yS3Evb6fF5ctNuc8EGRTIXFcQl9JwVmWKQyrXC4+SPb/uKZLfe+9dADyd+ybgz43bxNg38LKvg5XP7Nq1PagRK8n0wxZGfcFjkFbWbdqNpy6COP8/EO5HmW8jXuktfK4UfMxHrV36qOs6pKBATk7HtkQdFOlUY2AGk0EJs/11iYVLz5ty+ExokruuPEuKJkSX7Mg==" Feb 17 09:15:45 volumio go-librespot[4339]: time="2026-02-17T09:15:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:15:45 volumio go-librespot[4339]: time="2026-02-17T09:15:45+07:00" level=debug msg="completed keyexchange" Feb 17 09:15:45 volumio go-librespot[4339]: time="2026-02-17T09:15:45+07:00" level=debug msg="completed challenge" Feb 17 09:15:45 volumio go-librespot[4339]: time="2026-02-17T09:15:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:15:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:15:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:15:46 volumio volumio[4027]: info: Initializing connection to go-librespot Websocket Feb 17 09:15:46 volumio volumio[4027]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:15:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 17 09:15:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:48 volumio go-librespot[4346]: go-librespot daemon starting... Feb 17 09:15:48 volumio go-librespot[4347]: time="2026-02-17T09:15:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:15:48 volumio go-librespot[4347]: time="2026-02-17T09:15:48+07:00" level=debug msg="app state loaded" Feb 17 09:15:48 volumio go-librespot[4347]: time="2026-02-17T09:15:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:15:49 volumio volumio[4027]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 09:15:49 volumio go-librespot[4347]: time="2026-02-17T09:15:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:15:49 volumio go-librespot[4347]: time="2026-02-17T09:15:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:15:49 volumio go-librespot[4347]: time="2026-02-17T09:15:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:15:49 volumio go-librespot[4347]: time="2026-02-17T09:15:49+07:00" level=info msg="zeroconf server listening on port 34439" Feb 17 09:15:49 volumio go-librespot[4347]: time="2026-02-17T09:15:49+07:00" level=debug msg="obtained new client token: AADgKGf6CQY6VznTuR75oiECv5cEJii9Txq9aywzcNMZzggT9ofkKJz00C6ypVxewJdfYlGOre4pBad3RHZHgXNB2bvZwtmJh48kJz+PYzxdwrjer7T5qQ2YZELTnOLQ+DK8klQdEFb0zrBe5zjYyo+ihrMkAAb06Owsca4eCAgpw4wWzAXiqEjs12ieNLM8ChAeQqOMA7d4u1FAoukCztPIlrirO+cL6fjI2HPCcYbNFlLkHJgEtx0KBA==" Feb 17 09:15:49 volumio go-librespot[4347]: time="2026-02-17T09:15:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:15:49 volumio volumio[4027]: info: Initializing connection to go-librespot Websocket Feb 17 09:15:49 volumio go-librespot[4347]: time="2026-02-17T09:15:49+07:00" level=debug msg="new websocket client" Feb 17 09:15:49 volumio volumio[4027]: info: Connection to go-librespot Websocket established Feb 17 09:15:49 volumio go-librespot[4347]: time="2026-02-17T09:15:49+07:00" level=debug msg="completed keyexchange" Feb 17 09:15:49 volumio go-librespot[4347]: time="2026-02-17T09:15:49+07:00" level=debug msg="completed challenge" Feb 17 09:15:49 volumio go-librespot[4347]: time="2026-02-17T09:15: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 17 09:15:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:15:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:15:49 volumio volumio[4027]: info: Connection to go-librespot Websocket closed Feb 17 09:15:52 volumio volumio[4027]: info: Getting Spotify volume Feb 17 09:15:52 volumio volumio[4027]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:15:52 volumio volumio[4027]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:15:52 volumio volumio[4027]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 17 09:15:52 volumio volumio[4027]: errno: -111, Feb 17 09:15:52 volumio volumio[4027]: code: 'ECONNREFUSED', Feb 17 09:15:52 volumio volumio[4027]: syscall: 'connect', Feb 17 09:15:52 volumio volumio[4027]: address: '127.0.0.1', Feb 17 09:15:52 volumio volumio[4027]: port: 9879, Feb 17 09:15:52 volumio volumio[4027]: response: undefined Feb 17 09:15:52 volumio volumio[4027]: } Feb 17 09:15:52 volumio volumio[4027]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:15:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 17 09:15:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:15:53 volumio go-librespot[4369]: go-librespot daemon starting... Feb 17 09:15:53 volumio go-librespot[4371]: time="2026-02-17T09:15:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:15:53 volumio go-librespot[4371]: time="2026-02-17T09:15:53+07:00" level=debug msg="app state loaded" Feb 17 09:15:53 volumio go-librespot[4371]: time="2026-02-17T09:15:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:15:53 volumio go-librespot[4371]: time="2026-02-17T09:15: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:15:53 volumio go-librespot[4371]: time="2026-02-17T09:15:53+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:15:53 volumio go-librespot[4371]: time="2026-02-17T09:15:53+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:15:53 volumio go-librespot[4371]: time="2026-02-17T09:15:53+07:00" level=info msg="zeroconf server listening on port 40783" Feb 17 09:15:53 volumio go-librespot[4371]: time="2026-02-17T09:15:53+07:00" level=debug msg="obtained new client token: AAArF2562pNcUjg7QRlwMXfGi03pM5j3PU0qkVTus8VYjYpkMjE14667+d//1HxvOL9CGhWpzN8Mg9VcrNsq0s75SdRLSrUCtdrN+IBY0ga45PxjioCGmTM7iV4Cvw252DNtjV6RtNFr25CctX4ZCOAWJ9/zTHQH9282rWpc82gT6tJxMu/8w28YPAhstnKRCfwVp9t/4vx/wOejdBOTU9k7ANkMYZQRHMpdll+f7v7jttlo3pqLWch3NA==" Feb 17 09:15:54 volumio go-librespot[4371]: time="2026-02-17T09:15:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:15:54 volumio go-librespot[4371]: time="2026-02-17T09:15:54+07:00" level=debug msg="completed keyexchange" Feb 17 09:15:54 volumio go-librespot[4371]: time="2026-02-17T09:15:54+07:00" level=debug msg="completed challenge" Feb 17 09:15:54 volumio go-librespot[4371]: time="2026-02-17T09:15:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:15:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:15:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:15:54 volumio sudo[4394]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 09:14' Feb 17 09:15:54 volumio sudo[4394]: 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"