Oct 12 07:17:16 volumio ntpd[1191]: CLOCK: time stepped by 6605892.799439 Oct 12 07:17:16 volumio ntpd[1191]: CLOCK: time changed from 2026-07-27 to 2026-10-12 Oct 12 07:17:16 volumio ntpd[1191]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Oct 12 07:17:16 volumio volumio[1366]: info: go-librespot daemon successfully initialized Oct 12 07:17:16 volumio systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Oct 12 07:17:16 volumio systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Oct 12 07:17:16 volumio systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Oct 12 07:17:16 volumio systemd[1]: dpkg-db-backup.service: Deactivated successfully. Oct 12 07:17:16 volumio systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Oct 12 07:17:16 volumio volumio[1366]: info: Discovery: A device disappeared from network Oct 12 07:17:16 volumio volumio[1366]: info: Discovery: A device disappeared from network Oct 12 07:17:16 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Oct 12 07:17:16 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Oct 12 07:17:16 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Oct 12 07:17:16 volumio upmpdcli[1784]: Could not open config: /tmp/upmpdcli.conf Oct 12 07:17:16 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Oct 12 07:17:16 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Oct 12 07:17:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Oct 12 07:17:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:17 volumio go-librespot[1785]: go-librespot daemon starting... Oct 12 07:17:17 volumio go-librespot[1786]: time="2026-10-12T07:17:17+03:00" level=info msg="running go-librespot 0.7.1" Oct 12 07:17:17 volumio go-librespot[1786]: time="2026-10-12T07:17:17+03:00" level=debug msg="app state loaded" Oct 12 07:17:17 volumio go-librespot[1786]: time="2026-10-12T07:17:17+03:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 07:17:17 volumio go-librespot[1786]: time="2026-10-12T07:17:17+03:00" 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]" Oct 12 07:17:17 volumio go-librespot[1786]: time="2026-10-12T07:17:17+03:00" 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]" Oct 12 07:17:17 volumio go-librespot[1786]: time="2026-10-12T07:17:17+03:00" 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]" Oct 12 07:17:17 volumio go-librespot[1786]: time="2026-10-12T07:17:17+03:00" level=info msg="zeroconf server listening on port 35379" Oct 12 07:17:17 volumio go-librespot[1786]: time="2026-10-12T07:17:17+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 07:17:17 volumio go-librespot[1786]: time="2026-10-12T07:17:17+03:00" level=debug msg="obtained new client token: AAEVR5hmLYWf01jzZkT9k4W5WBDTF00dqgJUu+/bckbW5g/RCtIK6E36JxG9K+qApK8Cr7LE/C9HDDs+ZZn8vknnMMTYl6Pt3fOuyxTQ/FhsfwAmEnQrQuhQS8afyWJVGKZ6eWlTe9sS0hoK68kwzPIkZJXa8bTZafO2+BDntFv0UsBoeyOcITvJWiBi3ZkFD/WF1O6TCrHtcxO+/zBKhLEG45wJyDvxFlOAfnXnwLI5FqipxEO+cwbx" Oct 12 07:17:17 volumio go-librespot[1786]: time="2026-10-12T07:17:17+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 12 07:17:17 volumio go-librespot[1786]: time="2026-10-12T07:17:17+03:00" level=debug msg="completed keyexchange" Oct 12 07:17:17 volumio go-librespot[1786]: time="2026-10-12T07:17:17+03:00" level=debug msg="completed challenge" Oct 12 07:17:17 volumio go-librespot[1786]: time="2026-10-12T07:17:17+03:00" level=info msg="authenticated AP" username="31************************vu" Oct 12 07:17:17 volumio volumio[1366]: info: Volumio Network Manager: Network status updated: 1 Oct 12 07:17:18 volumio go-librespot[1786]: time="2026-10-12T07:17:18+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 07:17:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 07:17:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 07:17:18 volumio volumio[1366]: info: Discovery: adding 56bb66f9-cfbd-4574-9eff-f64c0f19061d Oct 12 07:17:18 volumio volumio[1366]: info: Discovery: Found device Volumio Oct 12 07:17:18 volumio volumio[1366]: info: CoreCommandRouter::volumioGetState Oct 12 07:17:18 volumio volumio[1366]: info: CorePlayQueue::getTrack 0 Oct 12 07:17:18 volumio volumio[1366]: info: Discovery: this is already registered, 56bb66f9-cfbd-4574-9eff-f64c0f19061d Oct 12 07:17:18 volumio volumio[1366]: info: Discovery: Found device Volumio Oct 12 07:17:18 volumio volumio[1366]: info: CoreCommandRouter::volumioGetState Oct 12 07:17:18 volumio volumio[1366]: info: CorePlayQueue::getTrack 0 Oct 12 07:17:18 volumio volumio[1366]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Oct 12 07:17:18 volumio volumio[1366]: info: New Spotify access tokenBQBKHBKuwz... Oct 12 07:17:18 volumio volumio[1366]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 12 07:17:19 volumio volumio[1366]: info: Initializing connection to go-librespot Websocket Oct 12 07:17:20 volumio sudo[1811]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 07:17:20 volumio sudo[1811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 07:17:20 volumio sudo[1813]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 07:17:20 volumio sudo[1813]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 07:17:20 volumio sudo[1813]: pam_unix(sudo:session): session closed for user root Oct 12 07:17:20 volumio sudo[1811]: pam_unix(sudo:session): session closed for user root Oct 12 07:17:20 volumio sudo[1817]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 12 07:17:20 volumio sudo[1817]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 07:17:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Oct 12 07:17:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:21 volumio go-librespot[1819]: go-librespot daemon starting... Oct 12 07:17:21 volumio go-librespot[1820]: time="2026-10-12T07:17:21+03:00" level=info msg="running go-librespot 0.7.1" Oct 12 07:17:21 volumio go-librespot[1820]: time="2026-10-12T07:17:21+03:00" level=debug msg="app state loaded" Oct 12 07:17:21 volumio go-librespot[1820]: time="2026-10-12T07:17:21+03:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 07:17:21 volumio go-librespot[1820]: time="2026-10-12T07:17:21+03:00" 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]" Oct 12 07:17:21 volumio go-librespot[1820]: time="2026-10-12T07:17:21+03:00" 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]" Oct 12 07:17:21 volumio go-librespot[1820]: time="2026-10-12T07:17:21+03:00" 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]" Oct 12 07:17:21 volumio go-librespot[1820]: time="2026-10-12T07:17:21+03:00" level=info msg="zeroconf server listening on port 33759" Oct 12 07:17:21 volumio go-librespot[1820]: time="2026-10-12T07:17:21+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 07:17:21 volumio go-librespot[1820]: time="2026-10-12T07:17:21+03:00" level=debug msg="obtained new client token: AAHyjs9MPIazjlsYYAlnLagWKKunmQfO4HWzeCyf5tGoBHcBJt2iRN/kcnduIabOMoZVEXs4a9smTE3AS2X4vRsb6vq7mJXE5TxAmKwpKr+UnLGW0fYaYQYPf6LI/CadvVMJPEZjDOYod1bEFM5GfySwpaxC/DmkVHpBNT7kJw/3JTLQZ7M6aIvSEu9ENUNDjRD7T2Jt8Il0zoCXTgXmaHksym8/RLqA1SlRp8Q45OI1Jqi0dr2bCesS" Oct 12 07:17:21 volumio go-librespot[1820]: time="2026-10-12T07:17:21+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 12 07:17:21 volumio go-librespot[1820]: time="2026-10-12T07:17:21+03:00" level=debug msg="completed keyexchange" Oct 12 07:17:21 volumio go-librespot[1820]: time="2026-10-12T07:17:21+03:00" level=debug msg="completed challenge" Oct 12 07:17:21 volumio go-librespot[1820]: time="2026-10-12T07:17:21+03:00" level=info msg="authenticated AP" username="31************************vu" Oct 12 07:17:21 volumio go-librespot[1820]: time="2026-10-12T07:17:21+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 07:17:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 07:17:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 07:17:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Oct 12 07:17:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:25 volumio volumio[1366]: info: Discovery: this is already registered, 56bb66f9-cfbd-4574-9eff-f64c0f19061d Oct 12 07:17:25 volumio volumio[1366]: info: Discovery: Found device Volumio Oct 12 07:17:25 volumio volumio[1366]: info: CoreCommandRouter::volumioGetState Oct 12 07:17:25 volumio volumio[1366]: info: CorePlayQueue::getTrack 0 Oct 12 07:17:25 volumio volumio[1366]: info: Discovery: this is already registered, 56bb66f9-cfbd-4574-9eff-f64c0f19061d Oct 12 07:17:25 volumio volumio[1366]: info: Discovery: Found device Volumio Oct 12 07:17:25 volumio volumio[1366]: info: CoreCommandRouter::volumioGetState Oct 12 07:17:25 volumio volumio[1366]: info: CorePlayQueue::getTrack 0 Oct 12 07:17:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:25 volumio go-librespot[1828]: go-librespot daemon starting... Oct 12 07:17:25 volumio go-librespot[1829]: time="2026-10-12T07:17:25+03:00" level=info msg="running go-librespot 0.7.1" Oct 12 07:17:25 volumio go-librespot[1829]: time="2026-10-12T07:17:25+03:00" level=debug msg="app state loaded" Oct 12 07:17:25 volumio go-librespot[1829]: time="2026-10-12T07:17:25+03:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 07:17:25 volumio go-librespot[1829]: time="2026-10-12T07:17:25+03:00" 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]" Oct 12 07:17:25 volumio go-librespot[1829]: time="2026-10-12T07:17:25+03:00" 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]" Oct 12 07:17:25 volumio go-librespot[1829]: time="2026-10-12T07:17:25+03:00" 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]" Oct 12 07:17:25 volumio go-librespot[1829]: time="2026-10-12T07:17:25+03:00" level=info msg="zeroconf server listening on port 46023" Oct 12 07:17:25 volumio go-librespot[1829]: time="2026-10-12T07:17:25+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 07:17:25 volumio volumio[1366]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 07:17:25 volumio go-librespot[1829]: time="2026-10-12T07:17:25+03:00" level=debug msg="obtained new client token: AAFvbEeyZtaJUe52hgthCcRjjkTioxkrQ2uOZa3y5ZDfVxMbgEPPoOz0YtW6rFnk3wvHxOOV+zKJD1yQ6114+CyxNPYpoGL/29BBXJLDsSbnOYtmXxIQk6fCUyWZFbXP4dZR+yM9TfahINqR3dS0bgEXMIT+gprvse4KZswHe+94/IC739l4Hw+Ht7e0g3dpdtVn6qlnosD9wM2qadwHPAB3kkw0mlwS2rcytX9ZYGU1FNvlU3SYO+ip" Oct 12 07:17:25 volumio go-librespot[1829]: time="2026-10-12T07:17:25+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 12 07:17:25 volumio go-librespot[1829]: time="2026-10-12T07:17:25+03:00" level=debug msg="completed keyexchange" Oct 12 07:17:25 volumio go-librespot[1829]: time="2026-10-12T07:17:25+03:00" level=debug msg="completed challenge" Oct 12 07:17:25 volumio go-librespot[1829]: time="2026-10-12T07:17:25+03:00" level=info msg="authenticated AP" username="31************************vu" Oct 12 07:17:25 volumio go-librespot[1829]: time="2026-10-12T07:17:25+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 07:17:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 07:17:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 12 07:17:27 volumio volumio[1366]: info: Adding plugin bluetooth to MyMusic Plugins Oct 12 07:17:27 volumio volumio[1366]: info: Adding plugin multiroom to MyMusic Plugins Oct 12 07:17:27 volumio volumio[1366]: info: Adding plugin metavolumio to MyMusic Plugins Oct 12 07:17:27 volumio volumio[1366]: info: Adding plugin cd_controller to MyMusic Plugins Oct 12 07:17:27 volumio volumio[1366]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 12 07:17:27 volumio volumio[1366]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 12 07:17:27 volumio volumio[1366]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 12 07:17:27 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 07:17:27 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 07:17:27 volumio volumio[1366]: info: Starting MyVolumio Remote Streaming Endpoints Oct 12 07:17:27 volumio volumio[1366]: info: MyVolumio login type: Token Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 12 07:17:27 volumio volumio[1366]: info: Streaming services startup Oct 12 07:17:27 volumio volumio[1366]: info: Starting Streaming Daemon Oct 12 07:17:27 volumio sudo[1853]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 07:17:27 volumio sudo[1853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 07:17:27 volumio volumio[1366]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 12 07:17:27 volumio sudo[1853]: pam_unix(sudo:session): session closed for user root Oct 12 07:17:28 volumio volumio[1366]: info: CoreCommandRouter::volumioGetState Oct 12 07:17:28 volumio volumio[1366]: info: CorePlayQueue::getTrack 0 Oct 12 07:17:28 volumio volumio[1366]: error: Cannot start Volumio Streaming Daemon Oct 12 07:17:28 volumio volumio[1366]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 07:17:28 volumio volumio[1366]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 07:17:28 volumio volumio[1366]: SPOTIFY: User informations: {"account_id":"VxHkEWGXEM","country":"GR","display_name":"Dim","email":"cameradlink57@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31t2trof5e5rkbgvq7w3cms5xivu"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31t2trof5e5rkbgvq7w3cms5xivu","id":"31t2trof5e5rkbgvq7w3cms5xivu","images":[],"product":"free","type":"user","uri":"spotify:user:31t2trof5e5rkbgvq7w3cms5xivu"} Oct 12 07:17:28 volumio volumio[1366]: info: Spotify Successfully logged in Oct 12 07:17:28 volumio volumio[1366]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 07:17:28 volumio volumio[1366]: info: [1791778648665] CoreMusicLibrary::Adding element Spotify Oct 12 07:17:28 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 07:17:28 volumio volumio[1366]: Cannot find translation for source Bandcamp Discover Oct 12 07:17:28 volumio volumio[1366]: Cannot find translation for source Mixcloud Oct 12 07:17:28 volumio volumio[1366]: Cannot find translation for source SoundCloud Oct 12 07:17:28 volumio volumio[1366]: Cannot find translation for source Spotify Oct 12 07:17:28 volumio volumio[1366]: info: Initializing connection to go-librespot Websocket Oct 12 07:17:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Oct 12 07:17:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:29 volumio go-librespot[1860]: go-librespot daemon starting... Oct 12 07:17:29 volumio go-librespot[1861]: time="2026-10-12T07:17:29+03:00" level=info msg="running go-librespot 0.7.1" Oct 12 07:17:29 volumio go-librespot[1861]: time="2026-10-12T07:17:29+03:00" level=debug msg="app state loaded" Oct 12 07:17:29 volumio go-librespot[1861]: time="2026-10-12T07:17:29+03:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 07:17:29 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully. Oct 12 07:17:29 volumio go-librespot[1861]: time="2026-10-12T07:17:29+03:00" 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]" Oct 12 07:17:29 volumio go-librespot[1861]: time="2026-10-12T07:17:29+03:00" 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]" Oct 12 07:17:29 volumio go-librespot[1861]: time="2026-10-12T07:17:29+03:00" 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]" Oct 12 07:17:29 volumio go-librespot[1861]: time="2026-10-12T07:17:29+03:00" level=info msg="zeroconf server listening on port 44157" Oct 12 07:17:29 volumio go-librespot[1861]: time="2026-10-12T07:17:29+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 07:17:29 volumio go-librespot[1861]: time="2026-10-12T07:17:29+03:00" level=debug msg="obtained new client token: AAFdDu/ZtTPcVs+IPbKeSZbweQkNaDCCZMlWjGRF0HCQ84kM9q03k8OsfzwfHPOUwEEUa+iyA0zy9yTlsL0gBcYATK9yOUqwkRNkW8Jrze/ZwnAZhGQnf1zL8ttht4YAK+1FRUoRfqu2hjnrpJbmhhkxkCIXVhEeyqkEt3UYY1m82unsTxhfCVfjYGpEtJKP1H8rmPwC4q1ude9zxslRNUL8Oge1VVUxEqQq4+XiJflTPFczEwFixnpM" Oct 12 07:17:29 volumio volumio[1366]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 07:17:29 volumio go-librespot[1861]: time="2026-10-12T07:17:29+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 12 07:17:29 volumio go-librespot[1861]: time="2026-10-12T07:17:29+03:00" level=debug msg="completed keyexchange" Oct 12 07:17:29 volumio go-librespot[1861]: time="2026-10-12T07:17:29+03:00" level=debug msg="completed challenge" Oct 12 07:17:29 volumio go-librespot[1861]: time="2026-10-12T07:17:29+03:00" level=info msg="authenticated AP" username="31************************vu" Oct 12 07:17:29 volumio go-librespot[1861]: time="2026-10-12T07:17:29+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 07:17:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 07:17:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 07:17:30 volumio volumio[1366]: (node:1366) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 close listeners added to [TLSSocket]. Use emitter.setMaxListeners() to increase limit Oct 12 07:17:30 volumio volumio[1366]: (Use `node --trace-warnings ...` to show where the warning was created) Oct 12 07:17:31 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully. Oct 12 07:17:31 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:31 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:31 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:31 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:31 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:31 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:31 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:31 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:31 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:31 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:31 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:32 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:32 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:32 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:32 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:32 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:32 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:32 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:32 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:32 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:32 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:32 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Oct 12 07:17:32 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Oct 12 07:17:32 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Oct 12 07:17:32 volumio sudo[1817]: pam_unix(sudo:session): session closed for user root Oct 12 07:17:32 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:32 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Oct 12 07:17:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:33 volumio go-librespot[1885]: go-librespot daemon starting... Oct 12 07:17:33 volumio go-librespot[1886]: time="2026-10-12T07:17:33+03:00" level=info msg="running go-librespot 0.7.1" Oct 12 07:17:33 volumio go-librespot[1886]: time="2026-10-12T07:17:33+03:00" level=debug msg="app state loaded" Oct 12 07:17:33 volumio go-librespot[1886]: time="2026-10-12T07:17:33+03:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 07:17:33 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:33 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:33 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:33 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:33 volumio go-librespot[1886]: time="2026-10-12T07:17:33+03:00" 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]" Oct 12 07:17:33 volumio go-librespot[1886]: time="2026-10-12T07:17:33+03:00" 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]" Oct 12 07:17:33 volumio go-librespot[1886]: time="2026-10-12T07:17:33+03:00" 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]" Oct 12 07:17:33 volumio go-librespot[1886]: time="2026-10-12T07:17:33+03:00" level=info msg="zeroconf server listening on port 39301" Oct 12 07:17:33 volumio go-librespot[1886]: time="2026-10-12T07:17:33+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 07:17:33 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:33 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:33 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:33 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:33 volumio go-librespot[1886]: time="2026-10-12T07:17:33+03:00" level=debug msg="obtained new client token: AAFm2HpV470jw8VLzdAH5OFiSGf8aCCrahfvro+GZlenV+YjzaQ/JiUBQPLr/IZR0khYkiP6xC/QsJO0cNENO6EQrtLU7eND2r8i1PTITRrbGd8/E0iURB9Pdq5S70sDB1PfsqIuAz4RFC6klw3E3L0VLMY4h+rXRL3pw5ToGMsLB2tkovepbVC7jqY0G6n/3AISPWtZDd3I5+oeDM/+zQPFvTQlbhH6RPQIMCAcGsbOIwqB/dnnzuAE" Oct 12 07:17:33 volumio go-librespot[1886]: time="2026-10-12T07:17:33+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 12 07:17:33 volumio go-librespot[1886]: time="2026-10-12T07:17:33+03:00" level=debug msg="completed keyexchange" Oct 12 07:17:33 volumio go-librespot[1886]: time="2026-10-12T07:17:33+03:00" level=debug msg="completed challenge" Oct 12 07:17:33 volumio go-librespot[1886]: time="2026-10-12T07:17:33+03:00" level=info msg="authenticated AP" username="31************************vu" Oct 12 07:17:33 volumio go-librespot[1886]: time="2026-10-12T07:17:33+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 07:17:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 07:17:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 07:17:33 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:33 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:34 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:34 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:34 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:34 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:34 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:34 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:34 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:34 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:34 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:34 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:34 volumio volumio[1366]: Cannot compose Albumart path Oct 12 07:17:34 volumio systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems... Oct 12 07:17:34 volumio systemd[1]: e2scrub_all.service: Deactivated successfully. Oct 12 07:17:34 volumio systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems. Oct 12 07:17:35 volumio volumio[1366]: info: Initializing connection to go-librespot Websocket Oct 12 07:17:35 volumio volumio[1366]: info: Upmpdcli Daemon Started Oct 12 07:17:35 volumio volumio[1366]: info: New access token = BQDd03eZuPnhBvpYcYbOtklUFgjlQo4HQkkY8i-jYlo9hlWp2Di__QAg8E-jiL2PqV3jRGe4nLtWzMK4TsGwNBVzjGyikJi5z5iLhfVpWIAdwHFn9ydQMIN3S08H5oy6JSH2ULG5oYT-1gueXzQLnLbcBOA0ORHJGQGU7SshK6LJ7lnU0x07tXnZGWq_v6KNH5BFnM0l7MkVtRY-5TcM77Y7_z7gDMQ1c2LbG0pptb8FFpnWvInqfGUfkdT6kSgobZqeQIJmaWGQMuOx6eEoWwKT_qxXT30wYcf-nPgEKGJ5IcBmPwD2XOxMhgWA Oct 12 07:17:35 volumio volumio[1366]: info: New access token = BQAXVPrvAJuDz8EYGVS5jE-ZJnLnrkdALBfFsVsb7p74jFZ4byeLDuWwj6uMoVysPD0sqZw0rR9d4zaGkKxP8-Q1g3NX-B0hw7KviUxfh-fkiMobDmty6QYNp6LpiCl2EeYTTvMUipqRAlZKnKP3PtBwHvnTXFWuFvhu9-YTn20MKGFKS3hizTn6lRB0L1Po92esW-8fPRI7CX4TDazvZSwC5cWjwNqIWNbsvI6TWgOenlfngdw2xRcUS9XNlBvQyGuksIUaXiv4gROB3qVKr4bc9to3lY7CA4Yre06t21cNBNQIQcC5mZShlou1 Oct 12 07:17:35 volumio volumio[1366]: info: New access token = BQAlAgX4rVzRtYxEfFEkXwpHmBIKozSaijD_PLRRQCUe5EGz-VnwXpH7uMLO5ey4ghdS6tpObpLr5tXT6Byy0PAxX3et8_NJhxBK7VIYYKjB5zlZo2q8_wdm7nmH5klRgHmTUb8hBsJJw0NU031JEKSsFvrRTXmCt5_9-yJxtdF9v-h3-NLfjQT9FXVpIbNA_5rRHVyHqCyvAoWeI01-a2ubHqwhZTm2-gwrS8QPn4YDuhaQPqAkRHN0KXTz_LPi0tL4fnaLJzqxsP-duLT62WWhRF1gLjwjx_PamGDoGyn4Yjp4ZYz2KWcNPzBc Oct 12 07:17:35 volumio volumio[1366]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 07:17:36 volumio volumio[1366]: error: MyVolumio Custom Token format not valid, refreshing it Oct 12 07:17:36 volumio volumio[1366]: error: Cannot refresh My Volumio Token: [object Object] Oct 12 07:17:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Oct 12 07:17:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:37 volumio go-librespot[1902]: go-librespot daemon starting... Oct 12 07:17:37 volumio go-librespot[1903]: time="2026-10-12T07:17:37+03:00" level=info msg="running go-librespot 0.7.1" Oct 12 07:17:37 volumio go-librespot[1903]: time="2026-10-12T07:17:37+03:00" level=debug msg="app state loaded" Oct 12 07:17:37 volumio go-librespot[1903]: time="2026-10-12T07:17:37+03:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 07:17:37 volumio go-librespot[1903]: time="2026-10-12T07:17:37+03:00" 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]" Oct 12 07:17:37 volumio go-librespot[1903]: time="2026-10-12T07:17:37+03:00" 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]" Oct 12 07:17:37 volumio go-librespot[1903]: time="2026-10-12T07:17:37+03:00" 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]" Oct 12 07:17:37 volumio go-librespot[1903]: time="2026-10-12T07:17:37+03:00" level=info msg="zeroconf server listening on port 43163" Oct 12 07:17:37 volumio go-librespot[1903]: time="2026-10-12T07:17:37+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 07:17:37 volumio go-librespot[1903]: time="2026-10-12T07:17:37+03:00" level=debug msg="obtained new client token: AAHEKsVwE3A1/U7NDstbx/KoxDhYO9I7mCRzr/pArkPUC9gEQKnxFUjwQgHlKfLuHF9aHOysgCX6XH/YB1uHAHZ8Ec3FKbOEcN3Dhxj1szK/P4NOXfOaiOmaOKilvL86JnYyjBzOzvC6/pRUarfN+FJXf9rYHfAsPUv0N++Y4obgTGdfm+L+ecnEXdvbqk6Hfw7hKpdgLbD3r6ImJGqKqCy+qwkrx8Px7TWJqMKExJ5pn0/FaBY+jOsG" Oct 12 07:17:37 volumio go-librespot[1903]: time="2026-10-12T07:17:37+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 12 07:17:37 volumio go-librespot[1903]: time="2026-10-12T07:17:37+03:00" level=debug msg="completed keyexchange" Oct 12 07:17:37 volumio go-librespot[1903]: time="2026-10-12T07:17:37+03:00" level=debug msg="completed challenge" Oct 12 07:17:37 volumio go-librespot[1903]: time="2026-10-12T07:17:37+03:00" level=info msg="authenticated AP" username="31************************vu" Oct 12 07:17:37 volumio go-librespot[1903]: time="2026-10-12T07:17:37+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 07:17:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 07:17:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 07:17:38 volumio volumio[1366]: info: Initializing connection to go-librespot Websocket Oct 12 07:17:38 volumio volumio[1366]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 07:17:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Oct 12 07:17:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:40 volumio go-librespot[1925]: go-librespot daemon starting... Oct 12 07:17:40 volumio go-librespot[1926]: time="2026-10-12T07:17:40+03:00" level=info msg="running go-librespot 0.7.1" Oct 12 07:17:40 volumio go-librespot[1926]: time="2026-10-12T07:17:40+03:00" level=debug msg="app state loaded" Oct 12 07:17:40 volumio go-librespot[1926]: time="2026-10-12T07:17:40+03:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 07:17:41 volumio go-librespot[1926]: time="2026-10-12T07:17:41+03:00" 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]" Oct 12 07:17:41 volumio go-librespot[1926]: time="2026-10-12T07:17:41+03:00" 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]" Oct 12 07:17:41 volumio go-librespot[1926]: time="2026-10-12T07:17:41+03:00" 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]" Oct 12 07:17:41 volumio go-librespot[1926]: time="2026-10-12T07:17:41+03:00" level=info msg="zeroconf server listening on port 36501" Oct 12 07:17:41 volumio go-librespot[1926]: time="2026-10-12T07:17:41+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 07:17:41 volumio go-librespot[1926]: time="2026-10-12T07:17:41+03:00" level=debug msg="obtained new client token: AAElr9AzJPBDhUvMk4ljd/hxIHxy0OYnsm54aJs69QyrY+viM7LgsEkV6lUwzq3cpv6qPgRs1KIp2X8gEESFpkINk9W6j+v9ostCGvK8BlY+49/DiptfGoGz2KQTWPJMS7PIfma9nml0F3BfWOE9oqtPuq3lhhhhGkDQzbTRc1ahcLV75euotlCkqricvYocbUt9UHldfy/G4knYRxiIgd1V0UwH70J5BSUOfgCKAmebZk+OvbpGYg==" Oct 12 07:17:41 volumio go-librespot[1926]: time="2026-10-12T07:17:41+03:00" 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" Oct 12 07:17:41 volumio go-librespot[1926]: time="2026-10-12T07:17:41+03:00" level=debug msg="connected to ap-gew1.spotify.com:443" Oct 12 07:17:41 volumio go-librespot[1926]: time="2026-10-12T07:17:41+03:00" level=debug msg="completed keyexchange" Oct 12 07:17:41 volumio go-librespot[1926]: time="2026-10-12T07:17:41+03:00" level=debug msg="completed challenge" Oct 12 07:17:41 volumio go-librespot[1926]: time="2026-10-12T07:17:41+03:00" level=info msg="authenticated AP" username="31************************vu" Oct 12 07:17:41 volumio go-librespot[1926]: time="2026-10-12T07:17:41+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 07:17:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 07:17:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 07:17:41 volumio volumio[1366]: info: Initializing connection to go-librespot Websocket Oct 12 07:17:41 volumio volumio[1366]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 07:17:42 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 12 07:17:42 volumio volumio[1366]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 12 07:17:42 volumio volumio[1366]: info: CoreCommandRouter::volumioGetState Oct 12 07:17:42 volumio volumio[1366]: info: CorePlayQueue::getTrack 0 Oct 12 07:17:42 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 07:17:42 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 07:17:42 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 12 07:17:43 volumio volumio5-onboarding[1665]: failed to bootstrap state: failed to check for software update: could not check for updates: context deadline exceeded Oct 12 07:17:43 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Oct 12 07:17:43 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 12 07:17:43 volumio volumio-remote-updater[1022]: Test mode disabled Oct 12 07:17:43 volumio volumio-remote-updater[1022]: Alpha mode disabled Oct 12 07:17:43 volumio volumio-remote-updater[1022]: Alpha legacy test mode disabled Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 12 07:17:43 volumio volumio[1366]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 12 07:17:43 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1. Oct 12 07:17:43 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 07:17:43 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 07:17:43 volumio volumio5-onboarding[1940]: time=2026-10-12T07:17:43.424+03:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 12 07:17:43 volumio volumio[1366]: 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 Oct 12 07:17:43 volumio volumio[1366]: 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 Oct 12 07:17:43 volumio volumio[1366]: info: Received Get System Info Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 07:17:43 volumio volumio[1366]: info: Discovery: Getting this device information Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::volumioGetState Oct 12 07:17:43 volumio volumio[1366]: info: CorePlayQueue::getTrack 0 Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 07:17:43 volumio volumio5-onboarding[1940]: time=2026-10-12T07:17:43.437+03:00 level=INFO msg="system info for 88dac654a8bbbd1a5b0e69e874f4ade3" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.119 Oct 12 07:17:43 volumio volumio5-onboarding[1940]: time=2026-10-12T07:17:43.450+03:00 level=INFO msg="bootstrapping state" hasInternet=true Oct 12 07:17:43 volumio volumio[1366]: info: Received Get System Info Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 07:17:43 volumio volumio[1366]: info: Discovery: Getting this device information Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::volumioGetState Oct 12 07:17:43 volumio volumio[1366]: info: CorePlayQueue::getTrack 0 Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 07:17:43 volumio volumio-remote-updater[1022]: Test mode disabled Oct 12 07:17:43 volumio volumio-remote-updater[1022]: Alpha mode disabled Oct 12 07:17:43 volumio volumio-remote-updater[1022]: Alpha legacy test mode disabled Oct 12 07:17:43 volumio volumio[1366]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 07:17:43 volumio volumio5-onboarding[1940]: time=2026-10-12T07:17:43.554+03:00 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" Oct 12 07:17:43 volumio volumio5-onboarding[1940]: time=2026-10-12T07:17:43.554+03:00 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" Oct 12 07:17:43 volumio volumio5-onboarding[1940]: time=2026-10-12T07:17:43.554+03:00 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" Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 07:17:43 volumio volumio[1366]: info: Received Get System Info Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 07:17:43 volumio volumio[1366]: info: Discovery: Getting this device information Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::volumioGetState Oct 12 07:17:43 volumio volumio[1366]: info: CorePlayQueue::getTrack 0 Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 12 07:17:43 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 12 07:17:43 volumio volumio5-onboarding[1940]: time=2026-10-12T07:17:43.560+03:00 level=INFO msg="enabling local network discovery" Oct 12 07:17:43 volumio volumio5-onboarding[1940]: time=2026-10-12T07:17:43.565+03:00 level=INFO msg="enabling BLE discovery" Oct 12 07:17:44 volumio volumio5-onboarding[1940]: time=2026-10-12T07:17:44.479+03:00 level=INFO msg="service successfully established" component=discovery/localnet Oct 12 07:17:44 volumio volumio[1366]: info: Initializing connection to go-librespot Websocket Oct 12 07:17:44 volumio volumio[1366]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 07:17:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Oct 12 07:17:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:44 volumio go-librespot[1953]: go-librespot daemon starting... Oct 12 07:17:44 volumio go-librespot[1954]: time="2026-10-12T07:17:44+03:00" level=info msg="running go-librespot 0.7.1" Oct 12 07:17:44 volumio go-librespot[1954]: time="2026-10-12T07:17:44+03:00" level=debug msg="app state loaded" Oct 12 07:17:44 volumio go-librespot[1954]: time="2026-10-12T07:17:44+03:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 07:17:45 volumio go-librespot[1954]: time="2026-10-12T07:17:45+03:00" 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]" Oct 12 07:17:45 volumio go-librespot[1954]: time="2026-10-12T07:17:45+03:00" 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]" Oct 12 07:17:45 volumio go-librespot[1954]: time="2026-10-12T07:17:45+03:00" 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]" Oct 12 07:17:45 volumio go-librespot[1954]: time="2026-10-12T07:17:45+03:00" level=info msg="zeroconf server listening on port 40581" Oct 12 07:17:45 volumio go-librespot[1954]: time="2026-10-12T07:17:45+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 07:17:45 volumio go-librespot[1954]: time="2026-10-12T07:17:45+03:00" level=debug msg="obtained new client token: AAFEAvg74ykxzv/iX6W0TTJzpG6PHFMwXMSIUNDNDS1YRq50SLDZ5XEQpIWSxH3y5buQs37dsy1vdufJid0pPoN1S399I7dmU29prvfe5vRAzXb1GfvqUsOqaQFI1gLDWM2lA+lJo4zcsj/F04geI6U5U9k9OJwO+7U1GuFaBIyuARCK6OHpSx7/CRLpSFHVaVGSgxO5iHr+uTxEOMHTyCeYqcgmf1dv+CWB9/DP5yHfcZErCRDTTg==" Oct 12 07:17:45 volumio go-librespot[1954]: time="2026-10-12T07:17:45+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 12 07:17:45 volumio go-librespot[1954]: time="2026-10-12T07:17:45+03:00" level=debug msg="completed keyexchange" Oct 12 07:17:45 volumio go-librespot[1954]: time="2026-10-12T07:17:45+03:00" level=debug msg="completed challenge" Oct 12 07:17:45 volumio go-librespot[1954]: time="2026-10-12T07:17:45+03:00" level=info msg="authenticated AP" username="31************************vu" Oct 12 07:17:45 volumio go-librespot[1954]: time="2026-10-12T07:17:45+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 07:17:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 07:17:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 07:17:47 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 07:17:47 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 07:17:47 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 12 07:17:47 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 12 07:17:47 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 12 07:17:47 volumio volumio[1366]: info: CoreCommandRouter::volumioGetBrowseSources Oct 12 07:17:47 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 07:17:47 volumio volumio[1366]: info: Initializing connection to go-librespot Websocket Oct 12 07:17:47 volumio volumio[1366]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 07:17:47 volumio volumio[1366]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 12 07:17:47 volumio volumio[1366]: info: Completed starting MyVolumio Plugin Oct 12 07:17:47 volumio volumio[1366]: [Metrics] CommandRouter: 40s 859.37ms Oct 12 07:17:47 volumio volumio[1366]: info: CoreCommandRouter::volumiosetStartupVolume Oct 12 07:17:47 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 07:17:47 volumio volumio[1366]: info: VolumeController:: Setting startup Volume 40 Oct 12 07:17:47 volumio volumio[1366]: info: VolumeController::SetAlsaVolume40 Oct 12 07:17:47 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 07:17:47 volumio volumio[1366]: info: CoreCommandRouter::Close All Modals sent Oct 12 07:17:47 volumio volumio[1366]: info: CoreCommandRouter::Close All Modals sent Oct 12 07:17:47 volumio volumio[1366]: info: CoreStateMachine::pushState Oct 12 07:17:47 volumio volumio[1366]: info: CorePlayQueue::getTrack 0 Oct 12 07:17:47 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 07:17:47 volumio volumio[1366]: info: CoreCommandRouter::volumioPushState Oct 12 07:17:47 volumio volumio[1366]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Oct 12 07:17:47 volumio volumio[1366]: ALSA lib confmisc.c:165:(snd_config_get_card) Cannot get card index for Set Oct 12 07:17:47 volumio volumio[1366]: aplay: main:831: audio open error: No such device Oct 12 07:17:47 volumio volumio[1366]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number '5'. Oct 12 07:17:47 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Oct 12 07:17:48 volumio volumio[1366]: info: Discovery: adding 0685b3d8-3bdc-4c01-acf1-dfb8d9f22f11 Oct 12 07:17:48 volumio volumio[1366]: info: Discovery: Found device Volumio-olga Oct 12 07:17:48 volumio volumio[1366]: info: Discovery: Connecting to remote: 192.168.1.7 Oct 12 07:17:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Oct 12 07:17:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:48 volumio go-librespot[1996]: go-librespot daemon starting... Oct 12 07:17:48 volumio go-librespot[1997]: time="2026-10-12T07:17:48+03:00" level=info msg="running go-librespot 0.7.1" Oct 12 07:17:48 volumio go-librespot[1997]: time="2026-10-12T07:17:48+03:00" level=debug msg="app state loaded" Oct 12 07:17:48 volumio go-librespot[1997]: time="2026-10-12T07:17:48+03:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 07:17:48 volumio go-librespot[1997]: time="2026-10-12T07:17:48+03:00" 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]" Oct 12 07:17:48 volumio go-librespot[1997]: time="2026-10-12T07:17:48+03:00" 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]" Oct 12 07:17:48 volumio go-librespot[1997]: time="2026-10-12T07:17:48+03:00" 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]" Oct 12 07:17:48 volumio go-librespot[1997]: time="2026-10-12T07:17:48+03:00" level=info msg="zeroconf server listening on port 44611" Oct 12 07:17:48 volumio go-librespot[1997]: time="2026-10-12T07:17:48+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 07:17:48 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 12 07:17:48 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 12 07:17:48 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: raat , onStop Oct 12 07:17:48 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 12 07:17:48 volumio go-librespot[1997]: time="2026-10-12T07:17:48+03:00" level=debug msg="obtained new client token: AAGK763/mQLaXbBra+wmAG2iAW9uWTreRLLmZ6jJE9TtCZl/vy79R3ivfFETq2kFH/+LP9GhGFjn/q2ip9p4KD2Q6hOuvHkIWHLH2NheTFu4fWuZaRYEcYzcvpA3yzEJCUQEHJsTpZ3BDDssKw1JnnEaE7w6e8V+j3oBykSSK8XpkxGjjIXjZfyQQpm8MT3zjdO+u/EQNwNOLwI2XfWq0Zgaf0KaSRCiHSdJWQfTPk1m9+7QNf0Qu56w" Oct 12 07:17:49 volumio go-librespot[1997]: time="2026-10-12T07:17:49+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 12 07:17:49 volumio go-librespot[1997]: time="2026-10-12T07:17:49+03:00" level=debug msg="completed keyexchange" Oct 12 07:17:49 volumio go-librespot[1997]: time="2026-10-12T07:17:49+03:00" level=debug msg="completed challenge" Oct 12 07:17:49 volumio go-librespot[1997]: time="2026-10-12T07:17:49+03:00" level=info msg="authenticated AP" username="31************************vu" Oct 12 07:17:49 volumio go-librespot[1997]: time="2026-10-12T07:17:49+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 07:17:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 07:17:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 07:17:49 volumio upmpdcli[2009]: writing RSA key Oct 12 07:17:50 volumio volumio[1366]: info: Initializing connection to go-librespot Websocket Oct 12 07:17:50 volumio volumio[1366]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 07:17:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Oct 12 07:17:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:52 volumio go-librespot[2018]: go-librespot daemon starting... Oct 12 07:17:52 volumio go-librespot[2019]: time="2026-10-12T07:17:52+03:00" level=info msg="running go-librespot 0.7.1" Oct 12 07:17:52 volumio go-librespot[2019]: time="2026-10-12T07:17:52+03:00" level=debug msg="app state loaded" Oct 12 07:17:52 volumio go-librespot[2019]: time="2026-10-12T07:17:52+03:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 07:17:52 volumio go-librespot[2019]: time="2026-10-12T07:17:52+03:00" 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]" Oct 12 07:17:52 volumio go-librespot[2019]: time="2026-10-12T07:17:52+03:00" 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]" Oct 12 07:17:52 volumio go-librespot[2019]: time="2026-10-12T07:17:52+03:00" 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]" Oct 12 07:17:52 volumio go-librespot[2019]: time="2026-10-12T07:17:52+03:00" level=info msg="zeroconf server listening on port 41685" Oct 12 07:17:52 volumio go-librespot[2019]: time="2026-10-12T07:17:52+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 07:17:52 volumio go-librespot[2019]: time="2026-10-12T07:17:52+03:00" level=debug msg="obtained new client token: AAGja26qvP1rhWlXZqoIqOQv8FN/6R5sToPIiy7txCQr5UALMoKf1Ze9HaGDGETOp36lW5LGNybJSx7qkfq8Nqoe6xOLP7xHrC/4G3PhwqiiC/tGQpbaOu+PetugH/wafEI2dn8z33Psmf+5Es5RTF98KXhIiHY2XSy/Y/+kxvzAouLrXd3/pJ9QmX2PukqUUmCnVZnowTyJL2EjqcfzJVue0Obr8LOobjXOW9R/bMByu11JtTM2+8rN" Oct 12 07:17:52 volumio go-librespot[2019]: time="2026-10-12T07:17:52+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 12 07:17:52 volumio go-librespot[2019]: time="2026-10-12T07:17:52+03:00" level=debug msg="completed keyexchange" Oct 12 07:17:52 volumio go-librespot[2019]: time="2026-10-12T07:17:52+03:00" level=debug msg="completed challenge" Oct 12 07:17:53 volumio go-librespot[2019]: time="2026-10-12T07:17:53+03:00" level=info msg="authenticated AP" username="31************************vu" Oct 12 07:17:53 volumio go-librespot[2019]: time="2026-10-12T07:17:53+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 07:17:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 07:17:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 07:17:53 volumio volumio[1366]: info: Discovery: Connected to remote: 192.168.1.7 Oct 12 07:17:53 volumio volumio[1366]: info: Initializing connection to go-librespot Websocket Oct 12 07:17:53 volumio volumio[1366]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 07:17:54 volumio volumio[1366]: info: BOOT COMPLETED Oct 12 07:17:55 volumio sudo[2033]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 07:17:55 volumio sudo[2033]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 07:17:55 volumio sudo[2033]: pam_unix(sudo:session): session closed for user root Oct 12 07:17:55 volumio sudo[2035]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 07:17:55 volumio sudo[2035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 07:17:55 volumio sudo[2035]: pam_unix(sudo:session): session closed for user root Oct 12 07:17:55 volumio volumio[1366]: verbose: New Socket.io Connection to 192.168.1.8 from 192.168.1.154 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/155.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Oct 12 07:17:55 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 12 07:17:55 volumio sudo[2040]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 07:17:55 volumio sudo[2040]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 07:17:55 volumio sudo[2042]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 07:17:55 volumio sudo[2042]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 07:17:55 volumio sudo[2040]: pam_unix(sudo:session): session closed for user root Oct 12 07:17:55 volumio sudo[2042]: pam_unix(sudo:session): session closed for user root Oct 12 07:17:55 volumio volumio[1366]: verbose: New Socket.io Connection to 192.168.1.8 from 192.168.1.154 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/155.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Oct 12 07:17:55 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 12 07:17:55 volumio volumio[1366]: info: CoreCommandRouter::volumioGetVisibleSources Oct 12 07:17:55 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 07:17:55 volumio volumio[1366]: info: CoreCommandRouter::volumioGetState Oct 12 07:17:55 volumio volumio[1366]: info: CorePlayQueue::getTrack 0 Oct 12 07:17:55 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 12 07:17:55 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 12 07:17:55 volumio volumio[1366]: info: Received Get System Info Oct 12 07:17:55 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 07:17:55 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 07:17:55 volumio volumio[1366]: info: Discovery: Getting this device information Oct 12 07:17:55 volumio volumio[1366]: info: CoreCommandRouter::volumioGetState Oct 12 07:17:55 volumio volumio[1366]: info: CorePlayQueue::getTrack 0 Oct 12 07:17:55 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 07:17:55 volumio volumio[1366]: info: CoreCommandRouter::volumioGetState Oct 12 07:17:55 volumio volumio[1366]: info: CorePlayQueue::getTrack 0 Oct 12 07:17:55 volumio volumio[1366]: info: Listing playlists Oct 12 07:17:55 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 12 07:17:55 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 12 07:17:56 volumio volumio[1366]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Saez/Apocalypse/37d92107-3725-41ff-9e68-b6f7f8d4c52c.jpg' Oct 12 07:17:56 volumio volumio[1366]: verbose: New Socket.io Connection to 192.168.1.8:3000 from 192.168.1.7 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 12 07:17:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Oct 12 07:17:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 07:17:56 volumio go-librespot[2046]: go-librespot daemon starting... Oct 12 07:17:56 volumio go-librespot[2047]: time="2026-10-12T07:17:56+03:00" level=info msg="running go-librespot 0.7.1" Oct 12 07:17:56 volumio go-librespot[2047]: time="2026-10-12T07:17:56+03:00" level=debug msg="app state loaded" Oct 12 07:17:56 volumio go-librespot[2047]: time="2026-10-12T07:17:56+03:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 07:17:56 volumio volumio[1366]: info: CoreCommandRouter::volumioGetState Oct 12 07:17:56 volumio volumio[1366]: info: CorePlayQueue::getTrack 0 Oct 12 07:17:56 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Oct 12 07:17:56 volumio volumio[1366]: info: CoreCommandRouter::volumioGetState Oct 12 07:17:56 volumio volumio[1366]: info: CorePlayQueue::getTrack 0 Oct 12 07:17:56 volumio volumio[1366]: info: Initializing connection to go-librespot Websocket Oct 12 07:17:56 volumio go-librespot[2047]: time="2026-10-12T07:17:56+03:00" level=debug msg="new websocket client" Oct 12 07:17:56 volumio volumio[1366]: info: Connection to go-librespot Websocket established Oct 12 07:17:57 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 12 07:17:57 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 07:17:57 volumio volumio[1366]: info: Received Get System Info Oct 12 07:17:57 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 07:17:57 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 07:17:57 volumio volumio[1366]: info: Discovery: Getting this device information Oct 12 07:17:57 volumio volumio[1366]: info: CoreCommandRouter::volumioGetState Oct 12 07:17:57 volumio volumio[1366]: info: CorePlayQueue::getTrack 0 Oct 12 07:17:57 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 07:17:58 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 12 07:17:58 volumio volumio[1366]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 12 07:17:59 volumio go-librespot[2047]: time="2026-10-12T07:17:59+03:00" 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]" Oct 12 07:17:59 volumio go-librespot[2047]: time="2026-10-12T07:17:59+03:00" 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]" Oct 12 07:17:59 volumio go-librespot[2047]: time="2026-10-12T07:17:59+03:00" 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]" Oct 12 07:17:59 volumio go-librespot[2047]: time="2026-10-12T07:17:59+03:00" level=info msg="zeroconf server listening on port 46849" Oct 12 07:17:59 volumio go-librespot[2047]: time="2026-10-12T07:17:59+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 07:17:59 volumio go-librespot[2047]: time="2026-10-12T07:17:59+03:00" level=debug msg="obtained new client token: AAFz0OX6IpCzuIV+bakP+K9lSGKlDXFTFAngHLwcMeOhv4QJP5e6u3WGI9V53s1+/j4JXZ4Wh+0QeGsqHIzuo4u+rmGZhVoDCBuLjrqJUftzBBIjIKr0+iuB9mo0qoUBUrXSsC9VT9x1Eko8GVpb6zGNayPbuWsPyV4LyYPnQqHO8k+iHSxTJrv/bcloe+vD58GRBUwUuhCeZBbWMkK3yJNnYzLmEc4d5CKYu7ND5XvuoEm88u92DpWg" Oct 12 07:17:59 volumio go-librespot[2047]: time="2026-10-12T07:17:59+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 12 07:17:59 volumio go-librespot[2047]: time="2026-10-12T07:17:59+03:00" level=debug msg="completed keyexchange" Oct 12 07:17:59 volumio go-librespot[2047]: time="2026-10-12T07:17:59+03:00" level=debug msg="completed challenge" Oct 12 07:17:59 volumio go-librespot[2047]: time="2026-10-12T07:17:59+03:00" level=info msg="authenticated AP" username="31************************vu" Oct 12 07:17:59 volumio go-librespot[2047]: time="2026-10-12T07:17:59+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 07:17:59 volumio volumio[1366]: info: Connection to go-librespot Websocket closed Oct 12 07:17:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 07:17:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 07:17:59 volumio volumio[1366]: info: Getting Spotify volume Oct 12 07:17:59 volumio volumio[1366]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 07:17:59 volumio volumio[1366]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 07:17:59 volumio volumio[1366]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 12 07:17:59 volumio volumio[1366]: errno: -111, Oct 12 07:17:59 volumio volumio[1366]: code: 'ECONNREFUSED', Oct 12 07:17:59 volumio volumio[1366]: syscall: 'connect', Oct 12 07:17:59 volumio volumio[1366]: address: '127.0.0.1', Oct 12 07:17:59 volumio volumio[1366]: port: 9879, Oct 12 07:17:59 volumio volumio[1366]: response: undefined Oct 12 07:17:59 volumio volumio[1366]: } Oct 12 07:17:59 volumio volumio[1366]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 07:17:59 volumio sudo[2084]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-12 07:16' Oct 12 07:17:59 volumio sudo[2084]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"