Feb 21 15:45:00 volumiostu volumio[1847]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 15:45:00 volumiostu volumio[1847]: info: [1771688700368] CoreMusicLibrary::Adding element Radio Paradise Feb 21 15:45:00 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:45:00 volumiostu volumio[1847]: Cannot find translation for source Radio Paradise Feb 21 15:45:00 volumiostu volumio[1847]: info: Volumio Calling Home Feb 21 15:45:00 volumiostu go-librespot[2024]: time="2026-02-21T15:45:00Z" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Feb 21 15:45:00 volumiostu go-librespot[2024]: time="2026-02-21T15:45:00Z" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 21 15:45:00 volumiostu go-librespot[2024]: time="2026-02-21T15:45:00Z" level=debug msg="completed keyexchange" Feb 21 15:45:00 volumiostu go-librespot[2024]: time="2026-02-21T15:45:00Z" level=debug msg="completed challenge" Feb 21 15:45:00 volumiostu go-librespot[2024]: time="2026-02-21T15:45:00Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:00 volumiostu volumio[1937]: Starting albumart workers Feb 21 15:45:01 volumiostu go-librespot[2024]: time="2026-02-21T15:45:01Z" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 21 15:45:01 volumiostu go-librespot[2024]: time="2026-02-21T15:45:01Z" level=debug msg="completed keyexchange" Feb 21 15:45:01 volumiostu go-librespot[2024]: time="2026-02-21T15:45:01Z" level=debug msg="completed challenge" Feb 21 15:45:01 volumiostu sudo[2069]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:01 volumiostu sudo[2067]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:01 volumiostu sudo[2067]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 21 15:45:01 volumiostu sudo[2067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:01 volumiostu volumio[1847]: info: MPD Permissions set Feb 21 15:45:01 volumiostu volumio[1847]: info: Completed starting Core Plugins Feb 21 15:45:01 volumiostu volumio[1847]: info: ------------------------------------------- Feb 21 15:45:01 volumiostu volumio[1847]: info: ----- MyVolumio plugins startup ---- Feb 21 15:45:01 volumiostu volumio[1847]: info: ------------------------------------------- Feb 21 15:45:01 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 21 15:45:01 volumiostu volumio[1847]: info: MPD Permissions set Feb 21 15:45:01 volumiostu sudo[2069]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 15:45:01 volumiostu sudo[2069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:01 volumiostu sudo[2067]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:01 volumiostu sudo[2069]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:01 volumiostu go-librespot[2024]: time="2026-02-21T15:45:01Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:01 volumiostu volumio[1847]: info: Volumio called home Feb 21 15:45:01 volumiostu volumio[1847]: info: Spotify config file written Feb 21 15:45:01 volumiostu sudo[2075]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:01 volumiostu sudo[2075]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 21 15:45:01 volumiostu sudo[2075]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:02 volumiostu systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 21 15:45:02 volumiostu systemd[1]: go-librespot-daemon.service: Killing process 2027 (go-librespot) with signal SIGKILL. Feb 21 15:45:02 volumiostu systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 21 15:45:02 volumiostu systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:45:02 volumiostu systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:45:02 volumiostu go-librespot[2077]: go-librespot daemon starting... Feb 21 15:45:02 volumiostu sudo[2075]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:02 volumiostu go-librespot[2078]: time="2026-02-21T15:45:02Z" level=info msg="running go-librespot 0.6.2" Feb 21 15:45:02 volumiostu go-librespot[2078]: time="2026-02-21T15:45:02Z" level=debug msg="app state loaded" Feb 21 15:45:02 volumiostu go-librespot[2078]: time="2026-02-21T15:45:02Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 15:45:02 volumiostu volumio[1847]: error: MPD error: The expression evaluated to a falsy value: Feb 21 15:45:02 volumiostu volumio[1847]: assert.ok(self.idling) Feb 21 15:45:02 volumiostu volumio[1847]: error: The expression evaluated to a falsy value: Feb 21 15:45:02 volumiostu volumio[1847]: assert.ok(self.idling) Feb 21 15:45:02 volumiostu go-librespot[2078]: time="2026-02-21T15:45:02Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 21 15:45:02 volumiostu go-librespot[2078]: time="2026-02-21T15:45:02Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 21 15:45:02 volumiostu go-librespot[2078]: time="2026-02-21T15:45:02Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 21 15:45:02 volumiostu go-librespot[2078]: time="2026-02-21T15:45:02Z" level=info msg="zeroconf server listening on port 40493" Feb 21 15:45:02 volumiostu go-librespot[2078]: time="2026-02-21T15:45:02Z" level=debug msg="obtained new client token: AABHvjIFbtJfzPQZ4oZmJAmqVE+PwGlyj4jQrGSRBX0rwgHU9f72v9TLzj6wJg18qxwCGhBSIP0PK76+YdYDw1mps6Opu2h0EcNE+iz+pTg2C4Xg/KGUmcc/+M72gLykboSFN6Vhkeg++wPDNm9XNhzAgb234BaxepfXjAzxtVZiEKnhlMwY0P3TjTwzjI8gq5dGzXkmNqkFz1QO/HPIAYfBF1dsP0BNZ5+fCopn/A8F3LyRnZudIchI" Feb 21 15:45:02 volumiostu go-librespot[2078]: time="2026-02-21T15:45:02Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:45:02 volumiostu volumio[1847]: 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 21 15:45:02 volumiostu volumio[1847]: info: MPD running with PID2033 Feb 21 15:45:02 volumiostu volumio[1847]: ,establishing connection Feb 21 15:45:02 volumiostu go-librespot[2078]: time="2026-02-21T15:45:02Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:55642->104.199.65.9:4070: read: connection reset by peer" Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:02 volumiostu volumio[1847]: info: No need to fix Spotify hosts Feb 21 15:45:02 volumiostu volumio[1847]: error: updateQueue error: null Feb 21 15:45:02 volumiostu go-librespot[2078]: time="2026-02-21T15:45:02Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 21 15:45:03 volumiostu go-librespot[2078]: time="2026-02-21T15:45:03Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:59134->104.199.65.9:443: read: connection reset by peer" Feb 21 15:45:03 volumiostu volumio[1847]: info: New Spotify access tokenBQAauLsrB0... Feb 21 15:45:03 volumiostu volumio[1847]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 21 15:45:03 volumiostu volumio[1847]: error: updateQueue error: null Feb 21 15:45:03 volumiostu volumio[1847]: info: Starting Shairport Sync Feb 21 15:45:03 volumiostu volumio[1847]: info: Starting Shairport Sync Feb 21 15:45:03 volumiostu volumio[1847]: info: Starting Shairport Sync Feb 21 15:45:03 volumiostu sudo[2105]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:03 volumiostu sudo[2105]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 15:45:03 volumiostu sudo[2105]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:03 volumiostu systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 21 15:45:03 volumiostu systemd[1]: shairport-sync.service: Deactivated successfully. Feb 21 15:45:03 volumiostu systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 15:45:03 volumiostu systemd[1]: shairport-sync.service: Consumed 1.532s CPU time. Feb 21 15:45:03 volumiostu sudo[2107]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:03 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:03 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:03 volumiostu systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 15:45:03 volumiostu sudo[2105]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:03 volumiostu sudo[2109]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:03 volumiostu volumio[1847]: info: Shairport-Sync Started Feb 21 15:45:03 volumiostu sudo[2109]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 15:45:03 volumiostu sudo[2109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:03 volumiostu volumio[1847]: Error adding Membership: Error: addMembership EINVAL Feb 21 15:45:03 volumiostu sudo[2107]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 15:45:03 volumiostu sudo[2107]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:03 volumiostu systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 21 15:45:03 volumiostu sudo[2111]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:03 volumiostu systemd[1]: shairport-sync.service: Deactivated successfully. Feb 21 15:45:03 volumiostu systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 15:45:03 volumiostu systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 15:45:03 volumiostu volumio[1847]: SPOTIFY: User informations: {"country":"BD","display_name":"Maruf","email":"sclements@brainleaked.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/317bbenxuzjt6r76dfjeh6lz7uwi"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/317bbenxuzjt6r76dfjeh6lz7uwi","id":"317bbenxuzjt6r76dfjeh6lz7uwi","images":[],"product":"premium","type":"user","uri":"spotify:user:317bbenxuzjt6r76dfjeh6lz7uwi"} Feb 21 15:45:03 volumiostu volumio[1847]: info: Spotify Successfully logged in Feb 21 15:45:03 volumiostu volumio[1847]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 15:45:03 volumiostu volumio[1847]: info: [1771688703420] CoreMusicLibrary::Adding element Spotify Feb 21 15:45:03 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:45:03 volumiostu volumio[1847]: Cannot find translation for source Radio Paradise Feb 21 15:45:03 volumiostu sudo[2109]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:03 volumiostu sudo[2111]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 21 15:45:03 volumiostu sudo[2111]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:03 volumiostu systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 21 15:45:03 volumiostu systemd[1]: shairport-sync.service: Deactivated successfully. Feb 21 15:45:03 volumiostu systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 15:45:03 volumiostu volumio-remote-updater[740]: [2026-02-21 15:45:03] [connect] Successful connection Feb 21 15:45:03 volumiostu systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 15:45:03 volumiostu volumio[1847]: Cannot find translation for source Spotify Feb 21 15:45:03 volumiostu go-librespot[2078]: time="2026-02-21T15:45:03Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 21 15:45:03 volumiostu sudo[2107]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:03 volumiostu go-librespot[2078]: time="2026-02-21T15:45:03Z" level=debug msg="completed keyexchange" Feb 21 15:45:03 volumiostu go-librespot[2078]: time="2026-02-21T15:45:03Z" level=debug msg="completed challenge" Feb 21 15:45:03 volumiostu sudo[2111]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:03 volumiostu go-librespot[2078]: time="2026-02-21T15:45:03Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:03 volumiostu volumio[1847]: info: Upmpdcli Daemon Started Feb 21 15:45:03 volumiostu volumio[1847]: info: Shairport-Sync Started Feb 21 15:45:03 volumiostu volumio[1847]: info: Shairport-Sync Started Feb 21 15:45:03 volumiostu volumio-remote-updater[740]: [2026-02-21 15:45:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771688703 101 Feb 21 15:45:03 volumiostu volumio[1847]: 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: 4 Feb 21 15:45:04 volumiostu go-librespot[2078]: time="2026-02-21T15:45:04Z" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 15:45:04 volumiostu go-librespot[2078]: time="2026-02-21T15:45:04Z" level=debug msg="completed keyexchange" Feb 21 15:45:04 volumiostu go-librespot[2078]: time="2026-02-21T15:45:04Z" level=debug msg="completed challenge" Feb 21 15:45:04 volumiostu go-librespot[2078]: time="2026-02-21T15:45:04Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:04 volumiostu go-librespot[2078]: time="2026-02-21T15:45:04Z" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Feb 21 15:45:05 volumiostu go-librespot[2078]: time="2026-02-21T15:45:05Z" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 21 15:45:05 volumiostu go-librespot[2078]: time="2026-02-21T15:45:05Z" level=debug msg="completed keyexchange" Feb 21 15:45:05 volumiostu go-librespot[2078]: time="2026-02-21T15:45:05Z" level=debug msg="completed challenge" Feb 21 15:45:05 volumiostu go-librespot[2078]: time="2026-02-21T15:45:05Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:06 volumiostu volumio[1847]: info: go-librespot daemon successfully initialized Feb 21 15:45:06 volumiostu go-librespot[2078]: time="2026-02-21T15:45:06Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:45:06 volumiostu go-librespot[2078]: time="2026-02-21T15:45:06Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:40802->104.199.65.9:4070: read: connection reset by peer" Feb 21 15:45:06 volumiostu go-librespot[2078]: time="2026-02-21T15:45:06Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:40802->104.199.65.9:4070: read: connection reset by peer" Feb 21 15:45:06 volumiostu systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:45:06 volumiostu systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 15:45:09 volumiostu volumio[1847]: info: Initializing connection to go-librespot Websocket Feb 21 15:45:09 volumiostu volumio[1847]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 15:45:09 volumiostu systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 21 15:45:09 volumiostu systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:45:09 volumiostu systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:45:09 volumiostu go-librespot[2153]: go-librespot daemon starting... Feb 21 15:45:09 volumiostu go-librespot[2154]: time="2026-02-21T15:45:09Z" level=info msg="running go-librespot 0.6.2" Feb 21 15:45:09 volumiostu go-librespot[2154]: time="2026-02-21T15:45:09Z" level=debug msg="app state loaded" Feb 21 15:45:09 volumiostu go-librespot[2154]: time="2026-02-21T15:45:09Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 15:45:09 volumiostu go-librespot[2154]: time="2026-02-21T15:45:09Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 21 15:45:09 volumiostu go-librespot[2154]: time="2026-02-21T15:45:09Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 21 15:45:09 volumiostu go-librespot[2154]: time="2026-02-21T15:45:09Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 21 15:45:09 volumiostu go-librespot[2154]: time="2026-02-21T15:45:09Z" level=info msg="zeroconf server listening on port 33491" Feb 21 15:45:09 volumiostu go-librespot[2154]: time="2026-02-21T15:45:09Z" level=debug msg="obtained new client token: AADbX4P2cdRy4TqtJrzvbLNDmUwkq6yhexdS9noahl1I2X9RNw7Mqb8Ad0FZrbT58Ij7Yn53+wssUMgwDFYvIQ7rV2hcYST1fFKzZJmnKt4EymfrAZ6R94Wo+V8b4el0/sVGDQKCp7OYbGpvvuG2daSpuEhRxJfaUNS5R7xpA3Z0TCApFW6gpr7Arj5JfHETqio3jzhwbF7wKsVfw3+iVPmOUVdKHRrrFpP0jBFvTiv7UeoyIqs0csaN" Feb 21 15:45:09 volumiostu go-librespot[2154]: time="2026-02-21T15:45:09Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:45:09 volumiostu sudo[2164]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:09 volumiostu sudo[2164]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 21 15:45:09 volumiostu sudo[2164]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:09 volumiostu go-librespot[2154]: time="2026-02-21T15:45:09Z" level=debug msg="completed keyexchange" Feb 21 15:45:09 volumiostu go-librespot[2154]: time="2026-02-21T15:45:09Z" level=debug msg="completed challenge" Feb 21 15:45:09 volumiostu go-librespot[2154]: time="2026-02-21T15:45:09Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:09 volumiostu sudo[2164]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:09 volumiostu sudo[2166]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:09 volumiostu sudo[2166]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 15:45:09 volumiostu sudo[2166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:09 volumiostu sudo[2166]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:09 volumiostu volumio[1847]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.169 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/145.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Feb 21 15:45:10 volumiostu go-librespot[2154]: time="2026-02-21T15:45:10Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Feb 21 15:45:10 volumiostu go-librespot[2154]: time="2026-02-21T15:45:10Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 21 15:45:10 volumiostu go-librespot[2154]: time="2026-02-21T15:45:10Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:53942->104.199.65.9:80: read: connection reset by peer" Feb 21 15:45:10 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 21 15:45:10 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetVisibleSources Feb 21 15:45:10 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:45:10 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:10 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:10 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 21 15:45:10 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 21 15:45:10 volumiostu volumio[1847]: info: Received Get System Info Feb 21 15:45:10 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:45:10 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:45:10 volumiostu volumio[1847]: info: Discovery: Getting this device information Feb 21 15:45:10 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:10 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:10 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:45:10 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:10 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:10 volumiostu volumio[1847]: info: Listing playlists Feb 21 15:45:10 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 21 15:45:10 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 21 15:45:11 volumiostu sudo[2189]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:11 volumiostu go-librespot[2154]: time="2026-02-21T15:45:11Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 21 15:45:11 volumiostu sudo[2189]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 21 15:45:11 volumiostu sudo[2189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:11 volumiostu sudo[2189]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:11 volumiostu sudo[2193]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:11 volumiostu sudo[2193]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 15:45:11 volumiostu sudo[2193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:11 volumiostu sudo[2193]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:11 volumiostu go-librespot[2154]: time="2026-02-21T15:45:11Z" level=debug msg="completed keyexchange" Feb 21 15:45:11 volumiostu go-librespot[2154]: time="2026-02-21T15:45:11Z" level=debug msg="completed challenge" Feb 21 15:45:11 volumiostu volumio[1847]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.169 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/145.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Feb 21 15:45:11 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 21 15:45:11 volumiostu go-librespot[2154]: time="2026-02-21T15:45:11Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:11 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetVisibleSources Feb 21 15:45:11 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:45:11 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:11 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:11 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 21 15:45:11 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 21 15:45:11 volumiostu volumio[1847]: info: Received Get System Info Feb 21 15:45:11 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:45:11 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:45:11 volumiostu volumio[1847]: info: Discovery: Getting this device information Feb 21 15:45:11 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:11 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:11 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:45:11 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:11 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:11 volumiostu volumio[1847]: info: Listing playlists Feb 21 15:45:11 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 21 15:45:11 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 21 15:45:11 volumiostu go-librespot[2154]: time="2026-02-21T15:45:11Z" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 21 15:45:11 volumiostu go-librespot[2154]: time="2026-02-21T15:45:11Z" level=debug msg="completed keyexchange" Feb 21 15:45:11 volumiostu go-librespot[2154]: time="2026-02-21T15:45:11Z" level=debug msg="completed challenge" Feb 21 15:45:11 volumiostu go-librespot[2154]: time="2026-02-21T15:45:11Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 21 15:45:11 volumiostu volumio[1847]: info: Adding plugin bluetooth to MyMusic Plugins Feb 21 15:45:11 volumiostu volumio[1847]: info: Adding plugin multiroom to MyMusic Plugins Feb 21 15:45:11 volumiostu volumio[1847]: info: Adding plugin metavolumio to MyMusic Plugins Feb 21 15:45:11 volumiostu volumio[1847]: info: Adding plugin cd_controller to MyMusic Plugins Feb 21 15:45:11 volumiostu volumio[1847]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 21 15:45:11 volumiostu volumio[1847]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 21 15:45:11 volumiostu volumio[1847]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 21 15:45:11 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 21 15:45:12 volumiostu go-librespot[2154]: time="2026-02-21T15:45:12Z" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 21 15:45:12 volumiostu go-librespot[2154]: time="2026-02-21T15:45:12Z" level=debug msg="completed keyexchange" Feb 21 15:45:12 volumiostu go-librespot[2154]: time="2026-02-21T15:45:12Z" level=debug msg="completed challenge" Feb 21 15:45:13 volumiostu go-librespot[2154]: time="2026-02-21T15:45:13Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:13 volumiostu go-librespot[2154]: time="2026-02-21T15:45:13Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:45:13 volumiostu go-librespot[2154]: time="2026-02-21T15:45:13Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 21 15:45:13 volumiostu go-librespot[2154]: time="2026-02-21T15:45:13Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 21 15:45:13 volumiostu systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:45:13 volumiostu systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 15:45:16 volumiostu volumio[1847]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 21 15:45:16 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 21 15:45:16 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:16 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:16 volumiostu volumio[1847]: info: Starting MyVolumio Remote Streaming Endpoints Feb 21 15:45:16 volumiostu systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 21 15:45:16 volumiostu systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:45:16 volumiostu volumio[1847]: info: MyVolumio login type: Token Feb 21 15:45:16 volumiostu systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:45:16 volumiostu go-librespot[2196]: go-librespot daemon starting... Feb 21 15:45:16 volumiostu go-librespot[2197]: time="2026-02-21T15:45:16Z" level=info msg="running go-librespot 0.6.2" Feb 21 15:45:16 volumiostu go-librespot[2197]: time="2026-02-21T15:45:16Z" level=debug msg="app state loaded" Feb 21 15:45:17 volumiostu go-librespot[2197]: time="2026-02-21T15:45:17Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 15:45:17 volumiostu volumio[1847]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 21 15:45:17 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 21 15:45:17 volumiostu go-librespot[2197]: time="2026-02-21T15:45:17Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 15:45:17 volumiostu go-librespot[2197]: time="2026-02-21T15:45:17Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 15:45:17 volumiostu go-librespot[2197]: time="2026-02-21T15:45:17Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 15:45:17 volumiostu go-librespot[2197]: time="2026-02-21T15:45:17Z" level=info msg="zeroconf server listening on port 46635" Feb 21 15:45:17 volumiostu go-librespot[2197]: time="2026-02-21T15:45:17Z" level=debug msg="obtained new client token: AAAcgntyVEBFG/iaTKzSjYxj06RE9xYFQ4V9Gx/oPXUTG7TWu28HC5IbXJtQDHxTTEzgiHbQ2kQ/DyI6dpDX7WxOpZDn48DqfnYBvhDdwfyxR67xJ5PCHFOz8CkNmphwl5icsIV1MXGRJ82+ekdtnhVR5ecV12SoYNf4zr26oEt0Oa9McYtqmonrHAscDhbiQkPivitbrW/UVvSewY8Q9jsWk6wKKFxVFQMWTIFxZgJUxy5lsruDJxqz" Feb 21 15:45:17 volumiostu go-librespot[2197]: time="2026-02-21T15:45:17Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:45:17 volumiostu go-librespot[2197]: time="2026-02-21T15:45:17Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:48396->104.199.65.9:4070: read: connection reset by peer" Feb 21 15:45:17 volumiostu go-librespot[2197]: time="2026-02-21T15:45:17Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Feb 21 15:45:17 volumiostu go-librespot[2197]: time="2026-02-21T15:45:17Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 21 15:45:17 volumiostu go-librespot[2197]: time="2026-02-21T15:45:17Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:53178->104.199.65.9:80: read: connection reset by peer" Feb 21 15:45:18 volumiostu go-librespot[2197]: time="2026-02-21T15:45:18Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 21 15:45:18 volumiostu go-librespot[2197]: time="2026-02-21T15:45:18Z" level=debug msg="completed keyexchange" Feb 21 15:45:18 volumiostu go-librespot[2197]: time="2026-02-21T15:45:18Z" level=debug msg="completed challenge" Feb 21 15:45:18 volumiostu go-librespot[2197]: time="2026-02-21T15:45:18Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:19 volumiostu go-librespot[2197]: time="2026-02-21T15:45:19Z" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 21 15:45:19 volumiostu go-librespot[2197]: time="2026-02-21T15:45:19Z" level=debug msg="completed keyexchange" Feb 21 15:45:19 volumiostu go-librespot[2197]: time="2026-02-21T15:45:19Z" level=debug msg="completed challenge" Feb 21 15:45:19 volumiostu go-librespot[2197]: time="2026-02-21T15:45:19Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:20 volumiostu go-librespot[2197]: time="2026-02-21T15:45:20Z" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.1.133:80: connect: connection refused" Feb 21 15:45:20 volumiostu go-librespot[2197]: time="2026-02-21T15:45:20Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Feb 21 15:45:20 volumiostu go-librespot[2197]: time="2026-02-21T15:45:20Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 21 15:45:20 volumiostu go-librespot[2197]: time="2026-02-21T15:45:20Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:59816->104.199.65.9:443: read: connection reset by peer" Feb 21 15:45:20 volumiostu go-librespot[2197]: time="2026-02-21T15:45:20Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 21 15:45:20 volumiostu go-librespot[2197]: time="2026-02-21T15:45:20Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 21 15:45:20 volumiostu go-librespot[2197]: time="2026-02-21T15:45:20Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 21 15:45:20 volumiostu systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:45:20 volumiostu systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 15:45:21 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 21 15:45:21 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 21 15:45:21 volumiostu volumio[1847]: info: Streaming services startup Feb 21 15:45:21 volumiostu volumio[1847]: info: Starting Streaming Daemon Feb 21 15:45:21 volumiostu volumio[1847]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 21 15:45:21 volumiostu sudo[2221]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:21 volumiostu sudo[2221]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 21 15:45:21 volumiostu sudo[2221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:21 volumiostu volumio[1847]: info: Initializing connection to go-librespot Websocket Feb 21 15:45:21 volumiostu sudo[2221]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:21 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:21 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:21 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 21 15:45:21 volumiostu volumio[1847]: info: Received Get System Info Feb 21 15:45:21 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:45:21 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:45:21 volumiostu volumio[1847]: info: Discovery: Getting this device information Feb 21 15:45:21 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:21 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:21 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:45:21 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Feb 21 15:45:21 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 21 15:45:21 volumiostu volumio[1847]: info: Received Get System Info Feb 21 15:45:21 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:45:21 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:45:21 volumiostu volumio[1847]: info: Discovery: Getting this device information Feb 21 15:45:21 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:21 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:21 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:45:22 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 21 15:45:22 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Feb 21 15:45:22 volumiostu volumio[1847]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 15:45:22 volumiostu volumio[1847]: error: Cannot start Volumio Streaming Daemon Feb 21 15:45:22 volumiostu volumio[1847]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 21 15:45:22 volumiostu volumio[1847]: sudo: unable to resolve host volumiostu: System error Feb 21 15:45:22 volumiostu volumio[1847]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 21 15:45:23 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Feb 21 15:45:23 volumiostu volumio[1847]: info: MyVolumio login type: Token Feb 21 15:45:23 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 21 15:45:23 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Feb 21 15:45:23 volumiostu volumio[1847]: info: MyVolumio login type: Token Feb 21 15:45:23 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 21 15:45:23 volumiostu systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 21 15:45:23 volumiostu systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:45:23 volumiostu systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:45:23 volumiostu go-librespot[2227]: go-librespot daemon starting... Feb 21 15:45:23 volumiostu go-librespot[2228]: time="2026-02-21T15:45:23Z" level=info msg="running go-librespot 0.6.2" Feb 21 15:45:23 volumiostu go-librespot[2228]: time="2026-02-21T15:45:23Z" level=debug msg="app state loaded" Feb 21 15:45:23 volumiostu go-librespot[2228]: time="2026-02-21T15:45:23Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 15:45:24 volumiostu volumio[1847]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 21 15:45:24 volumiostu go-librespot[2228]: time="2026-02-21T15:45:24Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 21 15:45:24 volumiostu go-librespot[2228]: time="2026-02-21T15:45:24Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 21 15:45:24 volumiostu go-librespot[2228]: time="2026-02-21T15:45:24Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 21 15:45:24 volumiostu go-librespot[2228]: time="2026-02-21T15:45:24Z" level=info msg="zeroconf server listening on port 42365" Feb 21 15:45:24 volumiostu go-librespot[2228]: time="2026-02-21T15:45:24Z" level=debug msg="obtained new client token: AACMlavL6bOvibvynbNaXhmUbBu3XvtdOnFvgq4fOUu9H/kKQ5Vdm16n7vn74VAJ8/yKV9TUyMrftmURL5z3lCL37Lq5jsW3iG+QPZAgB8Xvb51hhdkDw8OKnS0Y41hkePw4BqqQcn/Csa+7HfAHBh/Q3H1XK4o6YvXtxRBJC2jN34jEg6g0nCgXjgZzTYeWnx/foK5Aj+8diAAHZQUy8E168FSB+R97/TgA9ayIXVySFz235mkvlw==" Feb 21 15:45:24 volumiostu go-librespot[2228]: time="2026-02-21T15:45:24Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:45:24 volumiostu go-librespot[2228]: time="2026-02-21T15:45:24Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:48418->104.199.65.9:4070: read: connection reset by peer" Feb 21 15:45:24 volumiostu go-librespot[2228]: time="2026-02-21T15:45:24Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 21 15:45:24 volumiostu go-librespot[2228]: time="2026-02-21T15:45:24Z" level=debug msg="completed keyexchange" Feb 21 15:45:24 volumiostu go-librespot[2228]: time="2026-02-21T15:45:24Z" level=debug msg="completed challenge" Feb 21 15:45:24 volumiostu go-librespot[2228]: time="2026-02-21T15:45:24Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:25 volumiostu go-librespot[2228]: time="2026-02-21T15:45:25Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 21 15:45:25 volumiostu go-librespot[2228]: time="2026-02-21T15:45:25Z" level=debug msg="completed keyexchange" Feb 21 15:45:25 volumiostu go-librespot[2228]: time="2026-02-21T15:45:25Z" level=debug msg="completed challenge" Feb 21 15:45:25 volumiostu go-librespot[2228]: time="2026-02-21T15:45:25Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:25 volumiostu volumio[1847]: info: Initializing connection to go-librespot Websocket Feb 21 15:45:25 volumiostu go-librespot[2228]: time="2026-02-21T15:45:25Z" level=debug msg="new websocket client" Feb 21 15:45:25 volumiostu volumio[1847]: info: Connection to go-librespot Websocket established Feb 21 15:45:25 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 21 15:45:25 volumiostu volumio[1847]: info: Received Get System Info Feb 21 15:45:25 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:45:25 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:45:25 volumiostu volumio[1847]: info: Discovery: Getting this device information Feb 21 15:45:25 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:25 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:25 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:45:25 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 21 15:45:25 volumiostu volumio[1847]: info: Received Get System Info Feb 21 15:45:25 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:45:25 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:45:25 volumiostu volumio[1847]: info: Discovery: Getting this device information Feb 21 15:45:25 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:25 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:25 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:45:25 volumiostu volumio[1847]: info: MyVolumio token set successfully Feb 21 15:45:25 volumiostu volumio[1847]: info: MYVOLUMIO: Adding device Feb 21 15:45:25 volumiostu volumio[1847]: info: MYVOLUMIO: Evaluating Server Feb 21 15:45:26 volumiostu go-librespot[2228]: time="2026-02-21T15:45:26Z" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 15:45:26 volumiostu go-librespot[2228]: time="2026-02-21T15:45:26Z" level=debug msg="completed keyexchange" Feb 21 15:45:26 volumiostu go-librespot[2228]: time="2026-02-21T15:45:26Z" level=debug msg="completed challenge" Feb 21 15:45:26 volumiostu go-librespot[2228]: time="2026-02-21T15:45:26Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:26 volumiostu volumio[1847]: info: MyVolumio status changed Feb 21 15:45:26 volumiostu volumio[1847]: info: Streaming services startup Feb 21 15:45:26 volumiostu volumio[1847]: info: Starting Streaming Daemon Feb 21 15:45:26 volumiostu volumio[1847]: info: Removing browser output: myVolumio user plan is not superstar Feb 21 15:45:26 volumiostu volumio[1847]: info: Removing audio output: Feb 21 15:45:26 volumiostu volumio[1847]: info: Stoppping Tunnel 1 Feb 21 15:45:26 volumiostu volumio[1847]: info: Setting Geolocation for MyVolumio to eu3 Feb 21 15:45:26 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:26 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:26 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:26 volumiostu sudo[2260]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:26 volumiostu sudo[2260]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 21 15:45:26 volumiostu sudo[2260]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:26 volumiostu systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 21 15:45:26 volumiostu systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 21 15:45:26 volumiostu systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 21 15:45:26 volumiostu systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 21 15:45:26 volumiostu systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 21 15:45:26 volumiostu systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 21 15:45:26 volumiostu systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 21 15:45:26 volumiostu systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 21 15:45:26 volumiostu sudo[2260]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:26 volumiostu volumio[1847]: info: Remote SSH Stopped Feb 21 15:45:26 volumiostu go-librespot[2228]: time="2026-02-21T15:45:26Z" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 21 15:45:26 volumiostu sudo[2258]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:26 volumiostu go-librespot[2228]: time="2026-02-21T15:45:26Z" level=debug msg="completed keyexchange" Feb 21 15:45:26 volumiostu go-librespot[2228]: time="2026-02-21T15:45:26Z" level=debug msg="completed challenge" Feb 21 15:45:26 volumiostu go-librespot[2228]: time="2026-02-21T15:45:26Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:26 volumiostu sudo[2258]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 21 15:45:26 volumiostu sudo[2258]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:27 volumiostu sudo[2258]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:27 volumiostu volumio[1847]: error: Cannot start Volumio Streaming Daemon Feb 21 15:45:27 volumiostu volumio[1847]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 21 15:45:27 volumiostu volumio[1847]: sudo: unable to resolve host volumiostu: System error Feb 21 15:45:27 volumiostu volumio[1847]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 21 15:45:27 volumiostu volumio[1847]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 21 15:45:27 volumiostu volumio5-onboarding[1915]: failed to bootstrap state: failed to check for software update: could not check for updates: context deadline exceeded Feb 21 15:45:27 volumiostu systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:45:27 volumiostu systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Feb 21 15:45:27 volumiostu systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 2. Feb 21 15:45:27 volumiostu systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 21 15:45:27 volumiostu systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 21 15:45:27 volumiostu go-librespot[2228]: time="2026-02-21T15:45:27Z" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 21 15:45:27 volumiostu volumio5-onboarding[2263]: time=2026-02-21T15:45:27.673Z level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Feb 21 15:45:27 volumiostu volumio[1847]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Feb 21 15:45:27 volumiostu volumio[1847]: info: Updating MyVolumio device info Feb 21 15:45:27 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:27 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:27 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:27 volumiostu volumio[1847]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Feb 21 15:45:27 volumiostu volumio[1847]: info: Received Get System Info Feb 21 15:45:27 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:45:27 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:45:27 volumiostu volumio[1847]: info: Discovery: Getting this device information Feb 21 15:45:27 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:27 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:27 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:45:27 volumiostu volumio5-onboarding[2263]: time=2026-02-21T15:45:27.842Z level=INFO msg="system info for c548e4720a9caac822872f820532ef56" deviceName=Volumio_Stu deviceVariant=volumio deviceModel= softwareVersion=4.096 Feb 21 15:45:27 volumiostu go-librespot[2228]: time="2026-02-21T15:45:27Z" level=debug msg="completed keyexchange" Feb 21 15:45:27 volumiostu go-librespot[2228]: time="2026-02-21T15:45:27Z" level=debug msg="completed challenge" Feb 21 15:45:27 volumiostu volumio[1847]: info: Received Get System Info Feb 21 15:45:27 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:45:27 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:45:27 volumiostu volumio[1847]: info: Discovery: Getting this device information Feb 21 15:45:27 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:27 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:27 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:45:27 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 21 15:45:27 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 21 15:45:27 volumiostu volumio5-onboarding[2263]: time=2026-02-21T15:45:27.906Z level=INFO msg="enabling local network discovery" Feb 21 15:45:27 volumiostu volumio5-onboarding[2263]: time=2026-02-21T15:45:27.948Z level=INFO msg="bootstrapping state" hasInternet=true Feb 21 15:45:27 volumiostu volumio[1847]: info: Received Get System Info Feb 21 15:45:27 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:45:27 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:45:27 volumiostu volumio[1847]: info: Discovery: Getting this device information Feb 21 15:45:27 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:27 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:27 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:45:27 volumiostu volumio-remote-updater[740]: Test mode disabled Feb 21 15:45:27 volumiostu volumio-remote-updater[740]: Alpha mode disabled Feb 21 15:45:27 volumiostu volumio-remote-updater[740]: Alpha legacy test mode disabled Feb 21 15:45:28 volumiostu go-librespot[2228]: time="2026-02-21T15:45:28Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:28 volumiostu go-librespot[2228]: time="2026-02-21T15:45:28Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:28 volumiostu systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:45:28 volumiostu systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 15:45:28 volumiostu sudo[2276]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:28 volumiostu sudo[2276]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 21 15:45:28 volumiostu sudo[2276]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:28 volumiostu volumio[1847]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 21 15:45:28 volumiostu volumio[1847]: info: Connection to go-librespot Websocket closed Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 21 15:45:28 volumiostu sudo[2278]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:28 volumiostu sudo[2278]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 15:45:28 volumiostu sudo[2278]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:28 volumiostu sudo[2276]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:28 volumiostu sudo[2278]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 21 15:45:28 volumiostu volumio[1847]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 21 15:45:28 volumiostu volumio[1847]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.169 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/145.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:28 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:28 volumiostu volumio[1847]: info: Received Get System Info Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:45:28 volumiostu volumio[1847]: info: Discovery: Getting this device information Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:28 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:28 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetVisibleSources Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:28 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:28 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 21 15:45:28 volumiostu volumio[1847]: info: Received Get System Info Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:45:28 volumiostu volumio[1847]: info: Discovery: Getting this device information Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:28 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:45:28 volumiostu volumio[1847]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:28 volumiostu volumio[1847]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:28 volumiostu volumio[1847]: info: Listing playlists Feb 21 15:45:28 volumiostu sudo[2282]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:28 volumiostu sudo[2282]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 21 15:45:28 volumiostu sudo[2282]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:28 volumiostu volumio[1847]: info: Getting Spotify volume Feb 21 15:45:28 volumiostu volumio[1847]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 15:45:28 volumiostu volumio[1847]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 15:45:28 volumiostu volumio[1847]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 21 15:45:28 volumiostu volumio[1847]: errno: -111, Feb 21 15:45:28 volumiostu volumio[1847]: code: 'ECONNREFUSED', Feb 21 15:45:28 volumiostu volumio[1847]: syscall: 'connect', Feb 21 15:45:28 volumiostu volumio[1847]: address: '127.0.0.1', Feb 21 15:45:28 volumiostu volumio[1847]: port: 9879, Feb 21 15:45:28 volumiostu volumio[1847]: response: undefined Feb 21 15:45:28 volumiostu volumio[1847]: } Feb 21 15:45:28 volumiostu volumio[1847]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 15:45:28 volumiostu sudo[2284]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:28 volumiostu sudo[2284]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 15:45:28 volumiostu sudo[2284]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:28 volumiostu sudo[2284]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:28 volumiostu sudo[2282]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:30 volumiostu upmpdcli[2299]: writing RSA key Feb 21 15:45:31 volumiostu systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 21 15:45:31 volumiostu systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:45:31 volumiostu systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:45:31 volumiostu go-librespot[2309]: go-librespot daemon starting... Feb 21 15:45:31 volumiostu go-librespot[2313]: time="2026-02-21T15:45:31Z" level=info msg="running go-librespot 0.6.2" Feb 21 15:45:31 volumiostu go-librespot[2313]: time="2026-02-21T15:45:31Z" level=debug msg="app state loaded" Feb 21 15:45:31 volumiostu go-librespot[2313]: time="2026-02-21T15:45:31Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 15:45:31 volumiostu go-librespot[2313]: time="2026-02-21T15:45:31Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 21 15:45:31 volumiostu go-librespot[2313]: time="2026-02-21T15:45:31Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 21 15:45:31 volumiostu go-librespot[2313]: time="2026-02-21T15:45:31Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 21 15:45:31 volumiostu go-librespot[2313]: time="2026-02-21T15:45:31Z" level=info msg="zeroconf server listening on port 37271" Feb 21 15:45:31 volumiostu sudo[2330]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:31 volumiostu sudo[2330]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-21 15:44' Feb 21 15:45:31 volumiostu sudo[2330]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:31 volumiostu go-librespot[2313]: time="2026-02-21T15:45:31Z" level=debug msg="obtained new client token: AAD0lkxo0vATqnVyV4aHdSVw0uMrMjQC7yZCWv9M2H/cDL6moxC4j2ohUYC7jf4cAmGfmtqJvr8NHts1JhnG/tOvYu5rPEt1s29E8hUccA9jqSbV0YkHwBh23rFcIoH3SmcCCmSMz5FrJTjrpqBefKyqs6Zv5N+cJQ5OZMaBaY3Boa8sa3TEKUPzHo+vbWpgHr6lZAw4ez/766c52wWObDkYBkohb4P/iLB7EAb+33P9vcHzhis+zUF+" Feb 21 15:45:31 volumiostu go-librespot[2313]: time="2026-02-21T15:45:31Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:45:31 volumiostu go-librespot[2313]: time="2026-02-21T15:45:31Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 21 15:45:32 volumiostu go-librespot[2313]: time="2026-02-21T15:45:32Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 21 15:45:32 volumiostu go-librespot[2313]: time="2026-02-21T15:45:32Z" level=debug msg="completed keyexchange" Feb 21 15:45:32 volumiostu go-librespot[2313]: time="2026-02-21T15:45:32Z" level=debug msg="completed challenge" Feb 21 15:45:32 volumiostu go-librespot[2313]: time="2026-02-21T15:45:32Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:32 volumiostu sudo[2330]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:32 volumiostu volumio[1847]: sudo: unable to resolve host volumiostu: System error Feb 21 15:45:32 volumiostu volumio-remote-updater[740]: [2026-02-21 15:45:32] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 21 15:45:32 volumiostu volumio-remote-updater[740]: [2026-02-21 15:45:32] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 21 15:45:32 volumiostu volumio5-onboarding[2263]: time=2026-02-21T15:45:32.811Z level=ERROR msg="failed reading message" component=volumio/socket error="websocket: close 1006 (abnormal closure): unexpected EOF" Feb 21 15:45:32 volumiostu volumio5-onboarding[2263]: time=2026-02-21T15:45:32.812Z level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 21 15:45:32 volumiostu systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:45:32 volumiostu systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 21 15:45:32 volumiostu systemd[1]: volumio.service: Consumed 1min 28.444s CPU time. Feb 21 15:45:32 volumiostu go-librespot[2313]: time="2026-02-21T15:45:32Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 21 15:45:32 volumiostu go-librespot[2313]: time="2026-02-21T15:45:32Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:58100->104.199.65.9:80: read: connection reset by peer" Feb 21 15:45:32 volumiostu systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 21 15:45:32 volumiostu systemd[1]: dynamicswap.service: Deactivated successfully. Feb 21 15:45:33 volumiostu systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Feb 21 15:45:33 volumiostu systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 21 15:45:33 volumiostu systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 21 15:45:33 volumiostu systemd[1]: volumio.service: Consumed 1min 28.444s CPU time. Feb 21 15:45:33 volumiostu systemd[1]: Started volumio.service - Volumio Backend Module. Feb 21 15:45:33 volumiostu systemd[1]: dynamicswap.service: Deactivated successfully. Feb 21 15:45:33 volumiostu go-librespot[2313]: time="2026-02-21T15:45:33Z" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 15:45:33 volumiostu go-librespot[2313]: time="2026-02-21T15:45:33Z" level=debug msg="completed keyexchange" Feb 21 15:45:33 volumiostu go-librespot[2313]: time="2026-02-21T15:45:33Z" level=debug msg="completed challenge" Feb 21 15:45:33 volumiostu go-librespot[2313]: time="2026-02-21T15:45:33Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:33 volumiostu volumio5-onboarding[2263]: time=2026-02-21T15:45:33.813Z level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 21 15:45:34 volumiostu go-librespot[2313]: time="2026-02-21T15:45:34Z" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 21 15:45:34 volumiostu go-librespot[2313]: time="2026-02-21T15:45:34Z" level=debug msg="completed keyexchange" Feb 21 15:45:34 volumiostu go-librespot[2313]: time="2026-02-21T15:45:34Z" level=debug msg="completed challenge" Feb 21 15:45:34 volumiostu go-librespot[2313]: time="2026-02-21T15:45:34Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:34 volumiostu volumio5-onboarding[2263]: time=2026-02-21T15:45:34.814Z level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 21 15:45:34 volumiostu go-librespot[2313]: time="2026-02-21T15:45:34Z" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 21 15:45:35 volumiostu go-librespot[2313]: time="2026-02-21T15:45:35Z" level=debug msg="completed keyexchange" Feb 21 15:45:35 volumiostu go-librespot[2313]: time="2026-02-21T15:45:35Z" level=debug msg="completed challenge" Feb 21 15:45:35 volumiostu go-librespot[2313]: time="2026-02-21T15:45:35Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:35 volumiostu go-librespot[2313]: time="2026-02-21T15:45:35Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:35 volumiostu systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:45:35 volumiostu systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 15:45:35 volumiostu volumio[2352]: info: ------------------------------------------- Feb 21 15:45:35 volumiostu volumio[2352]: info: ----- Volumio3 ---- Feb 21 15:45:35 volumiostu volumio[2352]: info: ------------------------------------------- Feb 21 15:45:35 volumiostu volumio[2352]: info: ----- System startup ---- Feb 21 15:45:35 volumiostu volumio[2352]: info: ------------------------------------------- Feb 21 15:45:36 volumiostu volumio[2352]: info: MYVOLUMIO Environment detected Feb 21 15:45:36 volumiostu volumio[2352]: info: Plugin folders cleanup Feb 21 15:45:36 volumiostu volumio[2352]: info: Scanning into folder /volumio/app/plugins/ Feb 21 15:45:36 volumiostu volumio[2352]: info: Scanning category audio_interface Feb 21 15:45:36 volumiostu volumio[2352]: info: Scanning category miscellanea Feb 21 15:45:36 volumiostu volumio[2352]: info: Scanning category music_service Feb 21 15:45:36 volumiostu volumio[2352]: info: Scanning category plugins.json Feb 21 15:45:36 volumiostu volumio[2352]: info: Scanning category system_controller Feb 21 15:45:36 volumiostu volumio[2352]: info: Scanning category user_interface Feb 21 15:45:36 volumiostu volumio[2352]: info: Scanning into folder /data/plugins/ Feb 21 15:45:36 volumiostu volumio[2352]: info: Scanning category music_service Feb 21 15:45:36 volumiostu volumio[2352]: info: Scanning category user_interface Feb 21 15:45:36 volumiostu volumio[2352]: info: Plugin folders cleanup completed Feb 21 15:45:36 volumiostu volumio[2352]: info: ------------------------------------------- Feb 21 15:45:36 volumiostu volumio[2352]: info: ----- Core plugins startup ---- Feb 21 15:45:36 volumiostu volumio[2352]: info: ------------------------------------------- Feb 21 15:45:36 volumiostu volumio[2352]: info: Loading plugins from folder /volumio/app/plugins/ Feb 21 15:45:36 volumiostu volumio[2352]: info: Adding plugin upnp to MyMusic Plugins Feb 21 15:45:36 volumiostu volumio[2352]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 21 15:45:36 volumiostu volumio[2352]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 21 15:45:36 volumiostu volumio[2352]: info: Loading plugins from folder /data/plugins/ Feb 21 15:45:36 volumiostu volumio[2352]: info: Loading plugin "system"... Feb 21 15:45:36 volumiostu volumio[2352]: info: Loading plugin "appearance"... Feb 21 15:45:37 volumiostu volumio[2352]: info: Loading plugin "network"... Feb 21 15:45:37 volumiostu volumio[2352]: info: Refreshing Cached IP Addresses Feb 21 15:45:37 volumiostu volumio[2352]: info: Loading plugin "services"... Feb 21 15:45:37 volumiostu volumio[2352]: info: Loading plugin "volumio5onboarding"... Feb 21 15:45:37 volumiostu sudo[2380]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:37 volumiostu sudo[2382]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:37 volumiostu sudo[2380]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 21 15:45:37 volumiostu volumio[2352]: info: Loading plugin "alsa_controller"... Feb 21 15:45:37 volumiostu sudo[2380]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:37 volumiostu sudo[2388]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:37 volumiostu sudo[2382]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 15:45:37 volumiostu sudo[2382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:37 volumiostu sudo[2382]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:37 volumiostu sudo[2388]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 21 15:45:37 volumiostu sudo[2388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:37 volumiostu sudo[2380]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:37 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 15:45:37 volumiostu volumio[2352]: info: Loading plugin "wizard"... Feb 21 15:45:37 volumiostu volumio[2352]: info: Loading plugin "networkfs"... Feb 21 15:45:37 volumiostu volumio[2352]: info: Starting Udev Watcher for removable devices Feb 21 15:45:37 volumiostu volumio-remote-updater[740]: [2026-02-21 15:45:37] [connect] Successful connection Feb 21 15:45:37 volumiostu volumio[2352]: info: Ignoring mount for partition: boot Feb 21 15:45:37 volumiostu volumio[2352]: info: Ignoring mount for partition: volumio Feb 21 15:45:37 volumiostu volumio[2352]: info: Ignoring mount for partition: volumio_data Feb 21 15:45:37 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 21 15:45:37 volumiostu volumio[2352]: info: Loading plugin "volumio_command_line_client"... Feb 21 15:45:37 volumiostu volumio[2352]: info: Loading plugin "upnp"... Feb 21 15:45:37 volumiostu volumio[2352]: info: [1771688737875] Starting Upmpd Daemon Feb 21 15:45:37 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 21 15:45:37 volumiostu volumio[2352]: info: Loading plugin "my_music"... Feb 21 15:45:37 volumiostu volumio[2352]: info: Loading plugin "mpd"... Feb 21 15:45:38 volumiostu volumio[2352]: info: Loading plugin "upnp_browser"... Feb 21 15:45:38 volumiostu systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 21 15:45:38 volumiostu systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:45:38 volumiostu systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:45:38 volumiostu go-librespot[2413]: go-librespot daemon starting... Feb 21 15:45:38 volumiostu go-librespot[2414]: time="2026-02-21T15:45:38Z" level=info msg="running go-librespot 0.6.2" Feb 21 15:45:38 volumiostu go-librespot[2414]: time="2026-02-21T15:45:38Z" level=debug msg="app state loaded" Feb 21 15:45:38 volumiostu go-librespot[2414]: time="2026-02-21T15:45:38Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 15:45:39 volumiostu go-librespot[2414]: time="2026-02-21T15:45:39Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 21 15:45:39 volumiostu go-librespot[2414]: time="2026-02-21T15:45:39Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 21 15:45:39 volumiostu go-librespot[2414]: time="2026-02-21T15:45:39Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 21 15:45:39 volumiostu go-librespot[2414]: time="2026-02-21T15:45:39Z" level=info msg="zeroconf server listening on port 44551" Feb 21 15:45:39 volumiostu go-librespot[2414]: time="2026-02-21T15:45:39Z" level=debug msg="obtained new client token: AAB5FhWz+8IPpWHMxPeL4lXCihfYKvZQ6O1xMge8yPjZPCNHGbejkOBIINa3/DPNDGUVG2g4VfC7zR2kCL3gGxx3fVXw1qfPP1k44f4HQeBWtxa0qo0wBVwWW4GmEO9hsH457Z29sXMES3uSdr5kDnSJlMYM3vogNNSvpxWxroC7jq0akEdEOCM6YFLiW/c8pDJx4e7eSdwdbtwBtQFzwnx4F56+hyctz8O2gcj/lHlIaPQvxp1bOQ==" Feb 21 15:45:39 volumiostu go-librespot[2414]: time="2026-02-21T15:45:39Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:45:39 volumiostu go-librespot[2414]: time="2026-02-21T15:45:39Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 21 15:45:39 volumiostu volumio[2352]: info: Starting UPNP Browser Feb 21 15:45:39 volumiostu volumio[2352]: info: Loading plugin "alarm-clock"... Feb 21 15:45:39 volumiostu volumio[2352]: info: Loading plugin "airplay_emulation"... Feb 21 15:45:39 volumiostu volumio[2352]: info: Starting Shairport Sync Feb 21 15:45:39 volumiostu volumio[2352]: info: Loading plugin "last_100"... Feb 21 15:45:39 volumiostu volumio[2352]: info: Loading plugin "webradio"... Feb 21 15:45:39 volumiostu go-librespot[2414]: time="2026-02-21T15:45:39Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 21 15:45:39 volumiostu go-librespot[2414]: time="2026-02-21T15:45:39Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:36718->104.199.65.9:443: read: connection reset by peer" Feb 21 15:45:40 volumiostu volumio[2352]: info: Loading plugin "i2s_dacs"... Feb 21 15:45:40 volumiostu volumio[2352]: info: Loading plugin "volumiodiscovery"... Feb 21 15:45:40 volumiostu volumio[2352]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 21 15:45:40 volumiostu node[2352]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 21 15:45:40 volumiostu volumio[2352]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 15:45:40 volumiostu node[2352]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 15:45:40 volumiostu volumio[2352]: *** WARNING *** For more information see Feb 21 15:45:40 volumiostu node[2352]: *** WARNING *** For more information see Feb 21 15:45:40 volumiostu volumio[2352]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 21 15:45:40 volumiostu node[2352]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 21 15:45:40 volumiostu volumio[2352]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 15:45:40 volumiostu node[2352]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 15:45:40 volumiostu volumio[2352]: *** WARNING *** For more information see Feb 21 15:45:40 volumiostu node[2352]: *** WARNING *** For more information see Feb 21 15:45:40 volumiostu volumio[2352]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 21 15:45:40 volumiostu volumio[2352]: info: Discovery: Started advertising with name: Volumio_Stu Feb 21 15:45:40 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 21 15:45:40 volumiostu volumio[2352]: info: Loading plugin "spop"... Feb 21 15:45:40 volumiostu go-librespot[2414]: time="2026-02-21T15:45:40Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.65.9:80: connect: connection refused" Feb 21 15:45:40 volumiostu go-librespot[2414]: time="2026-02-21T15:45:40Z" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 15:45:40 volumiostu go-librespot[2414]: time="2026-02-21T15:45:40Z" level=debug msg="completed keyexchange" Feb 21 15:45:40 volumiostu go-librespot[2414]: time="2026-02-21T15:45:40Z" level=debug msg="completed challenge" Feb 21 15:45:40 volumiostu sudo[2388]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:41 volumiostu go-librespot[2414]: time="2026-02-21T15:45:41Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:41 volumiostu volumio[2352]: info: Plugin now_playing is not enabled Feb 21 15:45:41 volumiostu volumio[2352]: info: Loading plugin "outputs"... Feb 21 15:45:41 volumiostu volumio[2352]: info: Loading plugin "albumart"... Feb 21 15:45:41 volumiostu volumio[2352]: info: Plugin example_plugin is not enabled Feb 21 15:45:41 volumiostu volumio[2352]: info: Loading plugin "inputs"... Feb 21 15:45:41 volumiostu volumio[2352]: info: Loading plugin "updater_comm"... Feb 21 15:45:41 volumiostu volumio[2352]: info: Plugin mpdemulation is not enabled Feb 21 15:45:41 volumiostu volumio[2352]: info: Loading plugin "rest_api"... Feb 21 15:45:41 volumiostu volumio[2352]: info: Loading plugin "websocket"... Feb 21 15:45:41 volumiostu volumio[2352]: info: Starting Socket.io Server version 1.7.4 Feb 21 15:45:41 volumiostu volumio[2352]: info: Loading plugin "radio_paradise"... Feb 21 15:45:41 volumiostu go-librespot[2414]: time="2026-02-21T15:45:41Z" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 21 15:45:41 volumiostu go-librespot[2414]: time="2026-02-21T15:45:41Z" level=debug msg="completed keyexchange" Feb 21 15:45:41 volumiostu go-librespot[2414]: time="2026-02-21T15:45:41Z" level=debug msg="completed challenge" Feb 21 15:45:41 volumiostu go-librespot[2414]: time="2026-02-21T15:45:41Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:41 volumiostu volumio[2352]: info: Applying required configuration parameters for plugin radio_paradise Feb 21 15:45:41 volumiostu volumio[2352]: info: [1771688741733] [RadioParadise] API delay: 5 Feb 21 15:45:41 volumiostu volumio[2352]: info: Loading i18n strings for locale en Feb 21 15:45:41 volumiostu volumio[2352]: Updating browse sources language Feb 21 15:45:41 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:45:41 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 15:45:41 volumiostu volumio[2352]: info: CoreCommandRouter::initPlayerControls Feb 21 15:45:41 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:41 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:41 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:41 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:41 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:41 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:41 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:41 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:42 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 15:45:42 volumiostu volumio[2352]: Express server listening on port 3000 Feb 21 15:45:42 volumiostu volumio[2352]: [Metrics] WebUI: 7s 184.11ms Feb 21 15:45:42 volumiostu volumio[2352]: info: CoreStateMachine::resetVolumioState Feb 21 15:45:42 volumiostu volumio[2352]: info: CoreStateMachine::getcurrentVolume Feb 21 15:45:42 volumiostu volumio[2352]: info: CoreCommandRouter::volumioRetrievevolume Feb 21 15:45:42 volumiostu volumio[2352]: info: Volumio Network Manager: Network status updated: 2 Feb 21 15:45:42 volumiostu volumio[2425]: Forking 3 albumart workers Feb 21 15:45:42 volumiostu go-librespot[2414]: time="2026-02-21T15:45:42Z" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 21 15:45:42 volumiostu volumio[2352]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.169 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/145.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Feb 21 15:45:42 volumiostu go-librespot[2414]: time="2026-02-21T15:45:42Z" level=debug msg="completed keyexchange" Feb 21 15:45:42 volumiostu go-librespot[2414]: time="2026-02-21T15:45:42Z" level=debug msg="completed challenge" Feb 21 15:45:42 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:42 volumiostu volumio[2352]: info: Reloading queue from file Feb 21 15:45:42 volumiostu go-librespot[2414]: time="2026-02-21T15:45:42Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:42 volumiostu volumio[2352]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.169 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/145.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Feb 21 15:45:42 volumiostu volumio[2352]: info: VolumeController:: Volume=70 Mute =false Feb 21 15:45:42 volumiostu volumio[2352]: info: CoreStateMachine::pushState Feb 21 15:45:42 volumiostu volumio[2352]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:42 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 21 15:45:42 volumiostu volumio[2352]: info: CoreCommandRouter::volumioPushState Feb 21 15:45:42 volumiostu volumio[2352]: info: CoreStateMachine::updateTrackBlock Feb 21 15:45:42 volumiostu volumio[2352]: info: CorePlayQueue::getTrackBlock Feb 21 15:45:42 volumiostu volumio[2352]: info: CoreCommandRouter::volumioRetrievevolume Feb 21 15:45:43 volumiostu volumio[2352]: info: CoreStateMachine::setRepeat true single undefined Feb 21 15:45:43 volumiostu volumio[2352]: info: CoreStateMachine::pushState Feb 21 15:45:43 volumiostu volumio[2352]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:43 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 21 15:45:43 volumiostu volumio[2352]: info: CoreCommandRouter::volumioPushState Feb 21 15:45:43 volumiostu volumio[2352]: info: CoreStateMachine::setRandom null Feb 21 15:45:43 volumiostu volumio[2352]: info: CoreStateMachine::pushState Feb 21 15:45:43 volumiostu volumio[2352]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:43 volumiostu volumio[2352]: info: CoreCommandRouter::volumioPushState Feb 21 15:45:43 volumiostu volumio[2352]: info: Setting Device type: Raspberry PI Feb 21 15:45:43 volumiostu go-librespot[2414]: time="2026-02-21T15:45:43Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:45:43 volumiostu go-librespot[2414]: time="2026-02-21T15:45:43Z" level=debug msg="completed keyexchange" Feb 21 15:45:43 volumiostu go-librespot[2414]: time="2026-02-21T15:45:43Z" level=debug msg="completed challenge" Feb 21 15:45:43 volumiostu volumio[2352]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Feb 21 15:45:43 volumiostu go-librespot[2414]: time="2026-02-21T15:45:43Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:43 volumiostu go-librespot[2414]: time="2026-02-21T15:45:43Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:43 volumiostu systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:45:43 volumiostu systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 15:45:43 volumiostu volumio[2352]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Feb 21 15:45:43 volumiostu volumio[2352]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03114 Feb 21 15:45:43 volumiostu volumio[2352]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Feb 21 15:45:43 volumiostu volumio[2352]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Feb 21 15:45:43 volumiostu volumio[2352]: info: Received Get System Info Feb 21 15:45:43 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:45:43 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:45:43 volumiostu volumio[2352]: info: Discovery: Getting this device information Feb 21 15:45:43 volumiostu volumio[2352]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:43 volumiostu volumio[2352]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:43 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:45:43 volumiostu volumio[2352]: info: VolumeController:: Volume=70 Mute =false Feb 21 15:45:43 volumiostu volumio[2352]: info: CoreStateMachine::pushState Feb 21 15:45:43 volumiostu volumio[2352]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:43 volumiostu volumio[2352]: info: CoreCommandRouter::volumioPushState Feb 21 15:45:43 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 21 15:45:43 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 21 15:45:43 volumiostu volumio[2352]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.169 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/145.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Feb 21 15:45:44 volumiostu volumio[2352]: info: Discovery: adding 15a5d113-f4b7-4105-922c-74fc7b77d920 Feb 21 15:45:44 volumiostu volumio[2352]: info: Discovery: Found device Volumio_Stu Feb 21 15:45:44 volumiostu volumio[2352]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:44 volumiostu volumio[2352]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:44 volumiostu volumio[2352]: info: Discovery: this is already registered, 15a5d113-f4b7-4105-922c-74fc7b77d920 Feb 21 15:45:44 volumiostu volumio[2352]: info: Discovery: Found device Volumio_Stu Feb 21 15:45:44 volumiostu volumio[2352]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:44 volumiostu volumio[2352]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:44 volumiostu volumio[2352]: info: Completed loading Core Plugins Feb 21 15:45:44 volumiostu volumio[2352]: info: Preparing to generate the ALSA configuration file Feb 21 15:45:44 volumiostu volumio[2352]: info: Asound.conf file unchanged, so no further update is needed Feb 21 15:45:44 volumiostu volumio[2352]: info: Output device has changed, restarting MPD Feb 21 15:45:44 volumiostu volumio[2352]: info: Output device has changed, restarting Shairport Sync Feb 21 15:45:44 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:44 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:44 volumiostu sudo[2483]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:44 volumiostu sudo[2483]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 21 15:45:44 volumiostu sudo[2483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:44 volumiostu sudo[2485]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:44 volumiostu sudo[2485]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 21 15:45:44 volumiostu volumio[2352]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 15:45:44 volumiostu sudo[2485]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:44 volumiostu sudo[2483]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:44 volumiostu volumio[2352]: info: ___________ START PLUGINS ___________ Feb 21 15:45:44 volumiostu volumio[2352]: info: ControllerMpd::onStart: Initializing MPD Feb 21 15:45:44 volumiostu volumio[2352]: info: Creating MPD Configuration file Feb 21 15:45:44 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 15:45:44 volumiostu volumio[2352]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 15:45:44 volumiostu volumio[2352]: info: [1771688744509] CoreMusicLibrary::Adding element Media Servers Feb 21 15:45:44 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:45:44 volumiostu sudo[2493]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:44 volumiostu volumio[2352]: info: UPNP Browser: Client initialized successfully Feb 21 15:45:44 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:44 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:44 volumiostu sudo[2493]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Feb 21 15:45:44 volumiostu sudo[2493]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:44 volumiostu systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 21 15:45:44 volumiostu sudo[2495]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:44 volumiostu sudo[2495]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 21 15:45:44 volumiostu sudo[2495]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:44 volumiostu systemd[1]: mpd.service: Deactivated successfully. Feb 21 15:45:44 volumiostu systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 21 15:45:44 volumiostu systemd[1]: mpd.service: Consumed 1.500s CPU time. Feb 21 15:45:44 volumiostu systemd[1]: mpd.socket: Deactivated successfully. Feb 21 15:45:44 volumiostu systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 21 15:45:44 volumiostu systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 21 15:45:44 volumiostu systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 21 15:45:44 volumiostu systemd[1]: Starting mpd.service - Music Player Daemon... Feb 21 15:45:44 volumiostu sudo[2497]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:44 volumiostu volumio[2352]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 15:45:44 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:44 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:44 volumiostu sudo[2493]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:44 volumiostu sudo[2495]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:44 volumiostu sudo[2497]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 21 15:45:44 volumiostu sudo[2497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:44 volumiostu sudo[2505]: root : unable to resolve host volumiostu: System error Feb 21 15:45:44 volumiostu sudo[2505]: sudo: unable to resolve host volumiostu: System error Feb 21 15:45:44 volumiostu sudo[2505]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 21 15:45:44 volumiostu sudo[2505]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 21 15:45:44 volumiostu sudo[2505]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:44 volumiostu systemd[1]: mpd.service: Deactivated successfully. Feb 21 15:45:44 volumiostu systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 21 15:45:44 volumiostu systemd[1]: mpd.socket: Deactivated successfully. Feb 21 15:45:44 volumiostu volumio[2352]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 15:45:44 volumiostu systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 21 15:45:44 volumiostu systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 21 15:45:44 volumiostu volumio[2352]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 15:45:44 volumiostu volumio[2352]: info: [1771688744862] CoreMusicLibrary::Adding element Last_100 Feb 21 15:45:44 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:45:44 volumiostu volumio[2352]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 15:45:44 volumiostu volumio[2352]: info: [1771688744863] CoreMusicLibrary::Adding element Webradio Feb 21 15:45:44 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:45:44 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 15:45:44 volumiostu volumio[2352]: info: Initializing BBC Radios Feb 21 15:45:44 volumiostu systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 21 15:45:44 volumiostu systemd[1]: Starting mpd.service - Music Player Daemon... Feb 21 15:45:45 volumiostu sudo[2513]: root : unable to resolve host volumiostu: System error Feb 21 15:45:45 volumiostu sudo[2513]: sudo: unable to resolve host volumiostu: System error Feb 21 15:45:45 volumiostu sudo[2513]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 21 15:45:45 volumiostu sudo[2513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 21 15:45:45 volumiostu sudo[2513]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:45 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 15:45:45 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:45 volumiostu volumio[2352]: info: Creating Spotify config file Feb 21 15:45:45 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:46 volumiostu mpd[2518]: 2026-02-21T15:45:46 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 21 15:45:46 volumiostu systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 21 15:45:46 volumiostu systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:45:46 volumiostu systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:45:46 volumiostu systemd[1]: Started mpd.service - Music Player Daemon. Feb 21 15:45:46 volumiostu go-librespot[2530]: go-librespot daemon starting... Feb 21 15:45:46 volumiostu sudo[2497]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:46 volumiostu sudo[2485]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:46 volumiostu go-librespot[2533]: time="2026-02-21T15:45:46Z" level=info msg="running go-librespot 0.6.2" Feb 21 15:45:46 volumiostu go-librespot[2533]: time="2026-02-21T15:45:46Z" level=info msg="zeroconf server listening on port 39013" Feb 21 15:45:47 volumiostu volumio[2352]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 15:45:47 volumiostu volumio[2352]: info: [1771688747167] CoreMusicLibrary::Adding element Radio Paradise Feb 21 15:45:47 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:45:47 volumiostu volumio[2352]: Cannot find translation for source Radio Paradise Feb 21 15:45:47 volumiostu volumio[2352]: info: Volumio Calling Home Feb 21 15:45:47 volumiostu volumio[2442]: Starting albumart workers Feb 21 15:45:47 volumiostu volumio[2352]: info: MPD Permissions set Feb 21 15:45:47 volumiostu volumio[2352]: info: Completed starting Core Plugins Feb 21 15:45:47 volumiostu volumio[2352]: info: ------------------------------------------- Feb 21 15:45:47 volumiostu volumio[2352]: info: ----- MyVolumio plugins startup ---- Feb 21 15:45:47 volumiostu volumio[2352]: info: ------------------------------------------- Feb 21 15:45:47 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 21 15:45:47 volumiostu volumio[2443]: Starting albumart workers Feb 21 15:45:47 volumiostu volumio[2352]: info: MPD Permissions set Feb 21 15:45:47 volumiostu volumio[2441]: Starting albumart workers Feb 21 15:45:47 volumiostu volumio[2352]: info: MPD running with PID2518 Feb 21 15:45:47 volumiostu volumio[2352]: ,establishing connection Feb 21 15:45:47 volumiostu volumio[2352]: info: Volumio called home Feb 21 15:45:48 volumiostu sudo[2564]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:48 volumiostu sudo[2564]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 21 15:45:48 volumiostu sudo[2564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:48 volumiostu sudo[2564]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:48 volumiostu volumio[2352]: info: Spotify config file written Feb 21 15:45:48 volumiostu sudo[2567]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:48 volumiostu sudo[2567]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 15:45:48 volumiostu sudo[2567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:48 volumiostu sudo[2567]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:48 volumiostu sudo[2570]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:48 volumiostu sudo[2570]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 21 15:45:48 volumiostu sudo[2570]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:48 volumiostu systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 21 15:45:48 volumiostu systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 21 15:45:48 volumiostu systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:45:48 volumiostu systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:45:48 volumiostu sudo[2570]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:48 volumiostu go-librespot[2572]: go-librespot daemon starting... Feb 21 15:45:48 volumiostu go-librespot[2573]: time="2026-02-21T15:45:48Z" level=info msg="running go-librespot 0.6.2" Feb 21 15:45:48 volumiostu go-librespot[2573]: time="2026-02-21T15:45:48Z" level=debug msg="app state loaded" Feb 21 15:45:48 volumiostu go-librespot[2573]: time="2026-02-21T15:45:48Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 15:45:48 volumiostu go-librespot[2573]: time="2026-02-21T15:45:48Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 21 15:45:48 volumiostu go-librespot[2573]: time="2026-02-21T15:45:48Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 21 15:45:48 volumiostu go-librespot[2573]: time="2026-02-21T15:45:48Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 21 15:45:48 volumiostu go-librespot[2573]: time="2026-02-21T15:45:48Z" level=info msg="zeroconf server listening on port 33339" Feb 21 15:45:48 volumiostu go-librespot[2573]: time="2026-02-21T15:45:48Z" level=debug msg="obtained new client token: AACsM8Ju+uUd7mlr+p7rFKgmq2WkVUDGp4qbE5/T9YTOQLh0WizFBxmpszGuah6wrdAuX0qBmkYtLxGMZ/gEbxdVSbQdQvqA1dsbL6Pa/2VSLBTAv41Nf/5eQXFpICqDBidrP1lRzJ6AVmDHShGfd0uArvqw9gw8rusJ5maXkvSqseDKgxYjMQ50tbA4hgnWRv8qigXxceYh7JM2nWCNr4C9vwSysF60uw9eN8Ax/1tyLicuQu1Bbw3Z" Feb 21 15:45:48 volumiostu go-librespot[2573]: time="2026-02-21T15:45:48Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:45:48 volumiostu go-librespot[2573]: time="2026-02-21T15:45:48Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:55388->104.199.65.9:4070: read: connection reset by peer" Feb 21 15:45:49 volumiostu volumio[2352]: error: MPD error: The expression evaluated to a falsy value: Feb 21 15:45:49 volumiostu volumio[2352]: assert.ok(self.idling) Feb 21 15:45:49 volumiostu volumio[2352]: error: The expression evaluated to a falsy value: Feb 21 15:45:49 volumiostu volumio[2352]: assert.ok(self.idling) Feb 21 15:45:49 volumiostu volumio[2352]: error: MPD error: The expression evaluated to a falsy value: Feb 21 15:45:49 volumiostu volumio[2352]: assert.ok(self.idling) Feb 21 15:45:49 volumiostu volumio[2352]: error: The expression evaluated to a falsy value: Feb 21 15:45:49 volumiostu volumio[2352]: assert.ok(self.idling) Feb 21 15:45:49 volumiostu volumio[2352]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:49 volumiostu go-librespot[2573]: time="2026-02-21T15:45:49Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Feb 21 15:45:49 volumiostu go-librespot[2573]: time="2026-02-21T15:45:49Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 21 15:45:49 volumiostu go-librespot[2573]: time="2026-02-21T15:45:49Z" level=debug msg="completed keyexchange" Feb 21 15:45:49 volumiostu go-librespot[2573]: time="2026-02-21T15:45:49Z" level=debug msg="completed challenge" Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:49 volumiostu go-librespot[2573]: time="2026-02-21T15:45:49Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:49 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:45:49 volumiostu volumio[2352]: info: No need to fix Spotify hosts Feb 21 15:45:49 volumiostu volumio[2352]: error: updateQueue error: null Feb 21 15:45:49 volumiostu volumio[2352]: info: New Spotify access tokenBQCkH30lDv... Feb 21 15:45:49 volumiostu volumio[2352]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 21 15:45:49 volumiostu volumio[2352]: info: Starting Shairport Sync Feb 21 15:45:49 volumiostu volumio[2352]: info: Starting Shairport Sync Feb 21 15:45:49 volumiostu volumio[2352]: info: Starting Shairport Sync Feb 21 15:45:49 volumiostu go-librespot[2573]: time="2026-02-21T15:45:49Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 21 15:45:50 volumiostu sudo[2609]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:50 volumiostu sudo[2609]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 15:45:50 volumiostu sudo[2605]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:50 volumiostu sudo[2605]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 15:45:50 volumiostu sudo[2605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:50 volumiostu sudo[2609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:50 volumiostu systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 21 15:45:50 volumiostu go-librespot[2573]: time="2026-02-21T15:45:50Z" level=debug msg="completed keyexchange" Feb 21 15:45:50 volumiostu go-librespot[2573]: time="2026-02-21T15:45:50Z" level=debug msg="completed challenge" Feb 21 15:45:50 volumiostu sudo[2607]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:50 volumiostu systemd[1]: shairport-sync.service: Deactivated successfully. Feb 21 15:45:50 volumiostu systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 15:45:50 volumiostu systemd[1]: shairport-sync.service: Consumed 1.614s CPU time. Feb 21 15:45:50 volumiostu volumio[2352]: info: CoreCommandRouter::volumioGetState Feb 21 15:45:50 volumiostu sudo[2613]: volumio : unable to resolve host volumiostu: System error Feb 21 15:45:50 volumiostu volumio[2352]: info: CorePlayQueue::getTrack 0 Feb 21 15:45:50 volumiostu sudo[2613]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 21 15:45:50 volumiostu sudo[2613]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:50 volumiostu sudo[2607]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 15:45:50 volumiostu sudo[2607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:45:50 volumiostu systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 15:45:50 volumiostu systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 21 15:45:50 volumiostu sudo[2605]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:50 volumiostu systemd[1]: shairport-sync.service: Deactivated successfully. Feb 21 15:45:50 volumiostu systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 15:45:50 volumiostu systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 15:45:50 volumiostu sudo[2609]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:50 volumiostu go-librespot[2573]: time="2026-02-21T15:45:50Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:50 volumiostu sudo[2613]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:50 volumiostu volumio[2352]: info: Upmpdcli Daemon Started Feb 21 15:45:50 volumiostu volumio[2352]: info: Shairport-Sync Started Feb 21 15:45:50 volumiostu volumio-remote-updater[740]: [2026-02-21 15:45:50] [connect] Successful connection Feb 21 15:45:50 volumiostu systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 21 15:45:50 volumiostu systemd[1]: shairport-sync.service: Deactivated successfully. Feb 21 15:45:50 volumiostu systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 15:45:50 volumiostu volumio[2352]: Error adding Membership: Error: addMembership EINVAL Feb 21 15:45:50 volumiostu volumio[2352]: info: Shairport-Sync Started Feb 21 15:45:50 volumiostu volumio-remote-updater[740]: [2026-02-21 15:45:50] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771688750 101 Feb 21 15:45:50 volumiostu volumio[2352]: 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: 6 Feb 21 15:45:50 volumiostu systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 15:45:50 volumiostu sudo[2607]: pam_unix(sudo:session): session closed for user root Feb 21 15:45:50 volumiostu volumio[2352]: info: Shairport-Sync Started Feb 21 15:45:50 volumiostu volumio[2352]: SPOTIFY: User informations: {"country":"BD","display_name":"Maruf","email":"sclements@brainleaked.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/317bbenxuzjt6r76dfjeh6lz7uwi"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/317bbenxuzjt6r76dfjeh6lz7uwi","id":"317bbenxuzjt6r76dfjeh6lz7uwi","images":[],"product":"premium","type":"user","uri":"spotify:user:317bbenxuzjt6r76dfjeh6lz7uwi"} Feb 21 15:45:50 volumiostu volumio[2352]: info: Spotify Successfully logged in Feb 21 15:45:50 volumiostu volumio[2352]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 15:45:50 volumiostu volumio[2352]: info: [1771688750459] CoreMusicLibrary::Adding element Spotify Feb 21 15:45:50 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:45:50 volumiostu volumio[2352]: Cannot find translation for source Radio Paradise Feb 21 15:45:50 volumiostu volumio[2352]: Cannot find translation for source Spotify Feb 21 15:45:50 volumiostu go-librespot[2573]: time="2026-02-21T15:45:50Z" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 21 15:45:50 volumiostu go-librespot[2573]: time="2026-02-21T15:45:50Z" level=debug msg="completed keyexchange" Feb 21 15:45:50 volumiostu go-librespot[2573]: time="2026-02-21T15:45:50Z" level=debug msg="completed challenge" Feb 21 15:45:50 volumiostu go-librespot[2573]: time="2026-02-21T15:45:50Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:51 volumiostu go-librespot[2573]: time="2026-02-21T15:45:51Z" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 21 15:45:51 volumiostu go-librespot[2573]: time="2026-02-21T15:45:51Z" level=debug msg="completed keyexchange" Feb 21 15:45:51 volumiostu go-librespot[2573]: time="2026-02-21T15:45:51Z" level=debug msg="completed challenge" Feb 21 15:45:52 volumiostu go-librespot[2573]: time="2026-02-21T15:45:52Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:52 volumiostu go-librespot[2573]: time="2026-02-21T15:45:52Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:45:52 volumiostu go-librespot[2573]: time="2026-02-21T15:45:52Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:55396->104.199.65.9:4070: read: connection reset by peer" Feb 21 15:45:52 volumiostu go-librespot[2573]: time="2026-02-21T15:45:52Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:55396->104.199.65.9:4070: read: connection reset by peer" Feb 21 15:45:52 volumiostu systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:45:52 volumiostu systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 15:45:52 volumiostu volumio[2352]: info: go-librespot daemon successfully initialized Feb 21 15:45:55 volumiostu systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 21 15:45:55 volumiostu systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:45:55 volumiostu systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:45:55 volumiostu go-librespot[2658]: go-librespot daemon starting... Feb 21 15:45:55 volumiostu go-librespot[2659]: time="2026-02-21T15:45:55Z" level=info msg="running go-librespot 0.6.2" Feb 21 15:45:55 volumiostu go-librespot[2659]: time="2026-02-21T15:45:55Z" level=debug msg="app state loaded" Feb 21 15:45:55 volumiostu go-librespot[2659]: time="2026-02-21T15:45:55Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 15:45:55 volumiostu volumio[2352]: info: Initializing connection to go-librespot Websocket Feb 21 15:45:55 volumiostu go-librespot[2659]: time="2026-02-21T15:45:55Z" level=debug msg="new websocket client" Feb 21 15:45:55 volumiostu volumio[2352]: info: Connection to go-librespot Websocket established Feb 21 15:45:55 volumiostu go-librespot[2659]: time="2026-02-21T15:45:55Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 21 15:45:55 volumiostu go-librespot[2659]: time="2026-02-21T15:45:55Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 21 15:45:55 volumiostu go-librespot[2659]: time="2026-02-21T15:45:55Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 21 15:45:55 volumiostu go-librespot[2659]: time="2026-02-21T15:45:55Z" level=info msg="zeroconf server listening on port 38447" Feb 21 15:45:55 volumiostu go-librespot[2659]: time="2026-02-21T15:45:55Z" level=debug msg="obtained new client token: AAAxfV3KwaozJvad8dPpf/Y6w/B0zsqcJSk3wCxxruugzpgnikej1MkA3q4tfNaY15MsKfO5aNon48keMFnfbvyZ0Pak99Rj/JoeKBZpnYNS0YQ8TAJvcSFM9R4kPIHfMXMPs8iaV5ZdHa5LhmuOmDbDaHDf1vjcZGm9VgEEGBL/eAJPlnQ7w8NkaOOgDoUg4O+Iei1aIGawHeqpvigR/P+wFl7jLYOe6tMr/V2mnham5AUEviDPeZ2n" Feb 21 15:45:56 volumiostu go-librespot[2659]: time="2026-02-21T15:45:56Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:45:56 volumiostu go-librespot[2659]: time="2026-02-21T15:45:56Z" level=debug msg="completed keyexchange" Feb 21 15:45:56 volumiostu go-librespot[2659]: time="2026-02-21T15:45:56Z" level=debug msg="completed challenge" Feb 21 15:45:56 volumiostu go-librespot[2659]: time="2026-02-21T15:45:56Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 21 15:45:56 volumiostu volumio[2352]: info: Adding plugin bluetooth to MyMusic Plugins Feb 21 15:45:56 volumiostu volumio[2352]: info: Adding plugin multiroom to MyMusic Plugins Feb 21 15:45:56 volumiostu volumio[2352]: info: Adding plugin metavolumio to MyMusic Plugins Feb 21 15:45:56 volumiostu volumio[2352]: info: Adding plugin cd_controller to MyMusic Plugins Feb 21 15:45:56 volumiostu volumio[2352]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 21 15:45:56 volumiostu volumio[2352]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 21 15:45:56 volumiostu volumio[2352]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 21 15:45:56 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 21 15:45:56 volumiostu go-librespot[2659]: time="2026-02-21T15:45:56Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 21 15:45:56 volumiostu go-librespot[2659]: time="2026-02-21T15:45:56Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:36850->104.199.65.9:443: read: connection reset by peer" Feb 21 15:45:57 volumiostu go-librespot[2659]: time="2026-02-21T15:45:57Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 21 15:45:57 volumiostu go-librespot[2659]: time="2026-02-21T15:45:57Z" level=debug msg="completed keyexchange" Feb 21 15:45:57 volumiostu go-librespot[2659]: time="2026-02-21T15:45:57Z" level=debug msg="completed challenge" Feb 21 15:45:57 volumiostu go-librespot[2659]: time="2026-02-21T15:45:57Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:57 volumiostu go-librespot[2659]: time="2026-02-21T15:45:57Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 21 15:45:57 volumiostu go-librespot[2659]: time="2026-02-21T15:45:57Z" level=debug msg="completed keyexchange" Feb 21 15:45:57 volumiostu go-librespot[2659]: time="2026-02-21T15:45:57Z" level=debug msg="completed challenge" Feb 21 15:45:57 volumiostu volumio5-onboarding[2263]: failed to bootstrap state: failed to get music providers: could not get available plugins: could not get available plugins: context deadline exceeded Feb 21 15:45:57 volumiostu systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:45:57 volumiostu systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Feb 21 15:45:58 volumiostu go-librespot[2659]: time="2026-02-21T15:45:58Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:58 volumiostu systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 3. Feb 21 15:45:58 volumiostu systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 21 15:45:58 volumiostu systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 21 15:45:58 volumiostu volumio5-onboarding[2672]: time=2026-02-21T15:45:58.177Z level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Feb 21 15:45:58 volumiostu go-librespot[2659]: time="2026-02-21T15:45:58Z" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 21 15:45:58 volumiostu go-librespot[2659]: time="2026-02-21T15:45:58Z" level=debug msg="completed keyexchange" Feb 21 15:45:58 volumiostu go-librespot[2659]: time="2026-02-21T15:45:58Z" level=debug msg="completed challenge" Feb 21 15:45:58 volumiostu go-librespot[2659]: time="2026-02-21T15:45:58Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:45:59 volumiostu volumio[2352]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 21 15:45:59 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 21 15:45:59 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:59 volumiostu volumio[2352]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:45:59 volumiostu volumio[2352]: info: Starting MyVolumio Remote Streaming Endpoints Feb 21 15:45:59 volumiostu volumio[2352]: info: MyVolumio login type: Token Feb 21 15:45:59 volumiostu volumio[2352]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 21 15:45:59 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 21 15:45:59 volumiostu go-librespot[2659]: time="2026-02-21T15:45:59Z" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 21 15:45:59 volumiostu go-librespot[2659]: time="2026-02-21T15:45:59Z" level=debug msg="completed keyexchange" Feb 21 15:45:59 volumiostu go-librespot[2659]: time="2026-02-21T15:45:59Z" level=debug msg="completed challenge" Feb 21 15:46:00 volumiostu go-librespot[2659]: time="2026-02-21T15:46:00Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:00 volumiostu go-librespot[2659]: time="2026-02-21T15:46:00Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:00 volumiostu systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:46:00 volumiostu systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 15:46:01 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 21 15:46:01 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 21 15:46:01 volumiostu volumio[2352]: info: Streaming services startup Feb 21 15:46:01 volumiostu volumio[2352]: info: Starting Streaming Daemon Feb 21 15:46:02 volumiostu volumio[2352]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 21 15:46:02 volumiostu sudo[2691]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:02 volumiostu sudo[2691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 21 15:46:02 volumiostu sudo[2691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:02 volumiostu sudo[2691]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:02 volumiostu volumio[2352]: info: Getting Spotify volume Feb 21 15:46:02 volumiostu volumio[2352]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 15:46:02 volumiostu volumio[2352]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 15:46:02 volumiostu volumio[2352]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 21 15:46:02 volumiostu volumio[2352]: errno: -111, Feb 21 15:46:02 volumiostu volumio[2352]: code: 'ECONNREFUSED', Feb 21 15:46:02 volumiostu volumio[2352]: syscall: 'connect', Feb 21 15:46:02 volumiostu volumio[2352]: address: '127.0.0.1', Feb 21 15:46:02 volumiostu volumio[2352]: port: 9879, Feb 21 15:46:02 volumiostu volumio[2352]: response: undefined Feb 21 15:46:02 volumiostu volumio[2352]: } Feb 21 15:46:02 volumiostu volumio[2352]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 15:46:03 volumiostu systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 21 15:46:03 volumiostu systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:46:03 volumiostu systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:46:03 volumiostu go-librespot[2709]: go-librespot daemon starting... Feb 21 15:46:03 volumiostu go-librespot[2710]: time="2026-02-21T15:46:03Z" level=info msg="running go-librespot 0.6.2" Feb 21 15:46:03 volumiostu go-librespot[2710]: time="2026-02-21T15:46:03Z" level=debug msg="app state loaded" Feb 21 15:46:03 volumiostu go-librespot[2710]: time="2026-02-21T15:46:03Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 15:46:03 volumiostu go-librespot[2710]: time="2026-02-21T15:46:03Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 21 15:46:03 volumiostu go-librespot[2710]: time="2026-02-21T15:46:03Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 21 15:46:03 volumiostu go-librespot[2710]: time="2026-02-21T15:46:03Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 21 15:46:03 volumiostu go-librespot[2710]: time="2026-02-21T15:46:03Z" level=info msg="zeroconf server listening on port 36897" Feb 21 15:46:03 volumiostu go-librespot[2710]: time="2026-02-21T15:46:03Z" level=debug msg="obtained new client token: AADg1/nfuCkacazzQ2TE29K3f/KZfml+MOOd8YB4MST0mZdLGGyxGMY4VnJTg1+SmMLHrMas/pPlbIso+XCV4UAd90x1b/AksnAEQt0vlOfBn3mu47GCoxywwgyG7F2boR6UEflb3rLtHMXYfyPwq+iH6HXWUjqRnqfOMCy8kTF6lm5LbV5Nm0F3bnQAe+eNQW8s3u12eUoXzOKANOwNQYl3/8vgyvduaYuyFZBzE9FC8DcfpThi0ix/" Feb 21 15:46:03 volumiostu go-librespot[2710]: time="2026-02-21T15:46:03Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:46:03 volumiostu go-librespot[2710]: time="2026-02-21T15:46:03Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:44328->104.199.65.9:4070: read: connection reset by peer" Feb 21 15:46:04 volumiostu go-librespot[2710]: time="2026-02-21T15:46:04Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 21 15:46:04 volumiostu go-librespot[2710]: time="2026-02-21T15:46:04Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:36866->104.199.65.9:443: read: connection reset by peer" Feb 21 15:46:04 volumiostu go-librespot[2710]: time="2026-02-21T15:46:04Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 21 15:46:04 volumiostu go-librespot[2710]: time="2026-02-21T15:46:04Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:46136->104.199.65.9:80: read: connection reset by peer" Feb 21 15:46:04 volumiostu sudo[2721]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:04 volumiostu sudo[2721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-21 15:45' Feb 21 15:46:05 volumiostu sudo[2721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:05 volumiostu go-librespot[2710]: time="2026-02-21T15:46:05Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 21 15:46:05 volumiostu sudo[2721]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:05 volumiostu go-librespot[2710]: time="2026-02-21T15:46:05Z" level=debug msg="completed keyexchange" Feb 21 15:46:05 volumiostu go-librespot[2710]: time="2026-02-21T15:46:05Z" level=debug msg="completed challenge" Feb 21 15:46:05 volumiostu go-librespot[2710]: time="2026-02-21T15:46:05Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:05 volumiostu volumio[2352]: sudo: unable to resolve host volumiostu: System error Feb 21 15:46:05 volumiostu volumio5-onboarding[2672]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: read tcp 127.0.0.1:52044->127.0.0.1:3000: read: connection reset by peer Feb 21 15:46:05 volumiostu volumio-remote-updater[740]: [2026-02-21 15:46:05] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 21 15:46:05 volumiostu volumio-remote-updater[740]: [2026-02-21 15:46:05] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 21 15:46:05 volumiostu systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:46:05 volumiostu systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:46:05 volumiostu systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Feb 21 15:46:05 volumiostu systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 21 15:46:05 volumiostu systemd[1]: volumio.service: Consumed 1min 10.590s CPU time. Feb 21 15:46:06 volumiostu systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 21 15:46:06 volumiostu systemd[1]: dynamicswap.service: Deactivated successfully. Feb 21 15:46:06 volumiostu systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 4. Feb 21 15:46:06 volumiostu systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3. Feb 21 15:46:06 volumiostu systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 21 15:46:06 volumiostu systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 21 15:46:06 volumiostu systemd[1]: volumio.service: Consumed 1min 10.590s CPU time. Feb 21 15:46:06 volumiostu systemd[1]: Started volumio.service - Volumio Backend Module. Feb 21 15:46:06 volumiostu systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 21 15:46:06 volumiostu systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 21 15:46:06 volumiostu systemd[1]: dynamicswap.service: Deactivated successfully. Feb 21 15:46:06 volumiostu volumio5-onboarding[2740]: time=2026-02-21T15:46:06.129Z level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Feb 21 15:46:06 volumiostu volumio5-onboarding[2740]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: dial tcp 127.0.0.1:3000: connect: connection refused Feb 21 15:46:06 volumiostu systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:46:06 volumiostu systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Feb 21 15:46:06 volumiostu go-librespot[2710]: time="2026-02-21T15:46:06Z" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 21 15:46:06 volumiostu go-librespot[2710]: time="2026-02-21T15:46:06Z" level=debug msg="completed keyexchange" Feb 21 15:46:06 volumiostu go-librespot[2710]: time="2026-02-21T15:46:06Z" level=debug msg="completed challenge" Feb 21 15:46:06 volumiostu go-librespot[2710]: time="2026-02-21T15:46:06Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:06 volumiostu systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 5. Feb 21 15:46:06 volumiostu systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 21 15:46:06 volumiostu systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 21 15:46:06 volumiostu volumio5-onboarding[2759]: time=2026-02-21T15:46:06.482Z level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Feb 21 15:46:06 volumiostu volumio5-onboarding[2759]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: dial tcp 127.0.0.1:3000: connect: connection refused Feb 21 15:46:06 volumiostu systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:46:06 volumiostu systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Feb 21 15:46:06 volumiostu systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 6. Feb 21 15:46:06 volumiostu systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 21 15:46:06 volumiostu systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 21 15:46:06 volumiostu volumio5-onboarding[2765]: time=2026-02-21T15:46:06.865Z level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Feb 21 15:46:06 volumiostu volumio5-onboarding[2765]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: dial tcp 127.0.0.1:3000: connect: connection refused Feb 21 15:46:06 volumiostu systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:46:06 volumiostu systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Feb 21 15:46:07 volumiostu go-librespot[2710]: time="2026-02-21T15:46:07Z" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.241.202:80: connect: connection refused" Feb 21 15:46:07 volumiostu go-librespot[2710]: time="2026-02-21T15:46:07Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:46:07 volumiostu systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 7. Feb 21 15:46:07 volumiostu systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 21 15:46:07 volumiostu go-librespot[2710]: time="2026-02-21T15:46:07Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:45270->104.199.65.9:4070: read: connection reset by peer" Feb 21 15:46:07 volumiostu go-librespot[2710]: time="2026-02-21T15:46:07Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:45270->104.199.65.9:4070: read: connection reset by peer" Feb 21 15:46:07 volumiostu systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 21 15:46:07 volumiostu systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:46:07 volumiostu systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 15:46:07 volumiostu volumio5-onboarding[2773]: time=2026-02-21T15:46:07.166Z level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Feb 21 15:46:07 volumiostu volumio5-onboarding[2773]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: dial tcp 127.0.0.1:3000: connect: connection refused Feb 21 15:46:07 volumiostu systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:46:07 volumiostu systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Feb 21 15:46:07 volumiostu systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 8. Feb 21 15:46:07 volumiostu systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 21 15:46:07 volumiostu systemd[1]: volumio5-onboarding.service: Start request repeated too quickly. Feb 21 15:46:07 volumiostu systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Feb 21 15:46:07 volumiostu systemd[1]: Failed to start volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 21 15:46:08 volumiostu volumio[2736]: info: ------------------------------------------- Feb 21 15:46:08 volumiostu volumio[2736]: info: ----- Volumio3 ---- Feb 21 15:46:08 volumiostu volumio[2736]: info: ------------------------------------------- Feb 21 15:46:08 volumiostu volumio[2736]: info: ----- System startup ---- Feb 21 15:46:08 volumiostu volumio[2736]: info: ------------------------------------------- Feb 21 15:46:08 volumiostu volumio[2736]: info: MYVOLUMIO Environment detected Feb 21 15:46:09 volumiostu volumio[2736]: info: Plugin folders cleanup Feb 21 15:46:09 volumiostu volumio[2736]: info: Scanning into folder /volumio/app/plugins/ Feb 21 15:46:09 volumiostu volumio[2736]: info: Scanning category audio_interface Feb 21 15:46:09 volumiostu volumio[2736]: info: Scanning category miscellanea Feb 21 15:46:09 volumiostu volumio[2736]: info: Scanning category music_service Feb 21 15:46:09 volumiostu volumio[2736]: info: Scanning category plugins.json Feb 21 15:46:09 volumiostu volumio[2736]: info: Scanning category system_controller Feb 21 15:46:09 volumiostu volumio[2736]: info: Scanning category user_interface Feb 21 15:46:09 volumiostu volumio[2736]: info: Scanning into folder /data/plugins/ Feb 21 15:46:09 volumiostu volumio[2736]: info: Scanning category music_service Feb 21 15:46:09 volumiostu volumio[2736]: info: Scanning category user_interface Feb 21 15:46:09 volumiostu volumio[2736]: info: Plugin folders cleanup completed Feb 21 15:46:09 volumiostu volumio[2736]: info: ------------------------------------------- Feb 21 15:46:09 volumiostu volumio[2736]: info: ----- Core plugins startup ---- Feb 21 15:46:09 volumiostu volumio[2736]: info: ------------------------------------------- Feb 21 15:46:09 volumiostu volumio[2736]: info: Loading plugins from folder /volumio/app/plugins/ Feb 21 15:46:09 volumiostu volumio[2736]: info: Adding plugin upnp to MyMusic Plugins Feb 21 15:46:09 volumiostu volumio[2736]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 21 15:46:09 volumiostu volumio[2736]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 21 15:46:09 volumiostu volumio[2736]: info: Loading plugins from folder /data/plugins/ Feb 21 15:46:09 volumiostu volumio[2736]: info: Loading plugin "system"... Feb 21 15:46:09 volumiostu volumio[2736]: info: Loading plugin "appearance"... Feb 21 15:46:09 volumiostu volumio[2736]: info: Loading plugin "network"... Feb 21 15:46:09 volumiostu volumio[2736]: info: Refreshing Cached IP Addresses Feb 21 15:46:10 volumiostu sudo[2794]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:10 volumiostu sudo[2792]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:10 volumiostu volumio[2736]: info: Loading plugin "services"... Feb 21 15:46:10 volumiostu volumio[2736]: info: Loading plugin "volumio5onboarding"... Feb 21 15:46:10 volumiostu sudo[2792]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 21 15:46:10 volumiostu sudo[2792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:10 volumiostu sudo[2794]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 15:46:10 volumiostu sudo[2794]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:10 volumiostu sudo[2794]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:10 volumiostu sudo[2801]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:10 volumiostu sudo[2801]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 21 15:46:10 volumiostu sudo[2792]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:10 volumiostu sudo[2801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:10 volumiostu volumio[2736]: info: Loading plugin "alsa_controller"... Feb 21 15:46:10 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 15:46:10 volumiostu volumio[2736]: info: Loading plugin "wizard"... Feb 21 15:46:10 volumiostu volumio[2736]: info: Loading plugin "networkfs"... Feb 21 15:46:10 volumiostu volumio[2736]: info: Starting Udev Watcher for removable devices Feb 21 15:46:10 volumiostu volumio[2736]: info: Ignoring mount for partition: boot Feb 21 15:46:10 volumiostu volumio[2736]: info: Ignoring mount for partition: volumio Feb 21 15:46:10 volumiostu volumio[2736]: info: Ignoring mount for partition: volumio_data Feb 21 15:46:10 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 21 15:46:10 volumiostu volumio[2736]: info: Loading plugin "volumio_command_line_client"... Feb 21 15:46:10 volumiostu volumio[2736]: info: Loading plugin "upnp"... Feb 21 15:46:10 volumiostu volumio[2736]: info: [1771688770290] Starting Upmpd Daemon Feb 21 15:46:10 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 21 15:46:10 volumiostu volumio[2736]: info: Loading plugin "my_music"... Feb 21 15:46:10 volumiostu volumio[2736]: info: Loading plugin "mpd"... Feb 21 15:46:10 volumiostu systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 21 15:46:10 volumiostu systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:46:10 volumiostu go-librespot[2825]: go-librespot daemon starting... Feb 21 15:46:10 volumiostu systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:46:10 volumiostu go-librespot[2826]: time="2026-02-21T15:46:10Z" level=info msg="running go-librespot 0.6.2" Feb 21 15:46:10 volumiostu go-librespot[2826]: time="2026-02-21T15:46:10Z" level=debug msg="app state loaded" Feb 21 15:46:10 volumiostu go-librespot[2826]: time="2026-02-21T15:46:10Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 15:46:10 volumiostu go-librespot[2826]: time="2026-02-21T15:46:10Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 21 15:46:10 volumiostu go-librespot[2826]: time="2026-02-21T15:46:10Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 21 15:46:10 volumiostu go-librespot[2826]: time="2026-02-21T15:46:10Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 21 15:46:10 volumiostu go-librespot[2826]: time="2026-02-21T15:46:10Z" level=info msg="zeroconf server listening on port 42073" Feb 21 15:46:10 volumiostu volumio[2736]: info: Loading plugin "upnp_browser"... Feb 21 15:46:10 volumiostu volumio-remote-updater[740]: [2026-02-21 15:46:10] [connect] Successful connection Feb 21 15:46:10 volumiostu go-librespot[2826]: time="2026-02-21T15:46:10Z" level=debug msg="obtained new client token: AABTsjUbjVqyAAad8m5xc+kVrI8tAO8VSm+Eq8n7G7sQ5pmWZgCiAxOWSTLGgpHZ396DHsWWNX6dIpPL1xUFbIZCmXRLeuzQ0zTKU5XEwCEmSBwuqYyTxkY9oX/MviFvVIYv0lQPXcXDOuqjas0Cd3u/700HTTsab24Y/lP671sMsGm3+WsHZ5stgksHe1+fFbSWpQ3D3JHHN9WCW6VjKxfyFyIk7zcEFVi0wbYM7owVDkbkn55prNI3" Feb 21 15:46:11 volumiostu go-librespot[2826]: time="2026-02-21T15:46:11Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:46:11 volumiostu go-librespot[2826]: time="2026-02-21T15:46:11Z" level=debug msg="completed keyexchange" Feb 21 15:46:11 volumiostu go-librespot[2826]: time="2026-02-21T15:46:11Z" level=debug msg="completed challenge" Feb 21 15:46:11 volumiostu go-librespot[2826]: time="2026-02-21T15:46:11Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:11 volumiostu go-librespot[2826]: time="2026-02-21T15:46:11Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 21 15:46:12 volumiostu volumio[2736]: info: Starting UPNP Browser Feb 21 15:46:12 volumiostu volumio[2736]: info: Loading plugin "alarm-clock"... Feb 21 15:46:12 volumiostu volumio[2736]: info: Loading plugin "airplay_emulation"... Feb 21 15:46:12 volumiostu volumio[2736]: info: Starting Shairport Sync Feb 21 15:46:12 volumiostu volumio[2736]: info: Loading plugin "last_100"... Feb 21 15:46:12 volumiostu volumio[2736]: info: Loading plugin "webradio"... Feb 21 15:46:12 volumiostu volumio[2736]: info: Loading plugin "i2s_dacs"... Feb 21 15:46:12 volumiostu volumio[2736]: info: Loading plugin "volumiodiscovery"... Feb 21 15:46:12 volumiostu volumio[2736]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 21 15:46:12 volumiostu volumio[2736]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 15:46:12 volumiostu node[2736]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 21 15:46:12 volumiostu volumio[2736]: *** WARNING *** For more information see Feb 21 15:46:12 volumiostu volumio[2736]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 21 15:46:12 volumiostu volumio[2736]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 15:46:12 volumiostu volumio[2736]: *** WARNING *** For more information see Feb 21 15:46:12 volumiostu node[2736]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 15:46:12 volumiostu node[2736]: *** WARNING *** For more information see Feb 21 15:46:12 volumiostu node[2736]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 21 15:46:12 volumiostu node[2736]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 15:46:12 volumiostu node[2736]: *** WARNING *** For more information see Feb 21 15:46:12 volumiostu volumio[2736]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 21 15:46:12 volumiostu volumio[2736]: info: Discovery: Started advertising with name: Volumio_Stu Feb 21 15:46:12 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 21 15:46:12 volumiostu volumio[2736]: info: Loading plugin "spop"... Feb 21 15:46:13 volumiostu volumio[2736]: info: Plugin now_playing is not enabled Feb 21 15:46:13 volumiostu volumio[2736]: info: Loading plugin "outputs"... Feb 21 15:46:13 volumiostu volumio[2736]: info: Loading plugin "albumart"... Feb 21 15:46:13 volumiostu volumio[2736]: info: Plugin example_plugin is not enabled Feb 21 15:46:13 volumiostu volumio[2736]: info: Loading plugin "inputs"... Feb 21 15:46:13 volumiostu volumio[2736]: info: Loading plugin "updater_comm"... Feb 21 15:46:13 volumiostu sudo[2801]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:13 volumiostu volumio[2736]: info: Plugin mpdemulation is not enabled Feb 21 15:46:13 volumiostu volumio[2736]: info: Loading plugin "rest_api"... Feb 21 15:46:13 volumiostu volumio[2736]: info: Loading plugin "websocket"... Feb 21 15:46:13 volumiostu volumio[2736]: info: Starting Socket.io Server version 1.7.4 Feb 21 15:46:13 volumiostu volumio[2736]: info: Loading plugin "radio_paradise"... Feb 21 15:46:13 volumiostu volumio[2736]: info: Applying required configuration parameters for plugin radio_paradise Feb 21 15:46:13 volumiostu volumio[2736]: info: [1771688773886] [RadioParadise] API delay: 5 Feb 21 15:46:13 volumiostu volumio[2736]: info: Loading i18n strings for locale en Feb 21 15:46:13 volumiostu volumio[2736]: Updating browse sources language Feb 21 15:46:13 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:46:14 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 15:46:14 volumiostu volumio[2736]: info: CoreCommandRouter::initPlayerControls Feb 21 15:46:14 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:14 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:14 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:14 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:14 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:14 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:14 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:14 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:14 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 15:46:14 volumiostu volumio[2736]: Express server listening on port 3000 Feb 21 15:46:14 volumiostu volumio[2736]: [Metrics] WebUI: 6s 521.05ms Feb 21 15:46:14 volumiostu volumio[2837]: Forking 3 albumart workers Feb 21 15:46:14 volumiostu volumio[2736]: info: CoreStateMachine::resetVolumioState Feb 21 15:46:14 volumiostu volumio[2736]: info: CoreStateMachine::getcurrentVolume Feb 21 15:46:14 volumiostu volumio[2736]: info: CoreCommandRouter::volumioRetrievevolume Feb 21 15:46:14 volumiostu volumio[2736]: info: Volumio Network Manager: Network status updated: 2 Feb 21 15:46:15 volumiostu volumio-remote-updater[740]: [2026-02-21 15:46:15] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771688770 101 Feb 21 15:46:15 volumiostu volumio[2736]: 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 21 15:46:15 volumiostu volumio[2736]: info: VolumeController:: Volume=70 Mute =false Feb 21 15:46:15 volumiostu volumio[2736]: info: CoreStateMachine::pushState Feb 21 15:46:15 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:15 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 21 15:46:15 volumiostu volumio[2736]: info: CoreCommandRouter::volumioPushState Feb 21 15:46:15 volumiostu volumio[2736]: info: CoreStateMachine::updateTrackBlock Feb 21 15:46:15 volumiostu volumio[2736]: info: CorePlayQueue::getTrackBlock Feb 21 15:46:15 volumiostu volumio[2736]: info: CoreCommandRouter::volumioRetrievevolume Feb 21 15:46:15 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:46:15 volumiostu volumio[2736]: info: Reloading queue from file Feb 21 15:46:15 volumiostu volumio[2736]: info: CoreStateMachine::setRepeat true single undefined Feb 21 15:46:15 volumiostu volumio[2736]: info: CoreStateMachine::pushState Feb 21 15:46:15 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:15 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 21 15:46:15 volumiostu volumio[2736]: info: CoreCommandRouter::volumioPushState Feb 21 15:46:15 volumiostu volumio[2736]: info: CoreStateMachine::setRandom null Feb 21 15:46:15 volumiostu volumio[2736]: info: CoreStateMachine::pushState Feb 21 15:46:15 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:15 volumiostu volumio[2736]: info: CoreCommandRouter::volumioPushState Feb 21 15:46:15 volumiostu sudo[2889]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:15 volumiostu sudo[2889]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 21 15:46:15 volumiostu volumio[2736]: info: Setting Device type: Raspberry PI Feb 21 15:46:15 volumiostu sudo[2889]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:15 volumiostu sudo[2891]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:15 volumiostu sudo[2889]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:15 volumiostu sudo[2891]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 15:46:15 volumiostu sudo[2891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:15 volumiostu sudo[2891]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:16 volumiostu volumio[2736]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Feb 21 15:46:16 volumiostu volumio[2736]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03114 Feb 21 15:46:16 volumiostu volumio[2736]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Feb 21 15:46:16 volumiostu volumio[2736]: info: VolumeController:: Volume=70 Mute =false Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreStateMachine::pushState Feb 21 15:46:16 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::volumioPushState Feb 21 15:46:16 volumiostu volumio[2736]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.169 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/145.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Feb 21 15:46:16 volumiostu volumio[2736]: info: Discovery: adding 15a5d113-f4b7-4105-922c-74fc7b77d920 Feb 21 15:46:16 volumiostu volumio[2736]: info: Discovery: Found device Volumio_Stu Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:16 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:16 volumiostu volumio[2736]: info: Discovery: this is already registered, 15a5d113-f4b7-4105-922c-74fc7b77d920 Feb 21 15:46:16 volumiostu volumio[2736]: info: Discovery: Found device Volumio_Stu Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:16 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:16 volumiostu volumio[2736]: info: Completed loading Core Plugins Feb 21 15:46:16 volumiostu volumio[2736]: info: Preparing to generate the ALSA configuration file Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:16 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:16 volumiostu volumio[2736]: info: Received Get System Info Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:46:16 volumiostu volumio[2736]: info: Discovery: Getting this device information Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:16 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:16 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetVisibleSources Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:16 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:16 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 21 15:46:16 volumiostu volumio[2736]: info: Received Get System Info Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:46:16 volumiostu volumio[2736]: info: Discovery: Getting this device information Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:16 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:16 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:16 volumiostu volumio[2736]: info: Listing playlists Feb 21 15:46:16 volumiostu volumio[2736]: info: Received Get System Info Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:46:16 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:46:17 volumiostu volumio[2736]: info: Discovery: Getting this device information Feb 21 15:46:17 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:17 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:17 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:46:17 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:17 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:17 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:17 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:17 volumiostu volumio[2736]: info: Asound.conf file unchanged, so no further update is needed Feb 21 15:46:17 volumiostu volumio[2736]: info: Output device has changed, restarting MPD Feb 21 15:46:17 volumiostu volumio[2736]: info: Output device has changed, restarting Shairport Sync Feb 21 15:46:17 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:17 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:46:17 volumiostu sudo[2901]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:17 volumiostu sudo[2901]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 21 15:46:17 volumiostu sudo[2901]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:17 volumiostu sudo[2901]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:17 volumiostu sudo[2903]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:17 volumiostu sudo[2903]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 21 15:46:17 volumiostu sudo[2903]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:17 volumiostu volumio[2736]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 15:46:17 volumiostu volumio[2736]: info: ___________ START PLUGINS ___________ Feb 21 15:46:17 volumiostu volumio[2736]: info: ControllerMpd::onStart: Initializing MPD Feb 21 15:46:17 volumiostu volumio[2736]: info: Creating MPD Configuration file Feb 21 15:46:17 volumiostu systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 21 15:46:17 volumiostu systemd[1]: mpd.service: Deactivated successfully. Feb 21 15:46:17 volumiostu systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 21 15:46:17 volumiostu systemd[1]: mpd.service: Consumed 1.481s CPU time. Feb 21 15:46:17 volumiostu systemd[1]: mpd.socket: Deactivated successfully. Feb 21 15:46:17 volumiostu systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 21 15:46:17 volumiostu systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 21 15:46:17 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 15:46:17 volumiostu volumio[2736]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 15:46:18 volumiostu systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 21 15:46:18 volumiostu systemd[1]: Starting mpd.service - Music Player Daemon... Feb 21 15:46:18 volumiostu volumio[2736]: info: [1771688777997] CoreMusicLibrary::Adding element Media Servers Feb 21 15:46:18 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:46:18 volumiostu sudo[2911]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:18 volumiostu sudo[2911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Feb 21 15:46:18 volumiostu sudo[2913]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:18 volumiostu volumio[2736]: info: UPNP Browser: Client initialized successfully Feb 21 15:46:18 volumiostu sudo[2913]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 21 15:46:18 volumiostu sudo[2913]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:18 volumiostu sudo[2916]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:18 volumiostu sudo[2913]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:18 volumiostu sudo[2911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:18 volumiostu sudo[2917]: root : unable to resolve host volumiostu: System error Feb 21 15:46:18 volumiostu sudo[2917]: sudo: unable to resolve host volumiostu: System error Feb 21 15:46:18 volumiostu sudo[2917]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 21 15:46:18 volumiostu sudo[2917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 21 15:46:18 volumiostu sudo[2916]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 21 15:46:18 volumiostu sudo[2916]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:18 volumiostu sudo[2917]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:18 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:18 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:46:18 volumiostu systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 21 15:46:18 volumiostu sudo[2911]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:18 volumiostu volumio5-onboarding[2927]: time=2026-02-21T15:46:18.356Z level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Feb 21 15:46:18 volumiostu systemd[1]: mpd.service: Deactivated successfully. Feb 21 15:46:18 volumiostu systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 21 15:46:18 volumiostu systemd[1]: mpd.socket: Deactivated successfully. Feb 21 15:46:18 volumiostu volumio[2736]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 15:46:18 volumiostu systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 21 15:46:18 volumiostu systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 21 15:46:18 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:18 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:46:18 volumiostu systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 21 15:46:18 volumiostu systemd[1]: Starting mpd.service - Music Player Daemon... Feb 21 15:46:18 volumiostu sudo[2935]: root : unable to resolve host volumiostu: System error Feb 21 15:46:18 volumiostu sudo[2935]: sudo: unable to resolve host volumiostu: System error Feb 21 15:46:18 volumiostu sudo[2935]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 21 15:46:18 volumiostu sudo[2935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 21 15:46:18 volumiostu sudo[2935]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:18 volumiostu volumio[2736]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 15:46:18 volumiostu volumio[2736]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 15:46:18 volumiostu volumio[2736]: info: [1771688778572] CoreMusicLibrary::Adding element Last_100 Feb 21 15:46:18 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:46:18 volumiostu volumio[2736]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 15:46:18 volumiostu volumio[2736]: info: [1771688778575] CoreMusicLibrary::Adding element Webradio Feb 21 15:46:18 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:46:18 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 15:46:18 volumiostu volumio[2736]: info: Initializing BBC Radios Feb 21 15:46:19 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 15:46:19 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:46:19 volumiostu volumio[2736]: info: Creating Spotify config file Feb 21 15:46:19 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:19 volumiostu mpd[2940]: 2026-02-21T15:46:19 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 21 15:46:20 volumiostu systemd[1]: Started mpd.service - Music Player Daemon. Feb 21 15:46:20 volumiostu sudo[2916]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:20 volumiostu sudo[2903]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:20 volumiostu volumio[2850]: Starting albumart workers Feb 21 15:46:20 volumiostu volumio[2853]: Starting albumart workers Feb 21 15:46:20 volumiostu volumio[2852]: Starting albumart workers Feb 21 15:46:20 volumiostu volumio[2736]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 15:46:20 volumiostu volumio[2736]: info: [1771688780787] CoreMusicLibrary::Adding element Radio Paradise Feb 21 15:46:20 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:46:20 volumiostu volumio[2736]: Cannot find translation for source Radio Paradise Feb 21 15:46:20 volumiostu volumio[2736]: info: Volumio Calling Home Feb 21 15:46:22 volumiostu sudo[2974]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:22 volumiostu sudo[2976]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:22 volumiostu sudo[2974]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 21 15:46:22 volumiostu sudo[2974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:22 volumiostu sudo[2976]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 15:46:22 volumiostu sudo[2974]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:22 volumiostu sudo[2976]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:22 volumiostu sudo[2976]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:22 volumiostu volumio[2736]: error: Upnp client error: Error: This socket has been ended by the other party Feb 21 15:46:22 volumiostu volumio[2736]: info: MPD Permissions set Feb 21 15:46:22 volumiostu volumio[2736]: info: Completed starting Core Plugins Feb 21 15:46:22 volumiostu volumio[2736]: info: ------------------------------------------- Feb 21 15:46:22 volumiostu volumio[2736]: info: ----- MyVolumio plugins startup ---- Feb 21 15:46:22 volumiostu volumio[2736]: info: ------------------------------------------- Feb 21 15:46:22 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 21 15:46:22 volumiostu volumio[2736]: info: MPD Permissions set Feb 21 15:46:23 volumiostu volumio[2736]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Feb 21 15:46:23 volumiostu volumio[2736]: info: Volumio called home Feb 21 15:46:23 volumiostu volumio[2736]: info: Spotify config file written Feb 21 15:46:23 volumiostu sudo[3005]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:23 volumiostu sudo[3005]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 21 15:46:23 volumiostu sudo[3005]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:23 volumiostu systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 21 15:46:23 volumiostu systemd[1]: go-librespot-daemon.service: Killing process 2834 (go-librespot) with signal SIGKILL. Feb 21 15:46:23 volumiostu systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 21 15:46:23 volumiostu systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:46:23 volumiostu systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:46:23 volumiostu go-librespot[3007]: go-librespot daemon starting... Feb 21 15:46:23 volumiostu sudo[3005]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:23 volumiostu go-librespot[3008]: time="2026-02-21T15:46:23Z" level=info msg="running go-librespot 0.6.2" Feb 21 15:46:23 volumiostu go-librespot[3008]: time="2026-02-21T15:46:23Z" level=debug msg="app state loaded" Feb 21 15:46:23 volumiostu go-librespot[3008]: time="2026-02-21T15:46:23Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 15:46:23 volumiostu volumio[2736]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Feb 21 15:46:23 volumiostu volumio[2736]: info: Received Get System Info Feb 21 15:46:23 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:46:23 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:46:23 volumiostu volumio[2736]: info: Discovery: Getting this device information Feb 21 15:46:23 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:23 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:23 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:46:23 volumiostu go-librespot[3008]: time="2026-02-21T15:46:23Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 15:46:23 volumiostu go-librespot[3008]: time="2026-02-21T15:46:23Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 15:46:23 volumiostu go-librespot[3008]: time="2026-02-21T15:46:23Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 15:46:23 volumiostu volumio5-onboarding[2927]: time=2026-02-21T15:46:23.883Z level=INFO msg="system info for c548e4720a9caac822872f820532ef56" deviceName=Volumio_Stu deviceVariant=volumio deviceModel= softwareVersion=4.096 Feb 21 15:46:23 volumiostu go-librespot[3008]: time="2026-02-21T15:46:23Z" level=info msg="zeroconf server listening on port 39205" Feb 21 15:46:23 volumiostu go-librespot[3008]: time="2026-02-21T15:46:23Z" level=debug msg="obtained new client token: AADmPP7FYHZ3ZnXnHquoV0wV34YGMzLDa4ptCa8zpj4t89R6qYlGP3YzRW/Dxk+smbPzYXW7K/FudraIbMiWizEURnbKawetC9Hn0fB88lp9EuQ42b6LjXkBWeQHttP4XiOK1J6xgGrBZFjHCcOQMdC/oxzAEQOGj5Wsk3P+zE/IZW3B4m5DXdKF+x81Gg4w44Z1kXKlHne4JVgroybEonXzfAS2RIXtEvKQGrjUSr9F5E8J3+HW6zPB" Feb 21 15:46:23 volumiostu go-librespot[3008]: time="2026-02-21T15:46:23Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:46:23 volumiostu go-librespot[3008]: time="2026-02-21T15:46:23Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 21 15:46:24 volumiostu volumio[2736]: error: MPD error: The expression evaluated to a falsy value: Feb 21 15:46:24 volumiostu volumio[2736]: assert.ok(self.idling) Feb 21 15:46:24 volumiostu volumio[2736]: error: The expression evaluated to a falsy value: Feb 21 15:46:24 volumiostu volumio[2736]: assert.ok(self.idling) Feb 21 15:46:24 volumiostu volumio[2736]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Feb 21 15:46:24 volumiostu volumio[2736]: info: MPD running with PID2940 Feb 21 15:46:24 volumiostu volumio[2736]: ,establishing connection Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:46:24 volumiostu volumio[2736]: info: No need to fix Spotify hosts Feb 21 15:46:24 volumiostu go-librespot[3008]: time="2026-02-21T15:46:24Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 21 15:46:24 volumiostu go-librespot[3008]: time="2026-02-21T15:46:24Z" level=debug msg="completed keyexchange" Feb 21 15:46:24 volumiostu go-librespot[3008]: time="2026-02-21T15:46:24Z" level=debug msg="completed challenge" Feb 21 15:46:24 volumiostu go-librespot[3008]: time="2026-02-21T15:46:24Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:24 volumiostu volumio[2736]: info: Received Get System Info Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:46:24 volumiostu volumio[2736]: info: Discovery: Getting this device information Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:24 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:46:24 volumiostu volumio[2736]: error: updateQueue error: null Feb 21 15:46:24 volumiostu volumio[2736]: info: New Spotify access tokenBQBj9vChXM... Feb 21 15:46:24 volumiostu volumio[2736]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 21 15:46:24 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 21 15:46:24 volumiostu volumio5-onboarding[2927]: time=2026-02-21T15:46:24.837Z level=INFO msg="enabling local network discovery" Feb 21 15:46:24 volumiostu volumio[2736]: error: updateQueue error: null Feb 21 15:46:24 volumiostu volumio5-onboarding[2927]: time=2026-02-21T15:46:24.862Z level=INFO msg="bootstrapping state" hasInternet=true Feb 21 15:46:24 volumiostu volumio[2736]: info: Starting Shairport Sync Feb 21 15:46:24 volumiostu volumio[2736]: info: Starting Shairport Sync Feb 21 15:46:24 volumiostu volumio[2736]: info: Starting Shairport Sync Feb 21 15:46:24 volumiostu sudo[3031]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:25 volumiostu sudo[3031]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 15:46:25 volumiostu sudo[3031]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:25 volumiostu volumio[2736]: info: Received Get System Info Feb 21 15:46:25 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:46:25 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:46:25 volumiostu volumio[2736]: info: Discovery: Getting this device information Feb 21 15:46:25 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:25 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:25 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:46:25 volumiostu sudo[3033]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:25 volumiostu sudo[3037]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:25 volumiostu sudo[3037]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 21 15:46:25 volumiostu sudo[3037]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:25 volumiostu sudo[3033]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 15:46:25 volumiostu sudo[3033]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:25 volumiostu sudo[3035]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:25 volumiostu go-librespot[3008]: time="2026-02-21T15:46:25Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 21 15:46:25 volumiostu systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 21 15:46:25 volumiostu go-librespot[3008]: time="2026-02-21T15:46:25Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:36066->104.199.65.9:80: read: connection reset by peer" Feb 21 15:46:25 volumiostu systemd[1]: shairport-sync.service: Deactivated successfully. Feb 21 15:46:25 volumiostu systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 15:46:25 volumiostu systemd[1]: shairport-sync.service: Consumed 1.679s CPU time. Feb 21 15:46:25 volumiostu sudo[3035]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 15:46:25 volumiostu volumio-remote-updater[740]: Test mode disabled Feb 21 15:46:25 volumiostu volumio-remote-updater[740]: Alpha mode disabled Feb 21 15:46:25 volumiostu volumio-remote-updater[740]: Alpha legacy test mode disabled Feb 21 15:46:25 volumiostu sudo[3035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:25 volumiostu systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 15:46:25 volumiostu systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 21 15:46:25 volumiostu systemd[1]: shairport-sync.service: Deactivated successfully. Feb 21 15:46:25 volumiostu systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 15:46:25 volumiostu systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 15:46:25 volumiostu sudo[3031]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:25 volumiostu systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 21 15:46:25 volumiostu systemd[1]: shairport-sync.service: Deactivated successfully. Feb 21 15:46:25 volumiostu systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 15:46:25 volumiostu sudo[3037]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:25 volumiostu systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 15:46:25 volumiostu sudo[3033]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:25 volumiostu sudo[3035]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:25 volumiostu volumio[2736]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 21 15:46:25 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 21 15:46:25 volumiostu volumio[2736]: info: Shairport-Sync Started Feb 21 15:46:25 volumiostu volumio[2736]: Error adding Membership: Error: addMembership EINVAL Feb 21 15:46:25 volumiostu volumio[2736]: info: Shairport-Sync Started Feb 21 15:46:25 volumiostu volumio[2736]: info: Shairport-Sync Started Feb 21 15:46:25 volumiostu volumio[2736]: info: Upmpdcli Daemon Started Feb 21 15:46:25 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 21 15:46:25 volumiostu volumio5-onboarding[2927]: time=2026-02-21T15:46:25.469Z level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Feb 21 15:46:25 volumiostu volumio5-onboarding[2927]: time=2026-02-21T15:46:25.471Z level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Feb 21 15:46:25 volumiostu volumio5-onboarding[2927]: time=2026-02-21T15:46:25.472Z level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Feb 21 15:46:25 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 21 15:46:25 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:25 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:25 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 21 15:46:25 volumiostu volumio[2736]: SPOTIFY: User informations: {"country":"BD","display_name":"Maruf","email":"sclements@brainleaked.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/317bbenxuzjt6r76dfjeh6lz7uwi"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/317bbenxuzjt6r76dfjeh6lz7uwi","id":"317bbenxuzjt6r76dfjeh6lz7uwi","images":[],"product":"premium","type":"user","uri":"spotify:user:317bbenxuzjt6r76dfjeh6lz7uwi"} Feb 21 15:46:25 volumiostu volumio[2736]: info: Spotify Successfully logged in Feb 21 15:46:25 volumiostu volumio[2736]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 15:46:25 volumiostu volumio[2736]: info: [1771688785707] CoreMusicLibrary::Adding element Spotify Feb 21 15:46:25 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:46:25 volumiostu volumio[2736]: Cannot find translation for source Radio Paradise Feb 21 15:46:25 volumiostu volumio[2736]: Cannot find translation for source Spotify Feb 21 15:46:25 volumiostu go-librespot[3008]: time="2026-02-21T15:46:25Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 21 15:46:25 volumiostu go-librespot[3008]: time="2026-02-21T15:46:25Z" level=debug msg="completed keyexchange" Feb 21 15:46:25 volumiostu go-librespot[3008]: time="2026-02-21T15:46:25Z" level=debug msg="completed challenge" Feb 21 15:46:25 volumiostu go-librespot[3008]: time="2026-02-21T15:46:25Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:26 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Feb 21 15:46:26 volumiostu go-librespot[3008]: time="2026-02-21T15:46:26Z" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 21 15:46:26 volumiostu go-librespot[3008]: time="2026-02-21T15:46:26Z" level=debug msg="completed keyexchange" Feb 21 15:46:26 volumiostu go-librespot[3008]: time="2026-02-21T15:46:26Z" level=debug msg="completed challenge" Feb 21 15:46:26 volumiostu go-librespot[3008]: time="2026-02-21T15:46:26Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:27 volumiostu go-librespot[3008]: time="2026-02-21T15:46:27Z" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 21 15:46:27 volumiostu go-librespot[3008]: time="2026-02-21T15:46:27Z" level=debug msg="completed keyexchange" Feb 21 15:46:27 volumiostu go-librespot[3008]: time="2026-02-21T15:46:27Z" level=debug msg="completed challenge" Feb 21 15:46:27 volumiostu go-librespot[3008]: time="2026-02-21T15:46:27Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:27 volumiostu go-librespot[3008]: time="2026-02-21T15:46:27Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:27 volumiostu systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:46:27 volumiostu systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 15:46:27 volumiostu volumio[2736]: info: go-librespot daemon successfully initialized Feb 21 15:46:29 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 21 15:46:30 volumiostu systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 21 15:46:30 volumiostu systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:46:30 volumiostu go-librespot[3078]: go-librespot daemon starting... Feb 21 15:46:30 volumiostu systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:46:30 volumiostu go-librespot[3079]: time="2026-02-21T15:46:30Z" level=info msg="running go-librespot 0.6.2" Feb 21 15:46:30 volumiostu go-librespot[3079]: time="2026-02-21T15:46:30Z" level=debug msg="app state loaded" Feb 21 15:46:30 volumiostu go-librespot[3079]: time="2026-02-21T15:46:30Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 15:46:30 volumiostu volumio[2736]: info: Initializing connection to go-librespot Websocket Feb 21 15:46:30 volumiostu go-librespot[3079]: time="2026-02-21T15:46:30Z" level=debug msg="new websocket client" Feb 21 15:46:30 volumiostu volumio[2736]: info: Connection to go-librespot Websocket established Feb 21 15:46:30 volumiostu go-librespot[3079]: time="2026-02-21T15:46:30Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 15:46:30 volumiostu go-librespot[3079]: time="2026-02-21T15:46:30Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 15:46:30 volumiostu go-librespot[3079]: time="2026-02-21T15:46:30Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 15:46:30 volumiostu go-librespot[3079]: time="2026-02-21T15:46:30Z" level=info msg="zeroconf server listening on port 41165" Feb 21 15:46:31 volumiostu go-librespot[3079]: time="2026-02-21T15:46:31Z" level=debug msg="obtained new client token: AAABd+JpaOoLRLrCcJ0HnonZR/GLhi43Nu3OMofrRgY33yE9PS1ZHOZcVCrAU5OQp7dGR5EZ/jtRJYsRH9Bp+4ZjbSAEr1pa4zRhlpj0wH528FyMwYAf4AsFw+qx/23NeyU0mcXA1NQToZyMLBrMOGHCy+6ZoDCSqBlsiT37GsOc0ePVkS5hNRHWkb645fSuLd0kPcWdwyMT/m2PaKdd9lmNO+veErINanmMzPH3Bn0tnH6IwtFPbgK+" Feb 21 15:46:31 volumiostu go-librespot[3079]: time="2026-02-21T15:46:31Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Feb 21 15:46:31 volumiostu go-librespot[3079]: time="2026-02-21T15:46:31Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 21 15:46:31 volumiostu go-librespot[3079]: time="2026-02-21T15:46:31Z" level=debug msg="completed keyexchange" Feb 21 15:46:31 volumiostu go-librespot[3079]: time="2026-02-21T15:46:31Z" level=debug msg="completed challenge" Feb 21 15:46:31 volumiostu go-librespot[3079]: time="2026-02-21T15:46:31Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 21 15:46:31 volumiostu volumio[2736]: info: Adding plugin bluetooth to MyMusic Plugins Feb 21 15:46:31 volumiostu volumio[2736]: info: Adding plugin multiroom to MyMusic Plugins Feb 21 15:46:31 volumiostu volumio[2736]: info: Adding plugin metavolumio to MyMusic Plugins Feb 21 15:46:31 volumiostu volumio[2736]: info: Adding plugin cd_controller to MyMusic Plugins Feb 21 15:46:31 volumiostu volumio[2736]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 21 15:46:31 volumiostu volumio[2736]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 21 15:46:31 volumiostu volumio[2736]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 21 15:46:31 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 21 15:46:31 volumiostu go-librespot[3079]: time="2026-02-21T15:46:31Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 21 15:46:31 volumiostu go-librespot[3079]: time="2026-02-21T15:46:31Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:48314->104.199.65.9:80: read: connection reset by peer" Feb 21 15:46:32 volumiostu go-librespot[3079]: time="2026-02-21T15:46:32Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 21 15:46:32 volumiostu go-librespot[3079]: time="2026-02-21T15:46:32Z" level=debug msg="completed keyexchange" Feb 21 15:46:32 volumiostu go-librespot[3079]: time="2026-02-21T15:46:32Z" level=debug msg="completed challenge" Feb 21 15:46:32 volumiostu go-librespot[3079]: time="2026-02-21T15:46:32Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:33 volumiostu go-librespot[3079]: time="2026-02-21T15:46:33Z" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 21 15:46:33 volumiostu go-librespot[3079]: time="2026-02-21T15:46:33Z" level=debug msg="completed keyexchange" Feb 21 15:46:33 volumiostu go-librespot[3079]: time="2026-02-21T15:46:33Z" level=debug msg="completed challenge" Feb 21 15:46:33 volumiostu go-librespot[3079]: time="2026-02-21T15:46:33Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:33 volumiostu go-librespot[3079]: time="2026-02-21T15:46:33Z" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 21 15:46:33 volumiostu go-librespot[3079]: time="2026-02-21T15:46:33Z" level=debug msg="completed keyexchange" Feb 21 15:46:33 volumiostu go-librespot[3079]: time="2026-02-21T15:46:33Z" level=debug msg="completed challenge" Feb 21 15:46:33 volumiostu go-librespot[3079]: time="2026-02-21T15:46:33Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:34 volumiostu go-librespot[3079]: time="2026-02-21T15:46:34Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:46:34 volumiostu go-librespot[3079]: time="2026-02-21T15:46:34Z" level=debug msg="completed keyexchange" Feb 21 15:46:34 volumiostu go-librespot[3079]: time="2026-02-21T15:46:34Z" level=debug msg="completed challenge" Feb 21 15:46:34 volumiostu go-librespot[3079]: time="2026-02-21T15:46:34Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:34 volumiostu go-librespot[3079]: time="2026-02-21T15:46:34Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:34 volumiostu systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:46:34 volumiostu systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 15:46:34 volumiostu volumio[2736]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 21 15:46:34 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 21 15:46:34 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:46:34 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:46:34 volumiostu volumio[2736]: info: Starting MyVolumio Remote Streaming Endpoints Feb 21 15:46:34 volumiostu volumio[2736]: info: MyVolumio login type: Token Feb 21 15:46:34 volumiostu volumio[2736]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 21 15:46:34 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 21 15:46:37 volumiostu systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 21 15:46:37 volumiostu systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:46:37 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 21 15:46:37 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 21 15:46:37 volumiostu volumio[2736]: info: Streaming services startup Feb 21 15:46:37 volumiostu volumio[2736]: info: Starting Streaming Daemon Feb 21 15:46:37 volumiostu go-librespot[3090]: go-librespot daemon starting... Feb 21 15:46:37 volumiostu systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:46:37 volumiostu go-librespot[3091]: time="2026-02-21T15:46:37Z" level=info msg="running go-librespot 0.6.2" Feb 21 15:46:37 volumiostu go-librespot[3091]: time="2026-02-21T15:46:37Z" level=debug msg="app state loaded" Feb 21 15:46:37 volumiostu go-librespot[3091]: time="2026-02-21T15:46:37Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 15:46:37 volumiostu sudo[3097]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:38 volumiostu sudo[3097]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 21 15:46:38 volumiostu sudo[3097]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:38 volumiostu volumio[2736]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 21 15:46:38 volumiostu go-librespot[3091]: time="2026-02-21T15:46:38Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 15:46:38 volumiostu go-librespot[3091]: time="2026-02-21T15:46:38Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 15:46:38 volumiostu go-librespot[3091]: time="2026-02-21T15:46:38Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 15:46:38 volumiostu go-librespot[3091]: time="2026-02-21T15:46:38Z" level=info msg="zeroconf server listening on port 34771" Feb 21 15:46:38 volumiostu sudo[3097]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:38 volumiostu go-librespot[3091]: time="2026-02-21T15:46:38Z" level=debug msg="obtained new client token: AACf8urOT2gWDZpR4LtnG9B+EKahzoSKJttbKkz5nV61oypb/xI1wRkOrJ54BXpv5NIZ8DiZBiDLDax1Wfzv7MociWGnWsr7PZYUq22IHP51/nvaQh5a4H5FzcWW+IRuhp1PyyzxqeexYj1x3BGq3/EXFDyd3NMpwskuYsVOUXJ37LM5hUf3Cy1tCd3LL2ouLQm2RYb7NQYPZ25EJpY4XCVgv/QI2E2DLzw/eK9Ci+BR3OOeWbRM1g==" Feb 21 15:46:38 volumiostu go-librespot[3091]: time="2026-02-21T15:46:38Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:46:38 volumiostu volumio[2736]: info: Getting Spotify volume Feb 21 15:46:38 volumiostu volumio[2736]: info: Connection to go-librespot Websocket closed Feb 21 15:46:38 volumiostu go-librespot[3091]: time="2026-02-21T15:46:38Z" level=debug msg="completed keyexchange" Feb 21 15:46:38 volumiostu go-librespot[3091]: time="2026-02-21T15:46:38Z" level=debug msg="completed challenge" Feb 21 15:46:38 volumiostu volumio[2736]: error: Cannot start Volumio Streaming Daemon Feb 21 15:46:38 volumiostu volumio[2736]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 21 15:46:38 volumiostu volumio[2736]: sudo: unable to resolve host volumiostu: System error Feb 21 15:46:38 volumiostu volumio[2736]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 21 15:46:38 volumiostu go-librespot[3091]: time="2026-02-21T15:46:38Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:38 volumiostu sudo[3109]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:38 volumiostu sudo[3109]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 15:46:38 volumiostu sudo[3110]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:38 volumiostu sudo[3110]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 21 15:46:38 volumiostu sudo[3109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:38 volumiostu sudo[3110]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:38 volumiostu sudo[3110]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:38 volumiostu sudo[3109]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:38 volumiostu volumio[2736]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Feb 21 15:46:39 volumiostu go-librespot[3091]: time="2026-02-21T15:46:39Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 21 15:46:39 volumiostu go-librespot[3091]: time="2026-02-21T15:46:39Z" level=debug msg="completed keyexchange" Feb 21 15:46:39 volumiostu go-librespot[3091]: time="2026-02-21T15:46:39Z" level=debug msg="completed challenge" Feb 21 15:46:39 volumiostu go-librespot[3091]: time="2026-02-21T15:46:39Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:39 volumiostu volumio[2736]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.169 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/145.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:39 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:39 volumiostu go-librespot[3091]: time="2026-02-21T15:46:39Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 21 15:46:39 volumiostu go-librespot[3091]: time="2026-02-21T15:46:39Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:46240->104.199.65.9:80: read: connection reset by peer" Feb 21 15:46:39 volumiostu volumio[2736]: info: Received Get System Info Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:46:39 volumiostu volumio[2736]: info: Discovery: Getting this device information Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:39 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:39 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:39 volumiostu volumio[2736]: info: Received Get System Info Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:46:39 volumiostu volumio[2736]: info: Discovery: Getting this device information Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:39 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:39 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetVisibleSources Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:39 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:39 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 21 15:46:39 volumiostu volumio[2736]: info: Received Get System Info Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:46:39 volumiostu volumio[2736]: info: Discovery: Getting this device information Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:39 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:46:39 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:39 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:40 volumiostu volumio[2736]: info: Listing playlists Feb 21 15:46:40 volumiostu volumio[2736]: info: Received Get System Info Feb 21 15:46:40 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:46:40 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:46:40 volumiostu volumio[2736]: info: Discovery: Getting this device information Feb 21 15:46:40 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:40 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:40 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:46:40 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:40 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:40 volumiostu go-librespot[3091]: time="2026-02-21T15:46:40Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 21 15:46:40 volumiostu sudo[3115]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:40 volumiostu sudo[3115]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 21 15:46:40 volumiostu sudo[3117]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:40 volumiostu sudo[3115]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:40 volumiostu sudo[3117]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 15:46:40 volumiostu sudo[3117]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:40 volumiostu sudo[3115]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:40 volumiostu sudo[3117]: pam_unix(sudo:session): session closed for user root Feb 21 15:46:40 volumiostu go-librespot[3091]: time="2026-02-21T15:46:40Z" level=debug msg="completed keyexchange" Feb 21 15:46:40 volumiostu go-librespot[3091]: time="2026-02-21T15:46:40Z" level=debug msg="completed challenge" Feb 21 15:46:40 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Feb 21 15:46:40 volumiostu go-librespot[3091]: time="2026-02-21T15:46:40Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:40 volumiostu volumio[2736]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 21 15:46:40 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:40 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:41 volumiostu go-librespot[3091]: time="2026-02-21T15:46:41Z" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Feb 21 15:46:41 volumiostu go-librespot[3091]: time="2026-02-21T15:46:41Z" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 21 15:46:41 volumiostu volumio[2736]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.169 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/145.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Feb 21 15:46:41 volumiostu go-librespot[3091]: time="2026-02-21T15:46:41Z" level=debug msg="completed keyexchange" Feb 21 15:46:41 volumiostu go-librespot[3091]: time="2026-02-21T15:46:41Z" level=debug msg="completed challenge" Feb 21 15:46:41 volumiostu go-librespot[3091]: time="2026-02-21T15:46:41Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:41 volumiostu volumio[2736]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Feb 21 15:46:41 volumiostu volumio[2736]: SPOTIFY: SPOTIFY VOLUME undefined Feb 21 15:46:41 volumiostu volumio[2736]: SPOTIFY: VOLUMIO VOLUME 70 Feb 21 15:46:41 volumiostu volumio[2736]: info: Aligning Spotify Volume to Volumio Volume Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:41 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:41 volumiostu volumio[2736]: info: Setting Spotify Volume from Volumio: 70 Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:41 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:41 volumiostu volumio[2736]: info: Initializing connection to go-librespot Websocket Feb 21 15:46:41 volumiostu volumio[2736]: info: Received Get System Info Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:46:41 volumiostu volumio[2736]: info: Discovery: Getting this device information Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:41 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:41 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:41 volumiostu volumio[2736]: info: Received Get System Info Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:46:41 volumiostu volumio[2736]: info: Discovery: Getting this device information Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:41 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:41 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetVisibleSources Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:46:41 volumiostu go-librespot[3091]: time="2026-02-21T15:46:41Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:41 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:41 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 21 15:46:41 volumiostu volumio[2736]: info: Received Get System Info Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:46:41 volumiostu volumio[2736]: info: Discovery: Getting this device information Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:41 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:41 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:41 volumiostu volumio[2736]: info: Listing playlists Feb 21 15:46:41 volumiostu go-librespot[3091]: time="2026-02-21T15:46:41Z" level=debug msg="completed keyexchange" Feb 21 15:46:41 volumiostu go-librespot[3091]: time="2026-02-21T15:46:41Z" level=debug msg="completed challenge" Feb 21 15:46:41 volumiostu go-librespot[3091]: time="2026-02-21T15:46:41Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:41 volumiostu go-librespot[3091]: time="2026-02-21T15:46:41Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:41 volumiostu systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 15:46:41 volumiostu systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 15:46:41 volumiostu volumio[2736]: info: Received Get System Info Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:46:41 volumiostu volumio[2736]: info: Discovery: Getting this device information Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:41 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:46:41 volumiostu volumio[2736]: info: CoreCommandRouter::volumioGetState Feb 21 15:46:41 volumiostu volumio[2736]: info: CorePlayQueue::getTrack 0 Feb 21 15:46:42 volumiostu volumio[2736]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 15:46:42 volumiostu volumio[2736]: Error: socket hang up Feb 21 15:46:42 volumiostu volumio[2736]: at connResetException (node:internal/errors:720:14) Feb 21 15:46:42 volumiostu volumio[2736]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 21 15:46:42 volumiostu volumio[2736]: at Socket.emit (node:events:526:35) Feb 21 15:46:42 volumiostu volumio[2736]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 21 15:46:42 volumiostu volumio[2736]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 21 15:46:42 volumiostu volumio[2736]: code: 'ECONNRESET', Feb 21 15:46:42 volumiostu volumio[2736]: response: undefined Feb 21 15:46:42 volumiostu volumio[2736]: } Feb 21 15:46:42 volumiostu volumio[2736]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 15:46:44 volumiostu systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 21 15:46:44 volumiostu systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:46:44 volumiostu systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:46:44 volumiostu go-librespot[3146]: go-librespot daemon starting... Feb 21 15:46:45 volumiostu go-librespot[3147]: time="2026-02-21T15:46:45Z" level=info msg="running go-librespot 0.6.2" Feb 21 15:46:45 volumiostu go-librespot[3147]: time="2026-02-21T15:46:45Z" level=debug msg="app state loaded" Feb 21 15:46:45 volumiostu go-librespot[3147]: time="2026-02-21T15:46:45Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 15:46:45 volumiostu go-librespot[3147]: time="2026-02-21T15:46:45Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 21 15:46:45 volumiostu go-librespot[3147]: time="2026-02-21T15:46:45Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 21 15:46:45 volumiostu go-librespot[3147]: time="2026-02-21T15:46:45Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 21 15:46:45 volumiostu go-librespot[3147]: time="2026-02-21T15:46:45Z" level=info msg="zeroconf server listening on port 42029" Feb 21 15:46:45 volumiostu go-librespot[3147]: time="2026-02-21T15:46:45Z" level=debug msg="obtained new client token: AABF7DSFNHsfi2ee4c2Tvbls3huzKAYHPIRH3ly3g1dVglAc5KvURR9tmy7Stv34axJxNQqJh4rv2q6DJqAGU5rxW4rQi6Ikj+hl9PJOB9rOAMNcvRE1quH+3aWkLNXpXShekxk1HUPEOSvG5i2PRG7MwmokIg3iymY91MJfL207F+NaswUmKfplN3sSHNDRlwRtJfxttmRcHA8DH9u2z9v48bMrqm74fDkMjDEyeB103djgdotypw==" Feb 21 15:46:45 volumiostu go-librespot[3147]: time="2026-02-21T15:46:45Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 15:46:45 volumiostu go-librespot[3147]: time="2026-02-21T15:46:45Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.197:44472->104.199.65.9:4070: read: connection reset by peer" Feb 21 15:46:45 volumiostu sudo[3159]: volumio : unable to resolve host volumiostu: System error Feb 21 15:46:45 volumiostu sudo[3159]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-21 15:45' Feb 21 15:46:45 volumiostu sudo[3159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:46:45 volumiostu go-librespot[3147]: time="2026-02-21T15:46:45Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 21 15:46:45 volumiostu go-librespot[3147]: time="2026-02-21T15:46:45Z" level=debug msg="completed keyexchange" Feb 21 15:46:45 volumiostu go-librespot[3147]: time="2026-02-21T15:46:45Z" level=debug msg="completed challenge" Feb 21 15:46:45 volumiostu go-librespot[3147]: time="2026-02-21T15:46:45Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 21 15:46:46 volumiostu go-librespot[3147]: time="2026-02-21T15:46:46Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 21 15:46:46 volumiostu go-librespot[3147]: time="2026-02-21T15:46:46Z" level=debug msg="completed keyexchange" Feb 21 15:46:46 volumiostu go-librespot[3147]: time="2026-02-21T15:46:46Z" level=debug msg="completed challenge" Feb 21 15:46:46 volumiostu go-librespot[3147]: time="2026-02-21T15:46:46Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"