-- Logs begin at Fri 2025-08-01 04:30:34 CEST, end at Wed 2025-09-10 06:46:52 CEST. -- Sep 10 06:45:01 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:45:01 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 86. Sep 10 06:45:01 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:45:01 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:45:01 rivo go-librespot[5973]: go-librespot daemon starting... Sep 10 06:45:01 rivo go-librespot[5973]: time="2025-09-10T06:45:01+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:45:01 rivo go-librespot[5973]: time="2025-09-10T06:45:01+02:00" level=debug msg="app state loaded" Sep 10 06:45:01 rivo go-librespot[5973]: time="2025-09-10T06:45:01+02:00" level=debug msg="stored credentials not found" Sep 10 06:45:01 rivo go-librespot[5973]: time="2025-09-10T06:45:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:45:02 rivo go-librespot[5973]: time="2025-09-10T06:45:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:45:02 rivo go-librespot[5973]: time="2025-09-10T06:45:02+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:45:02 rivo go-librespot[5973]: time="2025-09-10T06:45:02+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:45:02 rivo go-librespot[5973]: time="2025-09-10T06:45:02+02:00" level=info msg="zeroconf server listening on port 39853" Sep 10 06:45:02 rivo go-librespot[5973]: time="2025-09-10T06:45:02+02:00" level=debug msg="obtained new client token: AACOxzTmADSbzfOwqWdF9eN5opcaXEHExEplKTcCu7iOdxYBigAOeotXEuo2/UE7yl2xWoxJcoflLF/SbZfgYml+WPP61Mc9vulpDoscBqaEKO2MbXeWO3UnBE3aRViw7nIp0BY6prfP++QqyvW8JtCnJzkmipUxUu6O+wReBm6/XqWsKvJlHHZ5dX+tiF/Y4gqHWvdJjs18QsYhPhAk+oKLyPGkBDI4K2DroIIGWWCX6Gln6qyO1Vc=" Sep 10 06:45:02 rivo go-librespot[5973]: time="2025-09-10T06:45:02+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:45:02 rivo go-librespot[5973]: time="2025-09-10T06:45:02+02:00" level=debug msg="completed keyexchange" Sep 10 06:45:02 rivo go-librespot[5973]: time="2025-09-10T06:45:02+02:00" level=debug msg="completed challenge" Sep 10 06:45:02 rivo go-librespot[5973]: time="2025-09-10T06:45:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:45:02 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:45:02 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:45:02 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:02 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:05 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:05 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:05 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:45:05 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87. Sep 10 06:45:05 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:45:05 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:45:05 rivo go-librespot[5983]: go-librespot daemon starting... Sep 10 06:45:05 rivo go-librespot[5983]: time="2025-09-10T06:45:05+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:45:05 rivo go-librespot[5983]: time="2025-09-10T06:45:05+02:00" level=debug msg="app state loaded" Sep 10 06:45:05 rivo go-librespot[5983]: time="2025-09-10T06:45:05+02:00" level=debug msg="stored credentials not found" Sep 10 06:45:05 rivo go-librespot[5983]: time="2025-09-10T06:45:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:45:06 rivo go-librespot[5983]: time="2025-09-10T06:45:06+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:45:06 rivo go-librespot[5983]: time="2025-09-10T06:45:06+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:45:06 rivo go-librespot[5983]: time="2025-09-10T06:45:06+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:45:06 rivo go-librespot[5983]: time="2025-09-10T06:45:06+02:00" level=info msg="zeroconf server listening on port 40377" Sep 10 06:45:06 rivo go-librespot[5983]: time="2025-09-10T06:45:06+02:00" level=debug msg="obtained new client token: AAAi2RNHWbwVShguyNPVjkp0VVlxQuWMNMEyz/Pb473FH98b9SpA8KHz3PmEud0NSa8yP60ePvnuEA0+A9K+hpwd+HpXxMW6Mn9jQ0eW+0loVWK9fDOUwvt+iwGUTWC/UFDI+YKnqZH6x4whPK5bGI1QEQvFWJKp5WA1vSGS07N4XfJ32iOgkcHabKNLtL+Ed+aGzqRDntb04akYH96QNW0mCmZ//t3Y8BKn8j4eSmlm/b3coZSeySI=" Sep 10 06:45:06 rivo go-librespot[5983]: time="2025-09-10T06:45:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:45:06 rivo go-librespot[5983]: time="2025-09-10T06:45:06+02:00" level=debug msg="completed keyexchange" Sep 10 06:45:06 rivo go-librespot[5983]: time="2025-09-10T06:45:06+02:00" level=debug msg="completed challenge" Sep 10 06:45:06 rivo go-librespot[5983]: time="2025-09-10T06:45:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:45:06 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:45:06 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:45:08 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:08 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:09 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:45:09 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 88. Sep 10 06:45:09 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:45:09 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:45:09 rivo go-librespot[5998]: go-librespot daemon starting... Sep 10 06:45:09 rivo go-librespot[5998]: time="2025-09-10T06:45:09+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:45:09 rivo go-librespot[5998]: time="2025-09-10T06:45:09+02:00" level=debug msg="app state loaded" Sep 10 06:45:09 rivo go-librespot[5998]: time="2025-09-10T06:45:09+02:00" level=debug msg="stored credentials not found" Sep 10 06:45:09 rivo go-librespot[5998]: time="2025-09-10T06:45:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:45:10 rivo go-librespot[5998]: time="2025-09-10T06:45:10+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:45:10 rivo go-librespot[5998]: time="2025-09-10T06:45:10+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:45:10 rivo go-librespot[5998]: time="2025-09-10T06:45:10+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:45:10 rivo go-librespot[5998]: time="2025-09-10T06:45:10+02:00" level=info msg="zeroconf server listening on port 46677" Sep 10 06:45:10 rivo go-librespot[5998]: time="2025-09-10T06:45:10+02:00" level=debug msg="obtained new client token: AADmylRRTKNSji8C6F0uuSi3mGfcuiN4fyTB9MLuUeEfSv/P8UxJmflhgFQPOBMhWcalw1fIMgUo3WX3TwQ+gcu+JfSdv9njS+JQtF7X8xBQ/EJ59jrdrttVKccFXt1rDDa9kMGxttZz+U4rN8BqeAo5sBVHiK5Nu1+mcqOQOQCQImWFTFwIPhbW7mqo2a5cuH3xunxFfJ3UngXK8+Ol3T8ZPXzukHYqNnSJxNQ+/N2x+ra9eS/Nr/g=" Sep 10 06:45:10 rivo go-librespot[5998]: time="2025-09-10T06:45:10+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:45:10 rivo go-librespot[5998]: time="2025-09-10T06:45:10+02:00" level=debug msg="completed keyexchange" Sep 10 06:45:10 rivo go-librespot[5998]: time="2025-09-10T06:45:10+02:00" level=debug msg="completed challenge" Sep 10 06:45:10 rivo go-librespot[5998]: time="2025-09-10T06:45:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:45:10 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:45:10 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:45:11 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:11 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:13 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:45:13 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 89. Sep 10 06:45:13 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:45:13 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:45:13 rivo go-librespot[6034]: go-librespot daemon starting... Sep 10 06:45:13 rivo go-librespot[6034]: time="2025-09-10T06:45:13+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:45:13 rivo go-librespot[6034]: time="2025-09-10T06:45:13+02:00" level=debug msg="app state loaded" Sep 10 06:45:13 rivo go-librespot[6034]: time="2025-09-10T06:45:13+02:00" level=debug msg="stored credentials not found" Sep 10 06:45:13 rivo go-librespot[6034]: time="2025-09-10T06:45:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:45:14 rivo go-librespot[6034]: time="2025-09-10T06:45:14+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:45:14 rivo go-librespot[6034]: time="2025-09-10T06:45:14+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:45:14 rivo go-librespot[6034]: time="2025-09-10T06:45:14+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:45:14 rivo go-librespot[6034]: time="2025-09-10T06:45:14+02:00" level=info msg="zeroconf server listening on port 40991" Sep 10 06:45:14 rivo go-librespot[6034]: time="2025-09-10T06:45:14+02:00" level=debug msg="obtained new client token: AAAbKl3fdPYmQB7Q2J2Q5VFcC5hPiTiUnxdsYcGNbeEevnZQwiChui7umD7wnpUTd2boAv+LbLQ8mgFvOV8nydaQpl1R8yxNHeoixKo663ZZ10cbwlXV00CzCg+mjcluME4tHWwpE/AovVocxzhm9/Sy+gd6z7lNpklwUl8osra9YFwnj6TqZUMgUx+c8dTXFw1XW5mf09G2bDAbOVIS9uFE5QLBKXBEhk38CvkeiC4gY8QAazpgc4c=" Sep 10 06:45:14 rivo go-librespot[6034]: time="2025-09-10T06:45:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:45:14 rivo go-librespot[6034]: time="2025-09-10T06:45:14+02:00" level=debug msg="completed keyexchange" Sep 10 06:45:14 rivo go-librespot[6034]: time="2025-09-10T06:45:14+02:00" level=debug msg="completed challenge" Sep 10 06:45:14 rivo go-librespot[6034]: time="2025-09-10T06:45:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:45:14 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:45:14 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:45:14 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:14 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:15 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 10 06:45:15 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 10 06:45:15 rivo volumio[3094]: info: Discovery: Getting this device information Sep 10 06:45:15 rivo volumio[3094]: info: CoreCommandRouter::volumioGetState Sep 10 06:45:15 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 10 06:45:17 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:17 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:17 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:45:17 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 90. Sep 10 06:45:17 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:45:17 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:45:17 rivo go-librespot[6058]: go-librespot daemon starting... Sep 10 06:45:17 rivo go-librespot[6058]: time="2025-09-10T06:45:17+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:45:17 rivo go-librespot[6058]: time="2025-09-10T06:45:17+02:00" level=debug msg="app state loaded" Sep 10 06:45:17 rivo go-librespot[6058]: time="2025-09-10T06:45:17+02:00" level=debug msg="stored credentials not found" Sep 10 06:45:17 rivo go-librespot[6058]: time="2025-09-10T06:45:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:45:18 rivo go-librespot[6058]: time="2025-09-10T06:45:18+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:45:18 rivo go-librespot[6058]: time="2025-09-10T06:45:18+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:45:18 rivo go-librespot[6058]: time="2025-09-10T06:45:18+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:45:18 rivo go-librespot[6058]: time="2025-09-10T06:45:18+02:00" level=info msg="zeroconf server listening on port 34619" Sep 10 06:45:18 rivo go-librespot[6058]: time="2025-09-10T06:45:18+02:00" level=debug msg="obtained new client token: AADq63V6J63j5W3dVpJ/uIjyX6Hibkm43WCO41I9G+z/kY4Evi1Ds0zFNlhojme78O6B6Yk6JM8OccJmJFfse3Bd9s19Fnd3F1nf702TFu/D/Ljg+xGIEwlJSSSJC9Vf0+uVqxr9jec7Q3q+E1uVGxdGdV5CLgVw/izgEG7nWED4xK0zBtDAwQkngGBIj+FNK2LaBjRGDKKKgaQRLYvC89o9vje/Y+QBYiR0csQVixrlJQvJ1dFKJ70=" Sep 10 06:45:18 rivo go-librespot[6058]: time="2025-09-10T06:45:18+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:45:18 rivo go-librespot[6058]: time="2025-09-10T06:45:18+02:00" level=debug msg="completed keyexchange" Sep 10 06:45:18 rivo go-librespot[6058]: time="2025-09-10T06:45:18+02:00" level=debug msg="completed challenge" Sep 10 06:45:18 rivo go-librespot[6058]: time="2025-09-10T06:45:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:45:18 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:45:18 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:45:20 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:20 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:21 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:45:21 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 91. Sep 10 06:45:21 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:45:21 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:45:21 rivo go-librespot[6066]: go-librespot daemon starting... Sep 10 06:45:21 rivo go-librespot[6066]: time="2025-09-10T06:45:21+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:45:21 rivo go-librespot[6066]: time="2025-09-10T06:45:21+02:00" level=debug msg="app state loaded" Sep 10 06:45:21 rivo go-librespot[6066]: time="2025-09-10T06:45:21+02:00" level=debug msg="stored credentials not found" Sep 10 06:45:21 rivo go-librespot[6066]: time="2025-09-10T06:45:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:45:22 rivo go-librespot[6066]: time="2025-09-10T06:45:22+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:45:22 rivo go-librespot[6066]: time="2025-09-10T06:45:22+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:45:22 rivo go-librespot[6066]: time="2025-09-10T06:45:22+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:45:22 rivo go-librespot[6066]: time="2025-09-10T06:45:22+02:00" level=info msg="zeroconf server listening on port 39235" Sep 10 06:45:22 rivo go-librespot[6066]: time="2025-09-10T06:45:22+02:00" level=debug msg="obtained new client token: AAAIstUf0bSG8vA/WvLSwaq/ukwkczRFG9pn8rumOZhJSj40WIBBMCsCXQXMsLuHJcIaJGtVrzCMq2d+sBikpOlYpW7VXSNI93JOdAyuOc0i3eP+DLFnjE5/y5HP9szbm50FIFbm1LUwpW64Qgqw6qI/0aLfFBiJpG9+At8tFAS07unnin3YTZQFKOjp9vc55JiV0J/R9tA6e4NZL/cm5Hy6RUZaEfFd0xpQe3G4HXw7w4SjwHsHb8E=" Sep 10 06:45:22 rivo go-librespot[6066]: time="2025-09-10T06:45:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:45:22 rivo volumio[3094]: info: VolumeController::SetAlsaVolume65 Sep 10 06:45:22 rivo go-librespot[6066]: time="2025-09-10T06:45:22+02:00" level=debug msg="completed keyexchange" Sep 10 06:45:22 rivo go-librespot[6066]: time="2025-09-10T06:45:22+02:00" level=debug msg="completed challenge" Sep 10 06:45:22 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:22 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:22 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:22 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:22 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:22 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:22 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Sep 10 06:45:22 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 66 Sep 10 06:45:22 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 65 Sep 10 06:45:22 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:22 rivo go-librespot[6066]: time="2025-09-10T06:45:22+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:45:22 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:45:22 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:45:22 rivo volumio[3094]: info: VolumeController::SetAlsaVolume64 Sep 10 06:45:22 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:22 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:22 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:22 rivo volumio[3094]: info: VolumeController::SetAlsaVolume63 Sep 10 06:45:22 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:22 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:22 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:22 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:22 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:22 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:22 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:22 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:22 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:22 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Sep 10 06:45:22 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 66 Sep 10 06:45:22 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 64 Sep 10 06:45:22 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 10 06:45:22 rivo volumio[3094]: info: Setting Spotify Volume from Volumio: 64 Sep 10 06:45:22 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 63 Sep 10 06:45:22 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 64 Sep 10 06:45:22 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 63 Sep 10 06:45:22 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:22 rivo volumio[3094]: info: VolumeController::SetAlsaVolume63 Sep 10 06:45:22 rivo volumio[3094]: info: VolumeController::SetAlsaVolume62 Sep 10 06:45:22 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:22 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:22 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:22 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:22 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:22 rivo volumio[3094]: info: VolumeController::SetAlsaVolume61 Sep 10 06:45:22 rivo volumio[3094]: info: VolumeController::SetAlsaVolume60 Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 62 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 64 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 62 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 10 06:45:23 rivo volumio[3094]: info: Setting Spotify Volume from Volumio: 62 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 62 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 62 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 60 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 10 06:45:23 rivo volumio[3094]: info: Setting Spotify Volume from Volumio: 60 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Sep 10 06:45:23 rivo volumio[3094]: info: VolumeController::SetAlsaVolume61 Sep 10 06:45:23 rivo volumio[3094]: info: VolumeController::SetAlsaVolume60 Sep 10 06:45:23 rivo volumio[3094]: info: VolumeController::SetAlsaVolume59 Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:23 rivo volumio[3094]: info: VolumeController::SetAlsaVolume58 Sep 10 06:45:23 rivo volumio[3094]: info: VolumeController::SetAlsaVolume57 Sep 10 06:45:23 rivo volumio[3094]: info: VolumeController::SetAlsaVolume56 Sep 10 06:45:23 rivo volumio[3094]: info: VolumeController::SetAlsaVolume55 Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:23 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 59 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 60 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 59 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 59 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 60 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 59 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 59 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 60 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 59 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 60 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 55 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 10 06:45:23 rivo volumio[3094]: info: Setting Spotify Volume from Volumio: 55 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Sep 10 06:45:23 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Sep 10 06:45:23 rivo volumio[3094]: info: VolumeController::SetAlsaVolume58 Sep 10 06:45:23 rivo volumio[3094]: info: VolumeController::SetAlsaVolume57 Sep 10 06:45:23 rivo volumio[3094]: info: VolumeController::SetAlsaVolume56 Sep 10 06:45:23 rivo volumio[3094]: info: VolumeController::SetAlsaVolume55 Sep 10 06:45:23 rivo volumio[3094]: info: VolumeController::SetAlsaVolume54 Sep 10 06:45:23 rivo volumio[3094]: info: VolumeController::SetAlsaVolume53 Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:23 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:23 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:23 rivo volumio[3094]: info: VolumeController::SetAlsaVolume52 Sep 10 06:45:23 rivo volumio[3094]: info: VolumeController::SetAlsaVolume51 Sep 10 06:45:24 rivo volumio[3094]: info: VolumeController::SetAlsaVolume50 Sep 10 06:45:24 rivo volumio[3094]: info: VolumeController::SetAlsaVolume49 Sep 10 06:45:24 rivo volumio[3094]: info: VolumeController::SetAlsaVolume48 Sep 10 06:45:24 rivo volumio[3094]: info: VolumeController::SetAlsaVolume47 Sep 10 06:45:24 rivo volumio[3094]: info: VolumeController::SetAlsaVolume46 Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53 Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 55 Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 53 Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 10 06:45:24 rivo volumio[3094]: info: Setting Spotify Volume from Volumio: 53 Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53 Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53 Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53 Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53 Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53 Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 53 Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 46 Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 10 06:45:24 rivo volumio[3094]: info: Setting Spotify Volume from Volumio: 46 Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Sep 10 06:45:24 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Sep 10 06:45:24 rivo volumio[3094]: info: VolumeController::SetAlsaVolume52 Sep 10 06:45:24 rivo volumio[3094]: info: VolumeController::SetAlsaVolume51 Sep 10 06:45:24 rivo volumio[3094]: info: VolumeController::SetAlsaVolume50 Sep 10 06:45:24 rivo volumio[3094]: info: VolumeController::SetAlsaVolume49 Sep 10 06:45:24 rivo volumio[3094]: info: VolumeController::SetAlsaVolume48 Sep 10 06:45:24 rivo volumio[3094]: info: VolumeController::SetAlsaVolume47 Sep 10 06:45:24 rivo volumio[3094]: info: VolumeController::SetAlsaVolume46 Sep 10 06:45:24 rivo volumio[3094]: info: VolumeController::SetAlsaVolume45 Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:24 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:24 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:24 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:25 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:25 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:25 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:25 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:25 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:25 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:25 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:25 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:25 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 46 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 45 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 46 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 45 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 46 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 45 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 46 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 45 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 46 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 45 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 46 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 45 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 46 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 45 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 46 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 45 Sep 10 06:45:25 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:25 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:45:25 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 92. Sep 10 06:45:25 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:45:25 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:45:25 rivo go-librespot[6136]: go-librespot daemon starting... Sep 10 06:45:25 rivo go-librespot[6136]: time="2025-09-10T06:45:25+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:45:25 rivo go-librespot[6136]: time="2025-09-10T06:45:25+02:00" level=debug msg="app state loaded" Sep 10 06:45:25 rivo go-librespot[6136]: time="2025-09-10T06:45:25+02:00" level=debug msg="stored credentials not found" Sep 10 06:45:25 rivo go-librespot[6136]: time="2025-09-10T06:45:25+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:45:26 rivo volumio[3094]: SPOTIFY: SETTING SPOTIFY VOLUME 46 Sep 10 06:45:26 rivo volumio[3094]: info: Sending Spotify command with payload to local API: /player/volume Sep 10 06:45:26 rivo go-librespot[6136]: time="2025-09-10T06:45:26+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:45:26 rivo go-librespot[6136]: time="2025-09-10T06:45:26+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:45:26 rivo go-librespot[6136]: time="2025-09-10T06:45:26+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:45:26 rivo go-librespot[6136]: time="2025-09-10T06:45:26+02:00" level=info msg="zeroconf server listening on port 43043" Sep 10 06:45:26 rivo go-librespot[6136]: time="2025-09-10T06:45:26+02:00" level=debug msg="obtained new client token: AAC16HnvBAgMuxYIeoSUYGSq3SKnmnLOghLK1XdthSHUzCtUJeNKuU6j81bcbKXyG850bNFJlcfyyTrohFWadqkpE60HFByPkMa20rBL9bKHuyX2ogN09A5Rwr68B2kpav23eLbSY8ZlUCgjHipLgbx2pBKT0SaVnZaK5GOrUXZuWUAVTv+Yc+BVt0eLvesSdP2mULDKK/gBxSzXJ81nkiEFX5tbbPl+LOBuuiR9Fv/kupP3gSf5Bxo=" Sep 10 06:45:26 rivo go-librespot[6136]: time="2025-09-10T06:45:26+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:45:26 rivo go-librespot[6136]: time="2025-09-10T06:45:26+02:00" level=debug msg="completed keyexchange" Sep 10 06:45:26 rivo go-librespot[6136]: time="2025-09-10T06:45:26+02:00" level=debug msg="completed challenge" Sep 10 06:45:26 rivo go-librespot[6136]: time="2025-09-10T06:45:26+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:45:26 rivo volumio[3094]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Sep 10 06:45:26 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:45:26 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:45:27 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:27 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:29 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:45:29 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93. Sep 10 06:45:29 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:45:29 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:45:29 rivo go-librespot[6144]: go-librespot daemon starting... Sep 10 06:45:29 rivo go-librespot[6144]: time="2025-09-10T06:45:29+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:45:29 rivo go-librespot[6144]: time="2025-09-10T06:45:29+02:00" level=debug msg="app state loaded" Sep 10 06:45:29 rivo go-librespot[6144]: time="2025-09-10T06:45:29+02:00" level=debug msg="stored credentials not found" Sep 10 06:45:29 rivo go-librespot[6144]: time="2025-09-10T06:45:29+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:45:30 rivo go-librespot[6144]: time="2025-09-10T06:45:30+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 10 06:45:30 rivo go-librespot[6144]: time="2025-09-10T06:45:30+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 10 06:45:30 rivo go-librespot[6144]: time="2025-09-10T06:45:30+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 10 06:45:30 rivo go-librespot[6144]: time="2025-09-10T06:45:30+02:00" level=info msg="zeroconf server listening on port 34181" Sep 10 06:45:30 rivo go-librespot[6144]: time="2025-09-10T06:45:30+02:00" level=debug msg="obtained new client token: AACcgePBu5STUAfPzZJxH2znh8YFG5h9HIcmGtNe6wA2GECjqpD5hqFuI1jHdrlkqGvkxDPj0kCDuDE3rTvQqgwVKggIxQPhnu9GW2lATqaM35xBRxS+L0sBd4mp01cvFrMXzbed2VoZumLHsw5oweUDh0R7Keqt1u9CYHRLQxmMSorLdHgPfywrdhrHlUxMRvDfOOFajqRnikgI+ANZiG3si5eSv9qbW9X+mKKBgktlsJyuv7VPy3aNWA==" Sep 10 06:45:30 rivo go-librespot[6144]: time="2025-09-10T06:45:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:45:30 rivo go-librespot[6144]: time="2025-09-10T06:45:30+02:00" level=debug msg="completed keyexchange" Sep 10 06:45:30 rivo go-librespot[6144]: time="2025-09-10T06:45:30+02:00" level=debug msg="completed challenge" Sep 10 06:45:30 rivo go-librespot[6144]: time="2025-09-10T06:45:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:45:30 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:45:30 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:45:30 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:30 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:31 rivo volumio[3094]: info: VolumeController::SetAlsaVolume44 Sep 10 06:45:31 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:31 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:31 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 46 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 44 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 10 06:45:31 rivo volumio[3094]: info: Setting Spotify Volume from Volumio: 44 Sep 10 06:45:31 rivo volumio[3094]: info: VolumeController::SetAlsaVolume43 Sep 10 06:45:31 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:31 rivo volumio[3094]: info: VolumeController::SetAlsaVolume42 Sep 10 06:45:31 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:31 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:31 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:31 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:31 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 44 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 43 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 44 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 42 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 10 06:45:31 rivo volumio[3094]: info: Setting Spotify Volume from Volumio: 42 Sep 10 06:45:31 rivo volumio[3094]: info: VolumeController::SetAlsaVolume42 Sep 10 06:45:31 rivo volumio[3094]: info: VolumeController::SetAlsaVolume41 Sep 10 06:45:31 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:31 rivo volumio[3094]: info: VolumeController::SetAlsaVolume41 Sep 10 06:45:31 rivo volumio[3094]: info: VolumeController::SetAlsaVolume40 Sep 10 06:45:31 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:31 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:31 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:31 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:31 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:31 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:31 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:31 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:31 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 42 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 41 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 42 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 41 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 42 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 40 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 10 06:45:31 rivo volumio[3094]: info: Setting Spotify Volume from Volumio: 40 Sep 10 06:45:31 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Sep 10 06:45:31 rivo volumio[3094]: info: VolumeController::SetAlsaVolume40 Sep 10 06:45:31 rivo volumio[3094]: info: VolumeController::SetAlsaVolume40 Sep 10 06:45:31 rivo volumio[3094]: info: VolumeController::SetAlsaVolume39 Sep 10 06:45:31 rivo volumio[3094]: info: VolumeController::SetAlsaVolume39 Sep 10 06:45:31 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:31 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:32 rivo volumio[3094]: info: VolumeController::SetAlsaVolume38 Sep 10 06:45:32 rivo volumio[3094]: info: VolumeController::SetAlsaVolume37 Sep 10 06:45:32 rivo volumio[3094]: info: VolumeController::SetAlsaVolume36 Sep 10 06:45:32 rivo volumio[3094]: info: VolumeController::SetAlsaVolume35 Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:32 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:32 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:32 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:32 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:32 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:32 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:32 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:32 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 39 Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 40 Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 39 Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 39 Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 40 Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 39 Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 39 Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 40 Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 39 Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 39 Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 40 Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 39 Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 40 Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 35 Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 10 06:45:32 rivo volumio[3094]: info: Setting Spotify Volume from Volumio: 35 Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Sep 10 06:45:32 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Sep 10 06:45:32 rivo volumio[3094]: info: VolumeController::SetAlsaVolume38 Sep 10 06:45:32 rivo volumio[3094]: info: VolumeController::SetAlsaVolume37 Sep 10 06:45:32 rivo volumio[3094]: info: VolumeController::SetAlsaVolume36 Sep 10 06:45:32 rivo volumio[3094]: info: VolumeController::SetAlsaVolume35 Sep 10 06:45:32 rivo volumio[3094]: info: VolumeController::SetAlsaVolume34 Sep 10 06:45:32 rivo volumio[3094]: info: VolumeController::SetAlsaVolume34 Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:32 rivo volumio[3094]: info: VolumeController::SetAlsaVolume33 Sep 10 06:45:32 rivo volumio[3094]: info: VolumeController::SetAlsaVolume32 Sep 10 06:45:32 rivo volumio[3094]: info: VolumeController::SetAlsaVolume31 Sep 10 06:45:32 rivo volumio[3094]: info: VolumeController::SetAlsaVolume30 Sep 10 06:45:32 rivo volumio[3094]: info: VolumeController::SetAlsaVolume29 Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:45:32 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:45:33 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:45:33 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:45:33 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 35 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 34 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 35 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 34 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 35 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 34 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 35 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 34 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 35 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 34 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 35 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 34 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 35 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 29 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 10 06:45:33 rivo volumio[3094]: info: Setting Spotify Volume from Volumio: 29 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29 Sep 10 06:45:33 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29 Sep 10 06:45:33 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:45:33 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 94. Sep 10 06:45:33 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:45:33 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:45:33 rivo go-librespot[6202]: go-librespot daemon starting... Sep 10 06:45:33 rivo go-librespot[6202]: time="2025-09-10T06:45:33+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:45:33 rivo go-librespot[6202]: time="2025-09-10T06:45:33+02:00" level=debug msg="app state loaded" Sep 10 06:45:33 rivo go-librespot[6202]: time="2025-09-10T06:45:33+02:00" level=debug msg="stored credentials not found" Sep 10 06:45:33 rivo go-librespot[6202]: time="2025-09-10T06:45:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:45:33 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:33 rivo go-librespot[6202]: time="2025-09-10T06:45:33+02:00" level=debug msg="new websocket client" Sep 10 06:45:33 rivo volumio[3094]: info: Connection to go-librespot Websocket established Sep 10 06:45:34 rivo go-librespot[6202]: time="2025-09-10T06:45:34+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:45:34 rivo go-librespot[6202]: time="2025-09-10T06:45:34+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:45:34 rivo go-librespot[6202]: time="2025-09-10T06:45:34+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:45:34 rivo go-librespot[6202]: time="2025-09-10T06:45:34+02:00" level=info msg="zeroconf server listening on port 41045" Sep 10 06:45:34 rivo go-librespot[6202]: time="2025-09-10T06:45:34+02:00" level=debug msg="obtained new client token: AACrJpqd5JN/cuLWULQo7r7jPpKcK0CATCNMQH9Bxe0nQs6YoiDkbB95m1i+SOACjO4dxDB+GDnIebIWhO1kM45GEuNMvIJyOaSAy30hFRjroN/M5d9gsEdeR91Bl3Ff7a/Oappq0Y3QO29KbdIYALr5UD5wwLhjv93mhCVkKq1ZTo2L1UJjrZq9srltEkwSPSuNNDrt0YPo6gLxRsT3ED4vq79GtDgjUmwauVRh+x19VxKTrsa/ljg=" Sep 10 06:45:34 rivo go-librespot[6202]: time="2025-09-10T06:45:34+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:45:34 rivo go-librespot[6202]: time="2025-09-10T06:45:34+02:00" level=debug msg="completed keyexchange" Sep 10 06:45:34 rivo go-librespot[6202]: time="2025-09-10T06:45:34+02:00" level=debug msg="completed challenge" Sep 10 06:45:34 rivo go-librespot[6202]: time="2025-09-10T06:45:34+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:45:34 rivo volumio[3094]: info: Connection to go-librespot Websocket closed Sep 10 06:45:34 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:45:34 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:45:34 rivo volumio[3094]: SPOTIFY: SETTING SPOTIFY VOLUME 29 Sep 10 06:45:34 rivo volumio[3094]: info: Sending Spotify command with payload to local API: /player/volume Sep 10 06:45:34 rivo volumio[3094]: error: Failed to send command to Spotify local API: /player/volume: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:36 rivo volumio[3094]: info: Getting Spotify volume Sep 10 06:45:36 rivo volumio[3094]: (node:3094) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:36 rivo volumio[3094]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 10 06:45:36 rivo volumio[3094]: (node:3094) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 6) Sep 10 06:45:36 rivo volumio[3094]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Sep 10 06:45:37 rivo volumio[3094]: info: CoreCommandRouter::volumioGetState Sep 10 06:45:37 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29 Sep 10 06:45:37 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:37 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:37 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:45:37 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 95. Sep 10 06:45:37 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:45:37 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:45:37 rivo go-librespot[6215]: go-librespot daemon starting... Sep 10 06:45:37 rivo go-librespot[6215]: time="2025-09-10T06:45:37+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:45:37 rivo go-librespot[6215]: time="2025-09-10T06:45:37+02:00" level=debug msg="app state loaded" Sep 10 06:45:37 rivo go-librespot[6215]: time="2025-09-10T06:45:37+02:00" level=debug msg="stored credentials not found" Sep 10 06:45:37 rivo go-librespot[6215]: time="2025-09-10T06:45:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:45:38 rivo go-librespot[6215]: time="2025-09-10T06:45:38+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 10 06:45:38 rivo go-librespot[6215]: time="2025-09-10T06:45:38+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 10 06:45:38 rivo go-librespot[6215]: time="2025-09-10T06:45:38+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 10 06:45:38 rivo go-librespot[6215]: time="2025-09-10T06:45:38+02:00" level=info msg="zeroconf server listening on port 34507" Sep 10 06:45:38 rivo go-librespot[6215]: time="2025-09-10T06:45:38+02:00" level=debug msg="obtained new client token: AAAyBmqv7u3u24U0FtzkauMOkRpZrXz2/DACAD+Xc6AUgrCspKhRM0o/tYNLGMI1T2ScopjCycC3LYrpN3cUv6XfhU2k9JX3CGgEJfrw/9o8zAZn71Y7dpnq6bMpgamy5jz2DU3f3r2cGvxpglNzGQPKgM8TAbqr3yuLpL10KmbvmEG6ltruJ2ls7zQGgcbv7pYDiwNh/ZAdJEWiR7Urc68aSOKBeR8EUcY1ciIED4cJMU/4CxOEzKU=" Sep 10 06:45:38 rivo go-librespot[6215]: time="2025-09-10T06:45:38+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:45:38 rivo go-librespot[6215]: time="2025-09-10T06:45:38+02:00" level=debug msg="completed keyexchange" Sep 10 06:45:38 rivo go-librespot[6215]: time="2025-09-10T06:45:38+02:00" level=debug msg="completed challenge" Sep 10 06:45:38 rivo go-librespot[6215]: time="2025-09-10T06:45:38+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:45:38 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:45:38 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:45:40 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:40 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:41 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:45:41 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 96. Sep 10 06:45:41 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:45:41 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:45:41 rivo go-librespot[6229]: go-librespot daemon starting... Sep 10 06:45:41 rivo go-librespot[6229]: time="2025-09-10T06:45:41+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:45:41 rivo go-librespot[6229]: time="2025-09-10T06:45:41+02:00" level=debug msg="app state loaded" Sep 10 06:45:41 rivo go-librespot[6229]: time="2025-09-10T06:45:41+02:00" level=debug msg="stored credentials not found" Sep 10 06:45:41 rivo go-librespot[6229]: time="2025-09-10T06:45:41+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:45:42 rivo go-librespot[6229]: time="2025-09-10T06:45:42+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:45:42 rivo go-librespot[6229]: time="2025-09-10T06:45:42+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:45:42 rivo go-librespot[6229]: time="2025-09-10T06:45:42+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:45:42 rivo go-librespot[6229]: time="2025-09-10T06:45:42+02:00" level=info msg="zeroconf server listening on port 42817" Sep 10 06:45:42 rivo go-librespot[6229]: time="2025-09-10T06:45:42+02:00" level=debug msg="obtained new client token: AADFlrljgbdBqqK18sUJX3ibLJzwBCulfc4bfJeU1QVTKxTXRf/9z7IOlB4Zxw2Wyfhat1JMmV/Il9lcBGZTwKgwqi8EFezsNpFyTn1LJXCTCTAXGH4iMCV6rNGp5INxl6A+i3zSQPOXFHwULxvYbcSwZ4xEHYaTn7bsx7cmQM3WE9anHsbMtU/5rotrx+2E8Sr69ii1gy6gyN8iojf6wxuuPkQfhz/UeMsov2t/m0+aznKtK6gpr2E=" Sep 10 06:45:42 rivo go-librespot[6229]: time="2025-09-10T06:45:42+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Sep 10 06:45:42 rivo go-librespot[6229]: time="2025-09-10T06:45:42+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Sep 10 06:45:42 rivo go-librespot[6229]: time="2025-09-10T06:45:42+02:00" level=debug msg="completed keyexchange" Sep 10 06:45:42 rivo go-librespot[6229]: time="2025-09-10T06:45:42+02:00" level=debug msg="completed challenge" Sep 10 06:45:42 rivo go-librespot[6229]: time="2025-09-10T06:45:42+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:45:42 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:45:42 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:45:43 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:43 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:45 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 10 06:45:45 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 10 06:45:45 rivo volumio[3094]: info: Discovery: Getting this device information Sep 10 06:45:45 rivo volumio[3094]: info: CoreCommandRouter::volumioGetState Sep 10 06:45:45 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 10 06:45:45 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:45:45 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 97. Sep 10 06:45:45 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:45:45 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:45:45 rivo go-librespot[6259]: go-librespot daemon starting... Sep 10 06:45:45 rivo go-librespot[6259]: time="2025-09-10T06:45:45+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:45:45 rivo go-librespot[6259]: time="2025-09-10T06:45:45+02:00" level=debug msg="app state loaded" Sep 10 06:45:45 rivo go-librespot[6259]: time="2025-09-10T06:45:45+02:00" level=debug msg="stored credentials not found" Sep 10 06:45:45 rivo go-librespot[6259]: time="2025-09-10T06:45:45+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:45:46 rivo go-librespot[6259]: time="2025-09-10T06:45:46+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 10 06:45:46 rivo go-librespot[6259]: time="2025-09-10T06:45:46+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 10 06:45:46 rivo go-librespot[6259]: time="2025-09-10T06:45:46+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 10 06:45:46 rivo go-librespot[6259]: time="2025-09-10T06:45:46+02:00" level=info msg="zeroconf server listening on port 33733" Sep 10 06:45:46 rivo go-librespot[6259]: time="2025-09-10T06:45:46+02:00" level=debug msg="obtained new client token: AAAmoi0lOgiFLvbOTlO+jpWiL+lCMG40NcReMj1OQOF/IVBhJaKeFnqMb2wsgghNgsmnpohGuVsK23ucyV+AB6eTcZb7emG+cxtLHe4nW0e+UPoYZlbNBUuNgwPuKs6wb+/IZMfBi5ttTWN8DOAu2o8Dg5sofGijSa88VZXTpAcRQN/PowQH+DQv3FMp7AiyFx9eXhtJRv+PZDbAsM5MQJxaNOW6oWH4OksyZw/1NyLvYfC+52ehlWM=" Sep 10 06:45:46 rivo go-librespot[6259]: time="2025-09-10T06:45:46+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:45:46 rivo go-librespot[6259]: time="2025-09-10T06:45:46+02:00" level=debug msg="completed keyexchange" Sep 10 06:45:46 rivo go-librespot[6259]: time="2025-09-10T06:45:46+02:00" level=debug msg="completed challenge" Sep 10 06:45:46 rivo go-librespot[6259]: time="2025-09-10T06:45:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:45:46 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:45:46 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:45:46 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:46 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:49 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:49 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:49 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:45:49 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 98. Sep 10 06:45:49 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:45:49 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:45:49 rivo go-librespot[6268]: go-librespot daemon starting... Sep 10 06:45:49 rivo go-librespot[6268]: time="2025-09-10T06:45:49+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:45:49 rivo go-librespot[6268]: time="2025-09-10T06:45:49+02:00" level=debug msg="app state loaded" Sep 10 06:45:49 rivo go-librespot[6268]: time="2025-09-10T06:45:49+02:00" level=debug msg="stored credentials not found" Sep 10 06:45:49 rivo go-librespot[6268]: time="2025-09-10T06:45:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:45:50 rivo go-librespot[6268]: time="2025-09-10T06:45:50+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:45:50 rivo go-librespot[6268]: time="2025-09-10T06:45:50+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:45:50 rivo go-librespot[6268]: time="2025-09-10T06:45:50+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:45:50 rivo go-librespot[6268]: time="2025-09-10T06:45:50+02:00" level=info msg="zeroconf server listening on port 36953" Sep 10 06:45:50 rivo go-librespot[6268]: time="2025-09-10T06:45:50+02:00" level=debug msg="obtained new client token: AAD5vm+bZWWR+u9qT7KAC/odOjW4zgxt9iJMAeHbtIVRF8CjFz3n5Yo6tJ7txAgUkFgN9Un97ekV8BXMUmgxnm8Bcg2zWeH1mWiq3k6s0k5RRxdkMgp6DIfn5PtXBNStwJ0c7xX8iPuDReoejqulOV1SJ+3c5wRxZ5vZh+lJzrhBIng1WMwMhwUv3+j16ZMoDNchdAj37eSY21eMr7YPop7oppfNzv2fNPWBa3VQPyXFF/HeXXD3eO4=" Sep 10 06:45:50 rivo go-librespot[6268]: time="2025-09-10T06:45:50+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:45:50 rivo go-librespot[6268]: time="2025-09-10T06:45:50+02:00" level=debug msg="completed keyexchange" Sep 10 06:45:50 rivo go-librespot[6268]: time="2025-09-10T06:45:50+02:00" level=debug msg="completed challenge" Sep 10 06:45:50 rivo go-librespot[6268]: time="2025-09-10T06:45:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:45:50 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:45:50 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:45:52 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:52 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:53 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:45:53 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99. Sep 10 06:45:53 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:45:53 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:45:53 rivo go-librespot[6341]: go-librespot daemon starting... Sep 10 06:45:53 rivo go-librespot[6341]: time="2025-09-10T06:45:53+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:45:53 rivo go-librespot[6341]: time="2025-09-10T06:45:53+02:00" level=debug msg="app state loaded" Sep 10 06:45:53 rivo go-librespot[6341]: time="2025-09-10T06:45:53+02:00" level=debug msg="stored credentials not found" Sep 10 06:45:53 rivo go-librespot[6341]: time="2025-09-10T06:45:53+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:45:54 rivo go-librespot[6341]: time="2025-09-10T06:45:54+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:45:54 rivo go-librespot[6341]: time="2025-09-10T06:45:54+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:45:54 rivo go-librespot[6341]: time="2025-09-10T06:45:54+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:45:54 rivo go-librespot[6341]: time="2025-09-10T06:45:54+02:00" level=info msg="zeroconf server listening on port 38851" Sep 10 06:45:54 rivo go-librespot[6341]: time="2025-09-10T06:45:54+02:00" level=debug msg="obtained new client token: AACFy6Zs5pkQlLMRvMdjTab0auZbkuJbuM1H9KhV666F0W6asv7gOgAliPMSNh4vcwhh5wVRBeu/q5QzGDVVpZYweiClMajHbU52LbPTxedS1JaV2ovbG77UwRfo61WYPH78oOi+8xMTt/LJd/sMJtHk/jUd45M7LjUcM2cDK2i+VqyJRVnWcBqWKASnUVrdVFkXuYpjhRA4H0iyDl4j4I3hqugT1dkU/ev6jl7a4E+oEAcHnEZXQkQ=" Sep 10 06:45:54 rivo go-librespot[6341]: time="2025-09-10T06:45:54+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:45:54 rivo go-librespot[6341]: time="2025-09-10T06:45:54+02:00" level=debug msg="completed keyexchange" Sep 10 06:45:54 rivo go-librespot[6341]: time="2025-09-10T06:45:54+02:00" level=debug msg="completed challenge" Sep 10 06:45:54 rivo go-librespot[6341]: time="2025-09-10T06:45:54+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:45:54 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:45:54 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:45:55 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:55 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:45:57 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:45:57 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 100. Sep 10 06:45:57 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:45:57 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:45:57 rivo go-librespot[6363]: go-librespot daemon starting... Sep 10 06:45:57 rivo go-librespot[6363]: time="2025-09-10T06:45:57+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:45:57 rivo go-librespot[6363]: time="2025-09-10T06:45:57+02:00" level=debug msg="app state loaded" Sep 10 06:45:57 rivo go-librespot[6363]: time="2025-09-10T06:45:57+02:00" level=debug msg="stored credentials not found" Sep 10 06:45:57 rivo go-librespot[6363]: time="2025-09-10T06:45:57+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:45:58 rivo go-librespot[6363]: time="2025-09-10T06:45:58+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:45:58 rivo go-librespot[6363]: time="2025-09-10T06:45:58+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:45:58 rivo go-librespot[6363]: time="2025-09-10T06:45:58+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:45:58 rivo go-librespot[6363]: time="2025-09-10T06:45:58+02:00" level=info msg="zeroconf server listening on port 34885" Sep 10 06:45:58 rivo go-librespot[6363]: time="2025-09-10T06:45:58+02:00" level=debug msg="obtained new client token: AAC4ky9XxHLJpuVQ+2XKugBHpxIfEXkiadE3d2E93M9qUP0cbLq6d595Kq7KW7UbQakexdN7W4rar6+ZtDK2Ea7ffDHCeHiwywpIXFcyuwtiF3WbSLBNLLpZOvPF7RjlTDxQFByQapaRbJuSr1UJ704bN6RwypPS3rI0mfA2IHD/CDhrTcLN1eRZrOvbuNwDiWiyTyKQGkad/w2IWfKIUdtcZgwzcjqSnm1a19KyT7jHVckO3RCaiZ8=" Sep 10 06:45:58 rivo go-librespot[6363]: time="2025-09-10T06:45:58+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:45:58 rivo go-librespot[6363]: time="2025-09-10T06:45:58+02:00" level=debug msg="completed keyexchange" Sep 10 06:45:58 rivo go-librespot[6363]: time="2025-09-10T06:45:58+02:00" level=debug msg="completed challenge" Sep 10 06:45:58 rivo go-librespot[6363]: time="2025-09-10T06:45:58+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:45:58 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:45:58 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:45:58 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:45:58 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:46:01 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:46:01 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:46:01 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:46:01 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 101. Sep 10 06:46:01 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:46:01 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:46:01 rivo go-librespot[6377]: go-librespot daemon starting... Sep 10 06:46:01 rivo go-librespot[6377]: time="2025-09-10T06:46:01+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:46:01 rivo go-librespot[6377]: time="2025-09-10T06:46:01+02:00" level=debug msg="app state loaded" Sep 10 06:46:01 rivo go-librespot[6377]: time="2025-09-10T06:46:01+02:00" level=debug msg="stored credentials not found" Sep 10 06:46:01 rivo go-librespot[6377]: time="2025-09-10T06:46:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:46:02 rivo go-librespot[6377]: time="2025-09-10T06:46:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:46:02 rivo go-librespot[6377]: time="2025-09-10T06:46:02+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:46:02 rivo go-librespot[6377]: time="2025-09-10T06:46:02+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:46:02 rivo go-librespot[6377]: time="2025-09-10T06:46:02+02:00" level=info msg="zeroconf server listening on port 41607" Sep 10 06:46:02 rivo go-librespot[6377]: time="2025-09-10T06:46:02+02:00" level=debug msg="obtained new client token: AADA76pz4fUP0x1CWmJrf+NL7y2+hReAMtld/l6HYWfknGFoLpfX7nKXgykW3whimDH1hVtE4PVkpmkvqh/SXo0/5qaNszUyTwNhoYj/1UYv8ftr3SADqDGu907Y3Kshmwgh4zauUM5P0zvzHYZuqiJB41QaSig1i4FQziexEpDyKHOumWWV00rntymXiuuIykkxRoMim+Sj0TtAPapcOePyyctQ8i0waXs75Wevf7cngbGFuka8bxA=" Sep 10 06:46:02 rivo go-librespot[6377]: time="2025-09-10T06:46:02+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:46:02 rivo go-librespot[6377]: time="2025-09-10T06:46:02+02:00" level=debug msg="completed keyexchange" Sep 10 06:46:02 rivo go-librespot[6377]: time="2025-09-10T06:46:02+02:00" level=debug msg="completed challenge" Sep 10 06:46:02 rivo go-librespot[6377]: time="2025-09-10T06:46:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:46:02 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:46:02 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:46:04 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:46:04 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:46:05 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:46:05 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 102. Sep 10 06:46:05 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:46:05 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:46:05 rivo go-librespot[6412]: go-librespot daemon starting... Sep 10 06:46:05 rivo go-librespot[6412]: time="2025-09-10T06:46:05+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:46:05 rivo go-librespot[6412]: time="2025-09-10T06:46:05+02:00" level=debug msg="app state loaded" Sep 10 06:46:05 rivo go-librespot[6412]: time="2025-09-10T06:46:05+02:00" level=debug msg="stored credentials not found" Sep 10 06:46:05 rivo go-librespot[6412]: time="2025-09-10T06:46:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:46:06 rivo go-librespot[6412]: time="2025-09-10T06:46:06+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:46:06 rivo go-librespot[6412]: time="2025-09-10T06:46:06+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:46:06 rivo go-librespot[6412]: time="2025-09-10T06:46:06+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:46:06 rivo go-librespot[6412]: time="2025-09-10T06:46:06+02:00" level=info msg="zeroconf server listening on port 41091" Sep 10 06:46:06 rivo go-librespot[6412]: time="2025-09-10T06:46:06+02:00" level=debug msg="obtained new client token: AACzfpjcFwa2zb0b4R5xQcAG2tarSAddn4WEmWcm1hodvolnmkP7g5bnv6VP9DisDzE3xdJvOtQoOvUrtaTKQ3IDUzTlUr/Z+Wb8fXWPxI6QSMPr0ahT4R6atls3lA35x1oyULkeXLsv+0cyYTvbCiXst8R0mzzJPB0sIhrH6Ukl6R0YcDOxNv7cXBLR37OQ9JFxgafGOeQSsoUP/k/C+t0sRtqS+AYiRDIVmkr4pZZwM39LjFA+c/g=" Sep 10 06:46:06 rivo go-librespot[6412]: time="2025-09-10T06:46:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:46:06 rivo go-librespot[6412]: time="2025-09-10T06:46:06+02:00" level=debug msg="completed keyexchange" Sep 10 06:46:06 rivo go-librespot[6412]: time="2025-09-10T06:46:06+02:00" level=debug msg="completed challenge" Sep 10 06:46:06 rivo go-librespot[6412]: time="2025-09-10T06:46:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:46:06 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:46:06 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:46:07 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:46:07 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:46:09 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:46:09 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 103. Sep 10 06:46:09 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:46:09 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:46:09 rivo go-librespot[6420]: go-librespot daemon starting... Sep 10 06:46:09 rivo go-librespot[6420]: time="2025-09-10T06:46:09+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:46:09 rivo go-librespot[6420]: time="2025-09-10T06:46:09+02:00" level=debug msg="app state loaded" Sep 10 06:46:09 rivo go-librespot[6420]: time="2025-09-10T06:46:09+02:00" level=debug msg="stored credentials not found" Sep 10 06:46:09 rivo go-librespot[6420]: time="2025-09-10T06:46:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:46:10 rivo go-librespot[6420]: time="2025-09-10T06:46:10+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:46:10 rivo go-librespot[6420]: time="2025-09-10T06:46:10+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:46:10 rivo go-librespot[6420]: time="2025-09-10T06:46:10+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:46:10 rivo go-librespot[6420]: time="2025-09-10T06:46:10+02:00" level=info msg="zeroconf server listening on port 43751" Sep 10 06:46:10 rivo go-librespot[6420]: time="2025-09-10T06:46:10+02:00" level=debug msg="obtained new client token: AADFYHWhwOKnvcll2+5dxvIvzLnx0AXHioIEW+8TZPc/Lt96l7dC+Emiq04KQMZwvZVsr0bvkpkt1Bf/SjLdCk1/Oa1n1KbEwEXuwCctBX11zFV3Aqx5RIINyKdBYYnSVGYhCko50Dma2RO+c+F3lUXM8l/DXV6xIsnfvOsU5c+4dJhi9Ftjs9qKduk4ifhxY1XM7JdwTG/QUMTkDKayuS7cXWj/LbQDyAo2CXQ02IKR6ivVbRTM0Zs=" Sep 10 06:46:10 rivo go-librespot[6420]: time="2025-09-10T06:46:10+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:46:10 rivo go-librespot[6420]: time="2025-09-10T06:46:10+02:00" level=debug msg="completed keyexchange" Sep 10 06:46:10 rivo go-librespot[6420]: time="2025-09-10T06:46:10+02:00" level=debug msg="completed challenge" Sep 10 06:46:10 rivo go-librespot[6420]: time="2025-09-10T06:46:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:46:10 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:46:10 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:46:10 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:46:10 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:46:13 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:46:13 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:46:13 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:46:13 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 104. Sep 10 06:46:13 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:46:13 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:46:13 rivo go-librespot[6455]: go-librespot daemon starting... Sep 10 06:46:13 rivo go-librespot[6455]: time="2025-09-10T06:46:13+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:46:13 rivo go-librespot[6455]: time="2025-09-10T06:46:13+02:00" level=debug msg="app state loaded" Sep 10 06:46:13 rivo go-librespot[6455]: time="2025-09-10T06:46:13+02:00" level=debug msg="stored credentials not found" Sep 10 06:46:13 rivo go-librespot[6455]: time="2025-09-10T06:46:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:46:14 rivo go-librespot[6455]: time="2025-09-10T06:46:14+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:46:14 rivo go-librespot[6455]: time="2025-09-10T06:46:14+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:46:14 rivo go-librespot[6455]: time="2025-09-10T06:46:14+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:46:14 rivo go-librespot[6455]: time="2025-09-10T06:46:14+02:00" level=info msg="zeroconf server listening on port 35867" Sep 10 06:46:14 rivo go-librespot[6455]: time="2025-09-10T06:46:14+02:00" level=debug msg="obtained new client token: AAB+GrQFR1uytsPfgtjvcnD7sLzKjIyqaHIT68jn+iOhdH/gl1rCwmHjqjhOj+L8s1k7VAC8XvvqYk053sknvg4KijAEW9A/u8PutSJoadAv3maRrDSZ8H1Q9rI0Dlud4UfEJ0noiRuZn3c5J51CRO+gOyKvGJFZY2/gsHtwEyV2zup4EWRHu2YzTmlV/mLV0LCkxpt0ZWNC8+gN0J/ctE4KpsS2qSzqc7+U3n6GIjvuC5BAjeu4f+c=" Sep 10 06:46:14 rivo go-librespot[6455]: time="2025-09-10T06:46:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:46:14 rivo go-librespot[6455]: time="2025-09-10T06:46:14+02:00" level=debug msg="completed keyexchange" Sep 10 06:46:14 rivo go-librespot[6455]: time="2025-09-10T06:46:14+02:00" level=debug msg="completed challenge" Sep 10 06:46:14 rivo go-librespot[6455]: time="2025-09-10T06:46:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:46:14 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:46:14 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:46:15 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 10 06:46:15 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 10 06:46:15 rivo volumio[3094]: info: Discovery: Getting this device information Sep 10 06:46:15 rivo volumio[3094]: info: CoreCommandRouter::volumioGetState Sep 10 06:46:15 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 10 06:46:16 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:46:16 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:46:17 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:46:17 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 105. Sep 10 06:46:17 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:46:17 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:46:17 rivo go-librespot[6467]: go-librespot daemon starting... Sep 10 06:46:17 rivo go-librespot[6467]: time="2025-09-10T06:46:17+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:46:17 rivo go-librespot[6467]: time="2025-09-10T06:46:17+02:00" level=debug msg="app state loaded" Sep 10 06:46:17 rivo go-librespot[6467]: time="2025-09-10T06:46:17+02:00" level=debug msg="stored credentials not found" Sep 10 06:46:17 rivo go-librespot[6467]: time="2025-09-10T06:46:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:46:18 rivo go-librespot[6467]: time="2025-09-10T06:46:18+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:46:18 rivo go-librespot[6467]: time="2025-09-10T06:46:18+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:46:18 rivo go-librespot[6467]: time="2025-09-10T06:46:18+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:46:18 rivo go-librespot[6467]: time="2025-09-10T06:46:18+02:00" level=info msg="zeroconf server listening on port 33991" Sep 10 06:46:18 rivo go-librespot[6467]: time="2025-09-10T06:46:18+02:00" level=debug msg="obtained new client token: AAAN2M5DzvKHYfAkbs/HqVFmKpAwxs0uJ/ji0wDKGvND/SzrW/+Qx10ylro1pzRgZRHnq94/rnMDifPRktKuPZzcGJ5S3wzkiSdSeZCAOxc7rPH7Q/U47AJVOnK14kmnUxovl5v90iPnECmp3awF8Zw9CY4XoHEPcpIpOz39pqHg351ZnW6iD4f+XTCe51Z/vvzReGhWPGGIaLGnV1Bp/gEXAB3ulbiEs0LFFrm7a1ExO9CgGa1XKOaudw==" Sep 10 06:46:18 rivo go-librespot[6467]: time="2025-09-10T06:46:18+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:46:18 rivo go-librespot[6467]: time="2025-09-10T06:46:18+02:00" level=debug msg="completed keyexchange" Sep 10 06:46:18 rivo go-librespot[6467]: time="2025-09-10T06:46:18+02:00" level=debug msg="completed challenge" Sep 10 06:46:18 rivo go-librespot[6467]: time="2025-09-10T06:46:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:46:18 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:46:18 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:46:19 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:46:19 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:46:21 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:46:21 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 106. Sep 10 06:46:21 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:46:21 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:46:21 rivo go-librespot[6496]: go-librespot daemon starting... Sep 10 06:46:21 rivo go-librespot[6496]: time="2025-09-10T06:46:21+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:46:21 rivo go-librespot[6496]: time="2025-09-10T06:46:21+02:00" level=debug msg="app state loaded" Sep 10 06:46:21 rivo go-librespot[6496]: time="2025-09-10T06:46:21+02:00" level=debug msg="stored credentials not found" Sep 10 06:46:21 rivo go-librespot[6496]: time="2025-09-10T06:46:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:46:22 rivo go-librespot[6496]: time="2025-09-10T06:46:22+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:46:22 rivo go-librespot[6496]: time="2025-09-10T06:46:22+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:46:22 rivo go-librespot[6496]: time="2025-09-10T06:46:22+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:46:22 rivo go-librespot[6496]: time="2025-09-10T06:46:22+02:00" level=info msg="zeroconf server listening on port 36819" Sep 10 06:46:22 rivo go-librespot[6496]: time="2025-09-10T06:46:22+02:00" level=debug msg="obtained new client token: AAAAKpyN6lpXCHZl/Rllow/9hgy/rQnBIA+m1hDndOA/mhlE47E2CehmMAb3ikRYWhjXpthgu9QRqFVnIFB/EDjAuQwjyQ21wm43tgYEMc04kq6psasLn9ge/ZP9GnOL4QgRIinw8tQUwUPDERZAlO1jIwi2C8N/Nbdc2Lxakjj3wGnvbTB7Mwobuo3bfvQW1kH/QygAKcU/6Df2Xbist6oHbedgacS9vO0n80nUIWuiv+St8AXPA48=" Sep 10 06:46:22 rivo go-librespot[6496]: time="2025-09-10T06:46:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:46:22 rivo go-librespot[6496]: time="2025-09-10T06:46:22+02:00" level=debug msg="completed keyexchange" Sep 10 06:46:22 rivo go-librespot[6496]: time="2025-09-10T06:46:22+02:00" level=debug msg="completed challenge" Sep 10 06:46:22 rivo go-librespot[6496]: time="2025-09-10T06:46:22+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:46:22 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:46:22 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:46:22 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:46:22 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:46:25 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:46:25 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:46:25 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:46:25 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 107. Sep 10 06:46:25 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:46:25 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:46:25 rivo go-librespot[6529]: go-librespot daemon starting... Sep 10 06:46:25 rivo go-librespot[6529]: time="2025-09-10T06:46:25+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:46:25 rivo go-librespot[6529]: time="2025-09-10T06:46:25+02:00" level=debug msg="app state loaded" Sep 10 06:46:25 rivo go-librespot[6529]: time="2025-09-10T06:46:25+02:00" level=debug msg="stored credentials not found" Sep 10 06:46:25 rivo go-librespot[6529]: time="2025-09-10T06:46:25+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:46:26 rivo go-librespot[6529]: time="2025-09-10T06:46:26+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:46:26 rivo go-librespot[6529]: time="2025-09-10T06:46:26+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:46:26 rivo go-librespot[6529]: time="2025-09-10T06:46:26+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:46:26 rivo go-librespot[6529]: time="2025-09-10T06:46:26+02:00" level=info msg="zeroconf server listening on port 44069" Sep 10 06:46:26 rivo go-librespot[6529]: time="2025-09-10T06:46:26+02:00" level=debug msg="obtained new client token: AACLhEoczalKVTa7tb81fbG+QeLulDn1mln1w3WW3vLtbDaGdCZ2L4D9AEO8ykwGlYDGu5v55EPZ00URhUiJOw0Y6TQK87GlKfDgY+Sn+6KjFhTskbSMHAjYlHP9zGJjbdXnqiW8uVFbkdu1muOG58EVEJD06AU0Axm3Xixm6vmW+RQfp/xU/o4lYvXg5DxzdDjKwtNTghOcZPZWsJlVGkbPwvoF0c/XhR+vtVBMgRndtwcAzmQR9lo=" Sep 10 06:46:26 rivo go-librespot[6529]: time="2025-09-10T06:46:26+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:46:26 rivo go-librespot[6529]: time="2025-09-10T06:46:26+02:00" level=debug msg="completed keyexchange" Sep 10 06:46:26 rivo go-librespot[6529]: time="2025-09-10T06:46:26+02:00" level=debug msg="completed challenge" Sep 10 06:46:26 rivo go-librespot[6529]: time="2025-09-10T06:46:26+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:46:26 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:46:26 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:46:28 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:46:28 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:46:29 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:46:29 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 108. Sep 10 06:46:29 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:46:29 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:46:29 rivo go-librespot[6537]: go-librespot daemon starting... Sep 10 06:46:29 rivo go-librespot[6537]: time="2025-09-10T06:46:29+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:46:29 rivo go-librespot[6537]: time="2025-09-10T06:46:29+02:00" level=debug msg="app state loaded" Sep 10 06:46:29 rivo go-librespot[6537]: time="2025-09-10T06:46:29+02:00" level=debug msg="stored credentials not found" Sep 10 06:46:29 rivo go-librespot[6537]: time="2025-09-10T06:46:29+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:46:30 rivo go-librespot[6537]: time="2025-09-10T06:46:30+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:46:30 rivo go-librespot[6537]: time="2025-09-10T06:46:30+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:46:30 rivo go-librespot[6537]: time="2025-09-10T06:46:30+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:46:30 rivo go-librespot[6537]: time="2025-09-10T06:46:30+02:00" level=info msg="zeroconf server listening on port 36749" Sep 10 06:46:30 rivo go-librespot[6537]: time="2025-09-10T06:46:30+02:00" level=debug msg="obtained new client token: AAARYenqvkjG6YK+HRIYzjlcnDg/knU2248hXfdI6xhcHXk5ke3BydIfz5IsN8+j+iQhqPq5+/dqNTJME7bLN5iT7gfZ+W798+1hNflOfnhL2NP84Ng8f33SGr3mfxuGJpLO5TJVsH/LfDH8Tceb87RMjbLZGktZgsuZAZabG2SeqO/2fTTi/fANay79vXn/t+4wZcMaVon5/li983PYesN0OZTwidA62q4wlnWEv4AVjG0t2B95Vz8=" Sep 10 06:46:30 rivo go-librespot[6537]: time="2025-09-10T06:46:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:46:30 rivo go-librespot[6537]: time="2025-09-10T06:46:30+02:00" level=debug msg="completed keyexchange" Sep 10 06:46:30 rivo go-librespot[6537]: time="2025-09-10T06:46:30+02:00" level=debug msg="completed challenge" Sep 10 06:46:30 rivo go-librespot[6537]: time="2025-09-10T06:46:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:46:30 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:46:30 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:46:31 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:46:31 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:46:33 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:46:33 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 109. Sep 10 06:46:33 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:46:33 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:46:33 rivo go-librespot[6562]: go-librespot daemon starting... Sep 10 06:46:33 rivo go-librespot[6562]: time="2025-09-10T06:46:33+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:46:33 rivo go-librespot[6562]: time="2025-09-10T06:46:33+02:00" level=debug msg="app state loaded" Sep 10 06:46:33 rivo go-librespot[6562]: time="2025-09-10T06:46:33+02:00" level=debug msg="stored credentials not found" Sep 10 06:46:33 rivo go-librespot[6562]: time="2025-09-10T06:46:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:46:34 rivo go-librespot[6562]: time="2025-09-10T06:46:34+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:46:34 rivo go-librespot[6562]: time="2025-09-10T06:46:34+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:46:34 rivo go-librespot[6562]: time="2025-09-10T06:46:34+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:46:34 rivo go-librespot[6562]: time="2025-09-10T06:46:34+02:00" level=info msg="zeroconf server listening on port 40685" Sep 10 06:46:34 rivo go-librespot[6562]: time="2025-09-10T06:46:34+02:00" level=debug msg="obtained new client token: AADhvvYEV2L2LlYzFB6gFh2zsrZk4sQk5x1zxPvqEvdJfTuy0NbVVUCRFkQczGYRG749ViDHMEemI0Mti0akxvmx8B2T14VzL4nWA+QxgIPYlhb0LLTWMH56IBpUixRUnu7+Ttaj3+x6RS7/Rwhb8cRtdTD5od+LjIqG5QN+/onFJmgsImEQrY7STI+d+9KyMcuZEXuyn9Cki/xPe7QRD0ZYJKjNWy3yTSNBpXIXdre7GUXvSHsfANksSQ==" Sep 10 06:46:34 rivo go-librespot[6562]: time="2025-09-10T06:46:34+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:46:34 rivo go-librespot[6562]: time="2025-09-10T06:46:34+02:00" level=debug msg="completed keyexchange" Sep 10 06:46:34 rivo go-librespot[6562]: time="2025-09-10T06:46:34+02:00" level=debug msg="completed challenge" Sep 10 06:46:34 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:46:34 rivo go-librespot[6562]: time="2025-09-10T06:46:34+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:46:34 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:46:34 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:46:34 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: read ECONNRESET Sep 10 06:46:35 rivo volumio[3094]: info: VolumeController::SetAlsaVolume30 Sep 10 06:46:35 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:35 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:46:35 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:35 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:35 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:35 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:35 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Sep 10 06:46:35 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 29 Sep 10 06:46:35 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 30 Sep 10 06:46:35 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:46:37 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:46:37 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:46:37 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:46:37 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 110. Sep 10 06:46:37 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:46:37 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:46:37 rivo go-librespot[6577]: go-librespot daemon starting... Sep 10 06:46:38 rivo go-librespot[6577]: time="2025-09-10T06:46:37+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:46:38 rivo go-librespot[6577]: time="2025-09-10T06:46:38+02:00" level=debug msg="app state loaded" Sep 10 06:46:38 rivo go-librespot[6577]: time="2025-09-10T06:46:38+02:00" level=debug msg="stored credentials not found" Sep 10 06:46:38 rivo go-librespot[6577]: time="2025-09-10T06:46:38+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:46:38 rivo go-librespot[6577]: time="2025-09-10T06:46:38+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 10 06:46:38 rivo go-librespot[6577]: time="2025-09-10T06:46:38+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 10 06:46:38 rivo go-librespot[6577]: time="2025-09-10T06:46:38+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 10 06:46:38 rivo go-librespot[6577]: time="2025-09-10T06:46:38+02:00" level=info msg="zeroconf server listening on port 45095" Sep 10 06:46:38 rivo go-librespot[6577]: time="2025-09-10T06:46:38+02:00" level=debug msg="obtained new client token: AAASJIqgE2mq/+iSHPErVCGDnoFYLSmoUHxh0DeKU2KHTSlC0Zg7FIvBH136p0NZhf5+O1bJLBPRqzATqcxrLzTmptcvpu6fzRzxQlzTvzpcMqWVb7wkOFtqJHrQkmRvz0/Rzfb7CSc4V5V5eNIHntVPHpKqgThGY2FHtu4IISj3uuzmR+uDz51tqLhVMaO250zcS6UHV++KzfjoOGmSR65YAglWf0K1h2wUJpovIPlCBMb4sUG4qod5Hg==" Sep 10 06:46:38 rivo go-librespot[6577]: time="2025-09-10T06:46:38+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:46:38 rivo go-librespot[6577]: time="2025-09-10T06:46:38+02:00" level=debug msg="completed keyexchange" Sep 10 06:46:38 rivo go-librespot[6577]: time="2025-09-10T06:46:38+02:00" level=debug msg="completed challenge" Sep 10 06:46:38 rivo go-librespot[6577]: time="2025-09-10T06:46:38+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:46:38 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:46:38 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:46:39 rivo volumio[3094]: info: VolumeController::SetAlsaVolume31 Sep 10 06:46:39 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:39 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:39 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 29 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 31 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 10 06:46:39 rivo volumio[3094]: info: Setting Spotify Volume from Volumio: 31 Sep 10 06:46:39 rivo volumio[3094]: info: VolumeController::SetAlsaVolume32 Sep 10 06:46:39 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:39 rivo volumio[3094]: info: VolumeController::SetAlsaVolume33 Sep 10 06:46:39 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:39 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:39 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:39 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:39 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 32 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 31 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 32 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 31 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 33 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 10 06:46:39 rivo volumio[3094]: info: Setting Spotify Volume from Volumio: 33 Sep 10 06:46:39 rivo volumio[3094]: info: VolumeController::SetAlsaVolume33 Sep 10 06:46:39 rivo volumio[3094]: info: VolumeController::SetAlsaVolume34 Sep 10 06:46:39 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:39 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:39 rivo volumio[3094]: info: VolumeController::SetAlsaVolume35 Sep 10 06:46:39 rivo volumio[3094]: info: VolumeController::SetAlsaVolume36 Sep 10 06:46:39 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:39 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:39 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:39 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:39 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:39 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:39 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:39 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:39 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:39 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:39 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 33 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 34 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 33 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 34 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 36 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 33 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 36 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 10 06:46:39 rivo volumio[3094]: info: Setting Spotify Volume from Volumio: 36 Sep 10 06:46:39 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 36 Sep 10 06:46:39 rivo volumio[3094]: info: VolumeController::SetAlsaVolume35 Sep 10 06:46:40 rivo volumio[3094]: info: VolumeController::SetAlsaVolume36 Sep 10 06:46:40 rivo volumio[3094]: info: VolumeController::SetAlsaVolume37 Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:40 rivo volumio[3094]: info: VolumeController::SetAlsaVolume38 Sep 10 06:46:40 rivo volumio[3094]: info: VolumeController::SetAlsaVolume39 Sep 10 06:46:40 rivo volumio[3094]: info: VolumeController::SetAlsaVolume40 Sep 10 06:46:40 rivo volumio[3094]: info: VolumeController::SetAlsaVolume41 Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 37 Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 36 Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 37 Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 37 Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 36 Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 37 Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 37 Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 36 Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 37 Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 36 Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 41 Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 10 06:46:40 rivo volumio[3094]: info: Setting Spotify Volume from Volumio: 41 Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Sep 10 06:46:40 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Sep 10 06:46:40 rivo volumio[3094]: info: VolumeController::SetAlsaVolume38 Sep 10 06:46:40 rivo volumio[3094]: info: VolumeController::SetAlsaVolume39 Sep 10 06:46:40 rivo volumio[3094]: info: VolumeController::SetAlsaVolume40 Sep 10 06:46:40 rivo volumio[3094]: info: VolumeController::SetAlsaVolume41 Sep 10 06:46:40 rivo volumio[3094]: info: VolumeController::SetAlsaVolume42 Sep 10 06:46:40 rivo volumio[3094]: info: VolumeController::SetAlsaVolume42 Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:40 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:46:40 rivo volumio[3094]: info: VolumeController::SetAlsaVolume43 Sep 10 06:46:40 rivo volumio[3094]: info: VolumeController::SetAlsaVolume44 Sep 10 06:46:40 rivo volumio[3094]: info: VolumeController::SetAlsaVolume45 Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::pushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioPushState Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:40 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:40 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:41 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:41 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:41 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:41 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:41 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:41 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:41 rivo volumio[3094]: info: CoreCommandRouter::volumioGetQueue Sep 10 06:46:41 rivo volumio[3094]: info: CoreStateMachine::getQueue Sep 10 06:46:41 rivo volumio[3094]: info: CorePlayQueue::getQueue Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 41 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 42 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 41 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 42 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 41 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 42 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 41 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 42 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 41 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 42 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 41 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 42 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: SPOTIFY VOLUME 41 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: VOLUMIO VOLUME 45 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 10 06:46:41 rivo volumio[3094]: info: Setting Spotify Volume from Volumio: 45 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Sep 10 06:46:41 rivo volumio[3094]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Sep 10 06:46:41 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:46:41 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:46:41 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 111. Sep 10 06:46:41 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:46:41 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:46:41 rivo go-librespot[6621]: go-librespot daemon starting... Sep 10 06:46:41 rivo go-librespot[6621]: time="2025-09-10T06:46:41+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:46:41 rivo go-librespot[6621]: time="2025-09-10T06:46:41+02:00" level=debug msg="app state loaded" Sep 10 06:46:42 rivo go-librespot[6621]: time="2025-09-10T06:46:42+02:00" level=debug msg="stored credentials not found" Sep 10 06:46:42 rivo go-librespot[6621]: time="2025-09-10T06:46:42+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:46:42 rivo go-librespot[6621]: time="2025-09-10T06:46:42+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:46:42 rivo go-librespot[6621]: time="2025-09-10T06:46:42+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:46:42 rivo go-librespot[6621]: time="2025-09-10T06:46:42+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:46:42 rivo go-librespot[6621]: time="2025-09-10T06:46:42+02:00" level=info msg="zeroconf server listening on port 42029" Sep 10 06:46:42 rivo go-librespot[6621]: time="2025-09-10T06:46:42+02:00" level=debug msg="obtained new client token: AACEVQwOB9A5ejz9ztg5xPVV03892FrGtk6pHtcTl8WL9YRozWZLMRR1doeKH1nd8yfwBl23sSPxZGvkLHjt9ts3Mlra61gKnDhf+sPRS/np5qidJiWcsueG4GSKa/5tpUsJCWVlNpOqeGukTV3hqskwzPKWWUp641hwavrtyDYPgNbBKLbny13mxGHJrwOjCy3uCyA7AYdRl6aWoYGsNNPkdfd49bUZvc3F9806F32n0NT5i39EbNkytQ==" Sep 10 06:46:42 rivo volumio[3094]: SPOTIFY: SETTING SPOTIFY VOLUME 45 Sep 10 06:46:42 rivo volumio[3094]: info: Sending Spotify command with payload to local API: /player/volume Sep 10 06:46:42 rivo go-librespot[6621]: time="2025-09-10T06:46:42+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:46:42 rivo go-librespot[6621]: time="2025-09-10T06:46:42+02:00" level=debug msg="completed keyexchange" Sep 10 06:46:42 rivo go-librespot[6621]: time="2025-09-10T06:46:42+02:00" level=debug msg="completed challenge" Sep 10 06:46:42 rivo go-librespot[6621]: time="2025-09-10T06:46:42+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:46:42 rivo volumio[3094]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Sep 10 06:46:42 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:46:42 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:46:44 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:46:44 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:46:45 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:46:45 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 112. Sep 10 06:46:45 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:46:45 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:46:45 rivo go-librespot[6646]: go-librespot daemon starting... Sep 10 06:46:46 rivo go-librespot[6646]: time="2025-09-10T06:46:46+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:46:46 rivo go-librespot[6646]: time="2025-09-10T06:46:46+02:00" level=debug msg="app state loaded" Sep 10 06:46:46 rivo go-librespot[6646]: time="2025-09-10T06:46:46+02:00" level=debug msg="stored credentials not found" Sep 10 06:46:46 rivo go-librespot[6646]: time="2025-09-10T06:46:46+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:46:46 rivo go-librespot[6646]: time="2025-09-10T06:46:46+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:46:46 rivo go-librespot[6646]: time="2025-09-10T06:46:46+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:46:46 rivo go-librespot[6646]: time="2025-09-10T06:46:46+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:46:46 rivo go-librespot[6646]: time="2025-09-10T06:46:46+02:00" level=info msg="zeroconf server listening on port 40075" Sep 10 06:46:46 rivo go-librespot[6646]: time="2025-09-10T06:46:46+02:00" level=debug msg="obtained new client token: AACmnxW7dYR9TI34FKBTMum5fhEykPTOeg57ApwM+tKw/jSulgg6MrmPVTGJdFGI8laK6TpkUO+r8m1ucmyKZxXy8CmO2TyjRkH5QfjqwNjsyCeMi8FbsXoNr0HInJVPB9C15rDh3gLx24MFNoV7F69TuJECRlkjUkjOgkJGWkewFlA0lEQPm6ZsXlzgHgDFlwoJNc1dUWmQzresPTtwQV8AyOQh694Y2zFzWOYqZQO9Fk5injiGyU/XeQ==" Sep 10 06:46:46 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 10 06:46:46 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 10 06:46:46 rivo volumio[3094]: info: Discovery: Getting this device information Sep 10 06:46:46 rivo volumio[3094]: info: CoreCommandRouter::volumioGetState Sep 10 06:46:46 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 10 06:46:46 rivo go-librespot[6646]: time="2025-09-10T06:46:46+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:46:46 rivo go-librespot[6646]: time="2025-09-10T06:46:46+02:00" level=debug msg="completed keyexchange" Sep 10 06:46:46 rivo go-librespot[6646]: time="2025-09-10T06:46:46+02:00" level=debug msg="completed challenge" Sep 10 06:46:46 rivo go-librespot[6646]: time="2025-09-10T06:46:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:46:46 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:46:46 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:46:47 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:46:47 rivo volumio[3094]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 10 06:46:49 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 10 06:46:49 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 113. Sep 10 06:46:49 rivo systemd[1]: Stopped go-librespot Daemon. Sep 10 06:46:49 rivo systemd[1]: Started go-librespot Daemon. Sep 10 06:46:49 rivo go-librespot[6661]: go-librespot daemon starting... Sep 10 06:46:50 rivo go-librespot[6661]: time="2025-09-10T06:46:49+02:00" level=info msg="running go-librespot 0.3.2" Sep 10 06:46:50 rivo go-librespot[6661]: time="2025-09-10T06:46:50+02:00" level=debug msg="app state loaded" Sep 10 06:46:50 rivo go-librespot[6661]: time="2025-09-10T06:46:50+02:00" level=debug msg="stored credentials not found" Sep 10 06:46:50 rivo go-librespot[6661]: time="2025-09-10T06:46:50+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 10 06:46:50 rivo volumio[3094]: info: Initializing connection to go-librespot Websocket Sep 10 06:46:50 rivo volumio[3094]: info: Connection to go-librespot Websocket established Sep 10 06:46:50 rivo go-librespot[6661]: time="2025-09-10T06:46:50+02:00" level=debug msg="new websocket client" Sep 10 06:46:50 rivo go-librespot[6661]: time="2025-09-10T06:46:50+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 10 06:46:50 rivo go-librespot[6661]: time="2025-09-10T06:46:50+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 10 06:46:50 rivo go-librespot[6661]: time="2025-09-10T06:46:50+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 10 06:46:50 rivo go-librespot[6661]: time="2025-09-10T06:46:50+02:00" level=info msg="zeroconf server listening on port 35105" Sep 10 06:46:50 rivo go-librespot[6661]: time="2025-09-10T06:46:50+02:00" level=debug msg="obtained new client token: AACyNu3JTr0EPgCzSG9AF7+xgmm47p0fjxWO+RRoS/N3M10ysSqLJ+olPaBCg1Uh3k0CpH1Vm3dtZ5qWEOZ9fdfujwDq+8JEBJrvZzkvbAFMMV0NNG68+2XrOZf7+12Pk3jSSY3aVAE9voQFi1hG5Cm1QzjsIqiKC/9T5cN5qyAObN3vhfIzqwmMlOcu+9VjxR3hblExXYv240yfA3Ujo4NGVdnS3D5rV25Uj4Yg12W4i09m28msrotZTA==" Sep 10 06:46:50 rivo go-librespot[6661]: time="2025-09-10T06:46:50+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 10 06:46:50 rivo go-librespot[6661]: time="2025-09-10T06:46:50+02:00" level=debug msg="completed keyexchange" Sep 10 06:46:50 rivo go-librespot[6661]: time="2025-09-10T06:46:50+02:00" level=debug msg="completed challenge" Sep 10 06:46:50 rivo go-librespot[6661]: time="2025-09-10T06:46:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 10 06:46:50 rivo volumio[3094]: info: Connection to go-librespot Websocket closed Sep 10 06:46:50 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 10 06:46:50 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 10 06:46:51 rivo volumio[3094]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 10 06:46:51 rivo volumio[3094]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 10 06:46:51 rivo volumio[3094]: TypeError: Cannot read property 'length' of undefined Sep 10 06:46:51 rivo volumio[3094]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Sep 10 06:46:51 rivo volumio[3094]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Sep 10 06:46:51 rivo volumio[3094]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Sep 10 06:46:51 rivo volumio[3094]: at Parser.emit (events.js:400:28) Sep 10 06:46:51 rivo volumio[3094]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Sep 10 06:46:51 rivo volumio[3094]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Sep 10 06:46:51 rivo volumio[3094]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Sep 10 06:46:51 rivo volumio[3094]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Sep 10 06:46:51 rivo volumio[3094]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Sep 10 06:46:51 rivo volumio[3094]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Sep 10 06:46:51 rivo volumio[3094]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Sep 10 06:46:51 rivo volumio[3094]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Sep 10 06:46:51 rivo volumio[3094]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Sep 10 06:46:51 rivo volumio[3094]: at IncomingMessage.emit (events.js:412:35) Sep 10 06:46:51 rivo volumio[3094]: at endReadableNT (internal/streams/readable.js:1333:12) Sep 10 06:46:51 rivo volumio[3094]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Sep 10 06:46:51 rivo volumio[3094]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 10 06:46:52 rivo sudo[6716]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-10 06:45 Sep 10 06:46:52 rivo sudo[6716]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="669bb6cc406bb77b11c5184fedb8a4dfd19ba4ec" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 11:43:09 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="fc7d09bc07ffd188bff4808d8f79c746"