Nov 01 08:08:00 volumio go-librespot[17306]: time="2025-11-01T08:08:00Z" level=debug msg="completed keyexchange" Nov 01 08:08:00 volumio go-librespot[17306]: time="2025-11-01T08:08:00Z" level=debug msg="completed challenge" Nov 01 08:08:00 volumio go-librespot[17306]: time="2025-11-01T08:08:00Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:08:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:08:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:08:01 volumio volumio[16875]: info: BOOT COMPLETED Nov 01 08:08:01 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 01 08:08:01 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:01 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 132. Nov 01 08:08:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:03 volumio go-librespot[17328]: go-librespot daemon starting... Nov 01 08:08:03 volumio go-librespot[17329]: time="2025-11-01T08:08:03Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:08:03 volumio go-librespot[17329]: time="2025-11-01T08:08:03Z" level=debug msg="app state loaded" Nov 01 08:08:03 volumio go-librespot[17329]: time="2025-11-01T08:08:03Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:08:03 volumio go-librespot[17329]: time="2025-11-01T08:08:03Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:08:03 volumio go-librespot[17329]: time="2025-11-01T08:08:03Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:08:03 volumio go-librespot[17329]: time="2025-11-01T08:08:03Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:08:03 volumio go-librespot[17329]: time="2025-11-01T08:08:03Z" level=info msg="zeroconf server listening on port 33935" Nov 01 08:08:03 volumio go-librespot[17329]: time="2025-11-01T08:08:03Z" level=debug msg="obtained new client token: AABIe+m9x3gQjQZvnksmkv1vfGQc4yDfJLlca352EYBp3LGUH6WWH9zJSMF3iOIhkoAaksoupQTT/qaVnhewZO8s2WB09z2xMDvaXJW03auolYeaUGkskGrOa/ZpSS/+K/iY3SHmz2MH3ODSgVf9i0+hIudz5XaBMc+1Jncv0lsXPxkp5mtJo4Ss7+wG9ejgfkfr8Eqv9U/fUXhZ+jOG6OoWaQjLgLE387Pk9ioHHamPbFdhHoKmkYc=" Nov 01 08:08:03 volumio go-librespot[17329]: time="2025-11-01T08:08:03Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:08:03 volumio go-librespot[17329]: time="2025-11-01T08:08:03Z" level=debug msg="completed keyexchange" Nov 01 08:08:03 volumio go-librespot[17329]: time="2025-11-01T08:08:03Z" level=debug msg="completed challenge" Nov 01 08:08:03 volumio go-librespot[17329]: time="2025-11-01T08:08:03Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:08:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:08:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:08:04 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:04 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 133. Nov 01 08:08:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:06 volumio go-librespot[17336]: go-librespot daemon starting... Nov 01 08:08:06 volumio go-librespot[17337]: time="2025-11-01T08:08:06Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:08:06 volumio go-librespot[17337]: time="2025-11-01T08:08:06Z" level=debug msg="app state loaded" Nov 01 08:08:06 volumio go-librespot[17337]: time="2025-11-01T08:08:06Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:08:06 volumio go-librespot[17337]: time="2025-11-01T08:08:06Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 01 08:08:06 volumio go-librespot[17337]: time="2025-11-01T08:08:06Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 01 08:08:06 volumio go-librespot[17337]: time="2025-11-01T08:08:06Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 01 08:08:06 volumio go-librespot[17337]: time="2025-11-01T08:08:06Z" level=info msg="zeroconf server listening on port 36969" Nov 01 08:08:06 volumio go-librespot[17337]: time="2025-11-01T08:08:06Z" level=debug msg="obtained new client token: AAC92slQlJVSVWYRcpoHZUE5r6ZO1+2BnZ3uT4whz/yn9Pta2wL/oXwfeive6vGHrVd+b3J2n9sg6d6miNcnMZYEr2nJNbOZF7bs/ZAd3ZgXasscNjNChQspTmrVDwcnovHwwrGpXxFEWuxaoSi9gr0LZNTE8ncuy3YZMfR+BY2aOINX5nMwX4IjNqtSXHOkz5hPBobajSUR9Cyq17cHURKUb9dNqTbhBQ7i2xhC07TI1sqTGpH12GE=" Nov 01 08:08:06 volumio go-librespot[17337]: time="2025-11-01T08:08:06Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:08:07 volumio go-librespot[17337]: time="2025-11-01T08:08:07Z" level=debug msg="completed keyexchange" Nov 01 08:08:07 volumio go-librespot[17337]: time="2025-11-01T08:08:07Z" level=debug msg="completed challenge" Nov 01 08:08:07 volumio go-librespot[17337]: time="2025-11-01T08:08:07Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:08:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:08:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:08:07 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:07 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:08 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 01 08:08:10 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:10 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 134. Nov 01 08:08:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:10 volumio go-librespot[17347]: go-librespot daemon starting... Nov 01 08:08:10 volumio go-librespot[17348]: time="2025-11-01T08:08:10Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:08:10 volumio go-librespot[17348]: time="2025-11-01T08:08:10Z" level=debug msg="app state loaded" Nov 01 08:08:10 volumio go-librespot[17348]: time="2025-11-01T08:08:10Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:08:10 volumio go-librespot[17348]: time="2025-11-01T08:08:10Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:08:10 volumio go-librespot[17348]: time="2025-11-01T08:08:10Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:08:10 volumio go-librespot[17348]: time="2025-11-01T08:08:10Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:08:10 volumio go-librespot[17348]: time="2025-11-01T08:08:10Z" level=info msg="zeroconf server listening on port 33187" Nov 01 08:08:10 volumio go-librespot[17348]: time="2025-11-01T08:08:10Z" level=debug msg="obtained new client token: AABlOE27oyQ3r31nM0zWrjrLatT4R+SzPZQXcAQ7ufu6bXgSk7wyS5XbmPHOV402BcR1TRm1YYvAqndYJKgISJRGRzfe0T+6d1klYjgkdvo0e/uW6HLdWXRyZIT50xkIoe7nV59hDBIOK8p//5iDohGAY7WPhh7GxR6ehj24t22+P4JvvTtVueFQAsNFp9fLPcl5rkq/jtlpRk2j48WBHXotgcsssEATGUJYVrbadSlG5YgjO/9HcMg=" Nov 01 08:08:10 volumio go-librespot[17348]: time="2025-11-01T08:08:10Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:08:10 volumio go-librespot[17348]: time="2025-11-01T08:08:10Z" level=debug msg="completed keyexchange" Nov 01 08:08:10 volumio go-librespot[17348]: time="2025-11-01T08:08:10Z" level=debug msg="completed challenge" Nov 01 08:08:10 volumio go-librespot[17348]: time="2025-11-01T08:08:10Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:08:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:08:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:08:13 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:13 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:13 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 01 08:08:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 135. Nov 01 08:08:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:13 volumio go-librespot[17369]: go-librespot daemon starting... Nov 01 08:08:13 volumio go-librespot[17370]: time="2025-11-01T08:08:13Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:08:13 volumio go-librespot[17370]: time="2025-11-01T08:08:13Z" level=debug msg="app state loaded" Nov 01 08:08:13 volumio go-librespot[17370]: time="2025-11-01T08:08:13Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:08:13 volumio go-librespot[17370]: time="2025-11-01T08:08:13Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:08:13 volumio go-librespot[17370]: time="2025-11-01T08:08:13Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:08:13 volumio go-librespot[17370]: time="2025-11-01T08:08:13Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:08:13 volumio go-librespot[17370]: time="2025-11-01T08:08:13Z" level=info msg="zeroconf server listening on port 45399" Nov 01 08:08:13 volumio go-librespot[17370]: time="2025-11-01T08:08:13Z" level=debug msg="obtained new client token: AAAWed8JRBg62iX1SP2al59IyNdOs6BX8XndH5DRGRW2H3d+k1Gdi7csfmyuUcvrQ0m20BW4S06hj7jVk5hSbxTzvTd0eYh/2vOgDSM3kC6R/FGGo4cBb4WocYSupW0yeegorey0Ui7pXWyuOd7kc2sb2qdjH80Mla9RZristq4NUVBZikl+0vovES35eal/N6Y7s6RvaxIm4wq8cweQL98XKbpUbD54ns27AZoB+0lfgC+7LAppVqY=" Nov 01 08:08:13 volumio go-librespot[17370]: time="2025-11-01T08:08:13Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:08:14 volumio go-librespot[17370]: time="2025-11-01T08:08:14Z" level=debug msg="completed keyexchange" Nov 01 08:08:14 volumio go-librespot[17370]: time="2025-11-01T08:08:14Z" level=debug msg="completed challenge" Nov 01 08:08:14 volumio go-librespot[17370]: time="2025-11-01T08:08:14Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:08:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:08:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:08:16 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:16 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 136. Nov 01 08:08:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:17 volumio go-librespot[17377]: go-librespot daemon starting... Nov 01 08:08:17 volumio go-librespot[17378]: time="2025-11-01T08:08:17Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:08:17 volumio go-librespot[17378]: time="2025-11-01T08:08:17Z" level=debug msg="app state loaded" Nov 01 08:08:17 volumio go-librespot[17378]: time="2025-11-01T08:08:17Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:08:17 volumio go-librespot[17378]: time="2025-11-01T08:08:17Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 01 08:08:17 volumio go-librespot[17378]: time="2025-11-01T08:08:17Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 01 08:08:17 volumio go-librespot[17378]: time="2025-11-01T08:08:17Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 01 08:08:17 volumio go-librespot[17378]: time="2025-11-01T08:08:17Z" level=info msg="zeroconf server listening on port 35455" Nov 01 08:08:17 volumio go-librespot[17378]: time="2025-11-01T08:08:17Z" level=debug msg="obtained new client token: AABsbCtifPxpjFlOs8ljSql4B8IQtDRkGOJDk86f74wWGtek46+Bp7RBAhJQb+PCERF82nafhvWXl3OPY868RupxQrjyd6Do/t9KpbrtnAfaImXwbaiAfofq5llMKXzEGqJlW/QKOjqfC8b9IANiu2cSSzI2XKPGUa2GjpXysfDwuLz942PNv51kdTGFeLPEZdkgQCEGotD6NbR9lngv0OgeYfE22lOzXPFtpxt/KUF3BhoXpp+I9bQ=" Nov 01 08:08:17 volumio go-librespot[17378]: time="2025-11-01T08:08:17Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:08:17 volumio go-librespot[17378]: time="2025-11-01T08:08:17Z" level=debug msg="completed keyexchange" Nov 01 08:08:17 volumio go-librespot[17378]: time="2025-11-01T08:08:17Z" level=debug msg="completed challenge" Nov 01 08:08:17 volumio go-librespot[17378]: time="2025-11-01T08:08:17Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:08:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:08:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:08:18 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 01 08:08:19 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:19 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 137. Nov 01 08:08:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:20 volumio go-librespot[17385]: go-librespot daemon starting... Nov 01 08:08:20 volumio go-librespot[17386]: time="2025-11-01T08:08:20Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:08:20 volumio go-librespot[17386]: time="2025-11-01T08:08:20Z" level=debug msg="app state loaded" Nov 01 08:08:20 volumio go-librespot[17386]: time="2025-11-01T08:08:20Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:08:20 volumio go-librespot[17386]: time="2025-11-01T08:08:20Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:08:20 volumio go-librespot[17386]: time="2025-11-01T08:08:20Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:08:20 volumio go-librespot[17386]: time="2025-11-01T08:08:20Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:08:20 volumio go-librespot[17386]: time="2025-11-01T08:08:20Z" level=info msg="zeroconf server listening on port 35021" Nov 01 08:08:20 volumio go-librespot[17386]: time="2025-11-01T08:08:20Z" level=debug msg="obtained new client token: AABChTBSBPEZ+bdSXkElBYJtt8VFRscpQaohuXjfwT6Xj/tnCyhqlkleUniCKHMvx4BKtsg70+QCw8Vqs+rdiRjxKpfjI/z+G3wycZrr9PUqDtgfsrH/72s7IP2+rPAECfmz9syUqusIpmoawIbSQwLbdqWOt+ou0N1jkYCaxt3CTQCwsTndwEv1TwmsYD0lgYiLhkc9H3JrNweoamiWDcrlvgV5Q4lHvAIoEdpgR0eQupisHSYy5sQ=" Nov 01 08:08:20 volumio go-librespot[17386]: time="2025-11-01T08:08:20Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:08:21 volumio go-librespot[17386]: time="2025-11-01T08:08:21Z" level=debug msg="completed keyexchange" Nov 01 08:08:21 volumio go-librespot[17386]: time="2025-11-01T08:08:21Z" level=debug msg="completed challenge" Nov 01 08:08:21 volumio go-librespot[17386]: time="2025-11-01T08:08:21Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:08:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:08:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:08:22 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:22 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 138. Nov 01 08:08:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:24 volumio go-librespot[17408]: go-librespot daemon starting... Nov 01 08:08:24 volumio go-librespot[17409]: time="2025-11-01T08:08:24Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:08:24 volumio go-librespot[17409]: time="2025-11-01T08:08:24Z" level=debug msg="app state loaded" Nov 01 08:08:24 volumio go-librespot[17409]: time="2025-11-01T08:08:24Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:08:24 volumio go-librespot[17409]: time="2025-11-01T08:08:24Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 01 08:08:24 volumio go-librespot[17409]: time="2025-11-01T08:08:24Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 01 08:08:24 volumio go-librespot[17409]: time="2025-11-01T08:08:24Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 01 08:08:24 volumio go-librespot[17409]: time="2025-11-01T08:08:24Z" level=info msg="zeroconf server listening on port 46233" Nov 01 08:08:24 volumio go-librespot[17409]: time="2025-11-01T08:08:24Z" level=debug msg="obtained new client token: AACjACfH+rkeJTtyGMTMfEMKPN/iBKjH8ylABbLpZGL7LWYvxMws57N/vOVAGfS4+4MKiCxsLxBWIJ9dtJb4gGTR6K2ACCH3Ud4Bhnnn0ngn3iU60beUDOPaOpDRAogF4nWu0Jhl5roFpCj3dUKXcfuvLbbG10gN2hT+4g+C2AXsh45g30q5XuCIl6RK/BvEiVkQjMZ6KPMoLglJaeLRPqGp3BamUR5ew/eRsrah5obN4e0aGle7v40=" Nov 01 08:08:24 volumio go-librespot[17409]: time="2025-11-01T08:08:24Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:08:24 volumio go-librespot[17409]: time="2025-11-01T08:08:24Z" level=debug msg="completed keyexchange" Nov 01 08:08:24 volumio go-librespot[17409]: time="2025-11-01T08:08:24Z" level=debug msg="completed challenge" Nov 01 08:08:24 volumio go-librespot[17409]: time="2025-11-01T08:08:24Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:08:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:08:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:08:25 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:25 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 139. Nov 01 08:08:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:27 volumio go-librespot[17416]: go-librespot daemon starting... Nov 01 08:08:27 volumio go-librespot[17417]: time="2025-11-01T08:08:27Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:08:27 volumio go-librespot[17417]: time="2025-11-01T08:08:27Z" level=debug msg="app state loaded" Nov 01 08:08:27 volumio go-librespot[17417]: time="2025-11-01T08:08:27Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:08:27 volumio go-librespot[17417]: time="2025-11-01T08:08:27Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:08:27 volumio go-librespot[17417]: time="2025-11-01T08:08:27Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:08:27 volumio go-librespot[17417]: time="2025-11-01T08:08:27Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:08:27 volumio go-librespot[17417]: time="2025-11-01T08:08:27Z" level=info msg="zeroconf server listening on port 33433" Nov 01 08:08:27 volumio go-librespot[17417]: time="2025-11-01T08:08:27Z" level=debug msg="obtained new client token: AACH2H8Tf8XeC+jiJYZLoSHvfZlQ5Q9hxwuIHFEaeqNmC8+G9VwGxurbLlr0T8DbN30DIEyL67HtWcDvVpjoMrk6XIBjSFw3GN34JEYJlfseXsORSXwVm2blLOPH8RllACzR0qjqqApyEF+mkNG9EdJm9647PO8E+hmus2XZzgHTCb50cldhm4yxILv7IgfNACZ2CWD/ZGKPDpQGEwbzenBp+Ej0GJpCsqRksb9lU0pui17LjSvvDGU=" Nov 01 08:08:27 volumio go-librespot[17417]: time="2025-11-01T08:08:27Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:08:28 volumio go-librespot[17417]: time="2025-11-01T08:08:28Z" level=debug msg="completed keyexchange" Nov 01 08:08:28 volumio go-librespot[17417]: time="2025-11-01T08:08:28Z" level=debug msg="completed challenge" Nov 01 08:08:28 volumio go-librespot[17417]: time="2025-11-01T08:08:28Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:08:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:08:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:08:28 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:28 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:31 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:31 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 140. Nov 01 08:08:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:31 volumio go-librespot[17427]: go-librespot daemon starting... Nov 01 08:08:31 volumio go-librespot[17428]: time="2025-11-01T08:08:31Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:08:31 volumio go-librespot[17428]: time="2025-11-01T08:08:31Z" level=debug msg="app state loaded" Nov 01 08:08:31 volumio go-librespot[17428]: time="2025-11-01T08:08:31Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:08:31 volumio go-librespot[17428]: time="2025-11-01T08:08:31Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:08:31 volumio go-librespot[17428]: time="2025-11-01T08:08:31Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:08:31 volumio go-librespot[17428]: time="2025-11-01T08:08:31Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:08:31 volumio go-librespot[17428]: time="2025-11-01T08:08:31Z" level=info msg="zeroconf server listening on port 46387" Nov 01 08:08:31 volumio go-librespot[17428]: time="2025-11-01T08:08:31Z" level=debug msg="obtained new client token: AAAUtP+QVO/petpCqA/vn/+quddJjizfA7LrMP/Gf7R7kkAYliNyMFPex6cpokPhZJLnlttCHXcPebwcZSzW+04ZhBEgfI0xE4Y+0qHRuilNRjxx7LeYf+L4G487unhrCN8r3w8G+TH4gqLh/RdrQ7LWTqlPa6cgVUvDheP7PRQpjbd2QdkQ1qBfSJOTAwnmXkspiHZiqNBtS72zJJt0aerVp0VF5I7/VOIb3zxvBUMpXxGbB2a3Nc0=" Nov 01 08:08:31 volumio go-librespot[17428]: time="2025-11-01T08:08:31Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:08:31 volumio go-librespot[17428]: time="2025-11-01T08:08:31Z" level=debug msg="completed keyexchange" Nov 01 08:08:31 volumio go-librespot[17428]: time="2025-11-01T08:08:31Z" level=debug msg="completed challenge" Nov 01 08:08:31 volumio go-librespot[17428]: time="2025-11-01T08:08:31Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:08:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:08:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:08:34 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:34 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:34 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 01 08:08:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 141. Nov 01 08:08:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:34 volumio go-librespot[17450]: go-librespot daemon starting... Nov 01 08:08:34 volumio go-librespot[17451]: time="2025-11-01T08:08:34Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:08:34 volumio go-librespot[17451]: time="2025-11-01T08:08:34Z" level=debug msg="app state loaded" Nov 01 08:08:34 volumio go-librespot[17451]: time="2025-11-01T08:08:34Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:08:34 volumio go-librespot[17451]: time="2025-11-01T08:08:34Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:08:34 volumio go-librespot[17451]: time="2025-11-01T08:08:34Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:08:34 volumio go-librespot[17451]: time="2025-11-01T08:08:34Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:08:34 volumio go-librespot[17451]: time="2025-11-01T08:08:34Z" level=info msg="zeroconf server listening on port 46241" Nov 01 08:08:34 volumio go-librespot[17451]: time="2025-11-01T08:08:34Z" level=debug msg="obtained new client token: AABXUxOcv2tvDkogVSDeWciSAux9VxReYHkQc+UiQDgQdE1f0qOUNm1Od4OpubNSPa9H8Z3vmDrzo2vMeNEj9uXfRnSU6unkNZL1nmJUqo2hhNyoRB+tg1kUO2UIlMmmpokbHFYK/XufQoI44CGDEsZlvSF/S/kAt+VzWFumr7h+8MqN9mmm5/VH2FthMWW1ieo0qf/DnuZzXsQcr2wbZrsibkGCmzIDJXwIGfnEjALOu83s/h9zL+0=" Nov 01 08:08:34 volumio go-librespot[17451]: time="2025-11-01T08:08:34Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:08:34 volumio go-librespot[17451]: time="2025-11-01T08:08:34Z" level=debug msg="completed keyexchange" Nov 01 08:08:34 volumio go-librespot[17451]: time="2025-11-01T08:08:34Z" level=debug msg="completed challenge" Nov 01 08:08:35 volumio go-librespot[17451]: time="2025-11-01T08:08:35Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:08:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:08:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:08:37 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:37 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 142. Nov 01 08:08:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:38 volumio go-librespot[17458]: go-librespot daemon starting... Nov 01 08:08:38 volumio go-librespot[17459]: time="2025-11-01T08:08:38Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:08:38 volumio go-librespot[17459]: time="2025-11-01T08:08:38Z" level=debug msg="app state loaded" Nov 01 08:08:38 volumio go-librespot[17459]: time="2025-11-01T08:08:38Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:08:38 volumio go-librespot[17459]: time="2025-11-01T08:08:38Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 01 08:08:38 volumio go-librespot[17459]: time="2025-11-01T08:08:38Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 01 08:08:38 volumio go-librespot[17459]: time="2025-11-01T08:08:38Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 01 08:08:38 volumio go-librespot[17459]: time="2025-11-01T08:08:38Z" level=info msg="zeroconf server listening on port 41479" Nov 01 08:08:38 volumio go-librespot[17459]: time="2025-11-01T08:08:38Z" level=debug msg="obtained new client token: AABS/GNCXEEAZnEOt6GbWNRO6ELB8Oh0rmtW0lDF1QhlkwIWyv8/xMZsH1FVfFGMP6LgpXQNl5TnM321pv+GEEskIAlmgHPGiAHKW9F6MV5dRDa359yBZHOE/0JQpV7xzYOQdGN8S7mEZFF9LQHAoJhjGHMxb5pckYaQH/l9zReaGi7pygtPOyT/oWd39UVNvTHb2m9erPUtpXRWXqpfNKFfUkFGTHvqds/4hzvd3Xsj53UqVVk83iU=" Nov 01 08:08:38 volumio go-librespot[17459]: time="2025-11-01T08:08:38Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:08:38 volumio go-librespot[17459]: time="2025-11-01T08:08:38Z" level=debug msg="completed keyexchange" Nov 01 08:08:38 volumio go-librespot[17459]: time="2025-11-01T08:08:38Z" level=debug msg="completed challenge" Nov 01 08:08:38 volumio go-librespot[17459]: time="2025-11-01T08:08:38Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:08:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:08:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:08:40 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:40 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 143. Nov 01 08:08:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:41 volumio go-librespot[17466]: go-librespot daemon starting... Nov 01 08:08:41 volumio go-librespot[17467]: time="2025-11-01T08:08:41Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:08:41 volumio go-librespot[17467]: time="2025-11-01T08:08:41Z" level=debug msg="app state loaded" Nov 01 08:08:41 volumio go-librespot[17467]: time="2025-11-01T08:08:41Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:08:41 volumio go-librespot[17467]: time="2025-11-01T08:08:41Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:08:41 volumio go-librespot[17467]: time="2025-11-01T08:08:41Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:08:41 volumio go-librespot[17467]: time="2025-11-01T08:08:41Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:08:41 volumio go-librespot[17467]: time="2025-11-01T08:08:41Z" level=info msg="zeroconf server listening on port 37029" Nov 01 08:08:41 volumio go-librespot[17467]: time="2025-11-01T08:08:41Z" level=debug msg="obtained new client token: AAAwrkejdLr4SzAhkrkqcZdh0iQnOx8y5ye28KxTlGU95GvjGoGFZhcmgvbdyfknyEvyXoy31i6ORRhylKQ971IZ+R1DMgFAwYisfFBK/xH80C1hAo4AQHwkfsIz6uJPYy7ls8aSw8etYKzAPLgWYrf4lh/6jblHLkGLnP4ZyXwfmCxxN6ULTNkrTWqsGJSz68AftKmsQuiQ4bK5aiqWNHJY8lPm2ZADAXgFEScKXkKYDEwyGd8CSAI=" Nov 01 08:08:41 volumio go-librespot[17467]: time="2025-11-01T08:08:41Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:08:41 volumio go-librespot[17467]: time="2025-11-01T08:08:41Z" level=debug msg="completed keyexchange" Nov 01 08:08:41 volumio go-librespot[17467]: time="2025-11-01T08:08:41Z" level=debug msg="completed challenge" Nov 01 08:08:42 volumio go-librespot[17467]: time="2025-11-01T08:08:42Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:08:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:08:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:08:43 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:43 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:44 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 01 08:08:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 144. Nov 01 08:08:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:45 volumio go-librespot[17489]: go-librespot daemon starting... Nov 01 08:08:45 volumio go-librespot[17490]: time="2025-11-01T08:08:45Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:08:45 volumio go-librespot[17490]: time="2025-11-01T08:08:45Z" level=debug msg="app state loaded" Nov 01 08:08:45 volumio go-librespot[17490]: time="2025-11-01T08:08:45Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:08:45 volumio go-librespot[17490]: time="2025-11-01T08:08:45Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:08:45 volumio go-librespot[17490]: time="2025-11-01T08:08:45Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:08:45 volumio go-librespot[17490]: time="2025-11-01T08:08:45Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:08:45 volumio go-librespot[17490]: time="2025-11-01T08:08:45Z" level=info msg="zeroconf server listening on port 35947" Nov 01 08:08:45 volumio go-librespot[17490]: time="2025-11-01T08:08:45Z" level=debug msg="obtained new client token: AAA59yjacIQxZiQMaSM64oPtktXJFBuG0QbODH3X9yk73FVlRg2YiOSRuvYPQv29tOT+/bzhxBLZgPJpHPCfayVQr2DRbk33CzVQqGWhjH68+ePQV2O8iA2aQ83RdinDD6VQqq/ZPg0Wtrgbnr7CvrFpnsFwAIrHeaUs2iYyyJ5eWM6yIh7bVcJHj9jY+9USvBOrDbWbE/YOE5RuRmCizpNusIucbgcpb1Lw9P01NiWR68wzA6WrToY=" Nov 01 08:08:45 volumio go-librespot[17490]: time="2025-11-01T08:08:45Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:08:45 volumio go-librespot[17490]: time="2025-11-01T08:08:45Z" level=debug msg="completed keyexchange" Nov 01 08:08:45 volumio go-librespot[17490]: time="2025-11-01T08:08:45Z" level=debug msg="completed challenge" Nov 01 08:08:45 volumio go-librespot[17490]: time="2025-11-01T08:08:45Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:08:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:08:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:08:46 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:46 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 145. Nov 01 08:08:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:48 volumio go-librespot[17501]: go-librespot daemon starting... Nov 01 08:08:48 volumio go-librespot[17502]: time="2025-11-01T08:08:48Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:08:48 volumio go-librespot[17502]: time="2025-11-01T08:08:48Z" level=debug msg="app state loaded" Nov 01 08:08:48 volumio go-librespot[17502]: time="2025-11-01T08:08:48Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:08:48 volumio go-librespot[17502]: time="2025-11-01T08:08:48Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 01 08:08:48 volumio go-librespot[17502]: time="2025-11-01T08:08:48Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 01 08:08:48 volumio go-librespot[17502]: time="2025-11-01T08:08:48Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 01 08:08:48 volumio go-librespot[17502]: time="2025-11-01T08:08:48Z" level=info msg="zeroconf server listening on port 42591" Nov 01 08:08:48 volumio go-librespot[17502]: time="2025-11-01T08:08:48Z" level=debug msg="obtained new client token: AABM3nHwBDP1RHapVKXdXEj/rs41FOI9TenAw/IN8Rcfhlf55snVqC2mUcr/JuDi69ZS64/ZqPxSRIqrMf0qYbLhAS/M/yMZclfDHo4ZmfyiFRKDCu7onV4+/PuPoC2Q0AUrcbpGs6ok4pRQk8XyEHNMrUgOrDARNtMPWw8DcYb9NEolXiQiCWrIBpa3Aq7eIbwKooL59EZTRheJP+oL5pQ0FhkZC/rLL1ZdU0zesdnqzM9tzXebvhU=" Nov 01 08:08:48 volumio go-librespot[17502]: time="2025-11-01T08:08:48Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:08:48 volumio go-librespot[17502]: time="2025-11-01T08:08:48Z" level=debug msg="completed keyexchange" Nov 01 08:08:48 volumio go-librespot[17502]: time="2025-11-01T08:08:48Z" level=debug msg="completed challenge" Nov 01 08:08:49 volumio go-librespot[17502]: time="2025-11-01T08:08:49Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:08:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:08:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:08:49 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:49 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:52 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:52 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 146. Nov 01 08:08:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:52 volumio go-librespot[17509]: go-librespot daemon starting... Nov 01 08:08:52 volumio go-librespot[17510]: time="2025-11-01T08:08:52Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:08:52 volumio go-librespot[17510]: time="2025-11-01T08:08:52Z" level=debug msg="app state loaded" Nov 01 08:08:52 volumio go-librespot[17510]: time="2025-11-01T08:08:52Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:08:52 volumio go-librespot[17510]: time="2025-11-01T08:08:52Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 01 08:08:52 volumio go-librespot[17510]: time="2025-11-01T08:08:52Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 01 08:08:52 volumio go-librespot[17510]: time="2025-11-01T08:08:52Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 01 08:08:52 volumio go-librespot[17510]: time="2025-11-01T08:08:52Z" level=info msg="zeroconf server listening on port 42143" Nov 01 08:08:52 volumio go-librespot[17510]: time="2025-11-01T08:08:52Z" level=debug msg="obtained new client token: AADtX/hb0J0f4WY1x35w93C/EjitJuBPVxY7E4KHApPPtMXyUYxPIalM6iJrRy+BNISuYBOPhIgr8z3PbAOWp/YfSbTfY9X9zQPS3IwOxvjZ4eANKkTPMf6agRkz6s3VmLXNrzIcpa+e5HYu690NRIgZbX+FeRgbuaP8G2miKjJebXFPk8OsgTbK+ERCjYV60h9kl1ldvqEqqdBNjM7fgT3QysTQye77g/XlWM0iU9UYxZ0nBdV7HGU=" Nov 01 08:08:52 volumio go-librespot[17510]: time="2025-11-01T08:08:52Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:08:52 volumio go-librespot[17510]: time="2025-11-01T08:08:52Z" level=debug msg="completed keyexchange" Nov 01 08:08:52 volumio go-librespot[17510]: time="2025-11-01T08:08:52Z" level=debug msg="completed challenge" Nov 01 08:08:52 volumio go-librespot[17510]: time="2025-11-01T08:08:52Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:08:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:08:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:08:55 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:55 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 147. Nov 01 08:08:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:55 volumio go-librespot[17531]: go-librespot daemon starting... Nov 01 08:08:55 volumio go-librespot[17532]: time="2025-11-01T08:08:55Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:08:55 volumio go-librespot[17532]: time="2025-11-01T08:08:55Z" level=debug msg="app state loaded" Nov 01 08:08:55 volumio go-librespot[17532]: time="2025-11-01T08:08:55Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:08:55 volumio go-librespot[17532]: time="2025-11-01T08:08:55Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:08:55 volumio go-librespot[17532]: time="2025-11-01T08:08:55Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:08:55 volumio go-librespot[17532]: time="2025-11-01T08:08:55Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:08:55 volumio go-librespot[17532]: time="2025-11-01T08:08:55Z" level=info msg="zeroconf server listening on port 39817" Nov 01 08:08:55 volumio go-librespot[17532]: time="2025-11-01T08:08:55Z" level=debug msg="obtained new client token: AAA5K/3fM40Wqw13DaJzv3M+yUDZFSfumRcErDFVAOI7lUfQF7OgtUBcOuS1ryK74fG1CiP/mPs2Le0ZVjg9wz3b61m9A3/FqSIsDZ6qsShKe8yKjvptRVZEAzDOjGmf1x8Dbu1MwKylywFBxNaC1fXdJzNkrdZeGIaet8Ck/L7/cyHSn7/I3stbxjrKMelohWZdfFsh6dTKQHepjfzILNA5wRwtbn9y7q87MUa42iaTgzP2OvH9qqE=" Nov 01 08:08:55 volumio go-librespot[17532]: time="2025-11-01T08:08:55Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:08:55 volumio go-librespot[17532]: time="2025-11-01T08:08:55Z" level=debug msg="completed keyexchange" Nov 01 08:08:55 volumio go-librespot[17532]: time="2025-11-01T08:08:55Z" level=debug msg="completed challenge" Nov 01 08:08:56 volumio go-librespot[17532]: time="2025-11-01T08:08:56Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:08:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:08:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:08:58 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:08:58 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:08:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 148. Nov 01 08:08:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:08:59 volumio go-librespot[17539]: go-librespot daemon starting... Nov 01 08:08:59 volumio go-librespot[17540]: time="2025-11-01T08:08:59Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:08:59 volumio go-librespot[17540]: time="2025-11-01T08:08:59Z" level=debug msg="app state loaded" Nov 01 08:08:59 volumio go-librespot[17540]: time="2025-11-01T08:08:59Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:08:59 volumio go-librespot[17540]: time="2025-11-01T08:08:59Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:08:59 volumio go-librespot[17540]: time="2025-11-01T08:08:59Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:08:59 volumio go-librespot[17540]: time="2025-11-01T08:08:59Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:08:59 volumio go-librespot[17540]: time="2025-11-01T08:08:59Z" level=info msg="zeroconf server listening on port 39571" Nov 01 08:08:59 volumio go-librespot[17540]: time="2025-11-01T08:08:59Z" level=debug msg="obtained new client token: AABbFf3Hr/7fIxfDDKa0WHXSeWU5Fmsh0fTNgWqWrMyELmkwYvZP/nDN+Fq9iVDZjleXP8uJUgGJ6KYf7aA2iSoi2lileVKgifDeiKpmzTQdr5NMPRh/6YHqS4xNkTwXYBOc3VxnpQ2j9Bl/01hKxINOoOV3IqklDZk1A7+9tokhNEgW6r6ucqiU7+k5/tTgkrCGBjylD7ruPAwyRWtJhmuLDvjt9kuY4NhzyPcVaMBi5rG8zTVqZqM=" Nov 01 08:08:59 volumio go-librespot[17540]: time="2025-11-01T08:08:59Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:08:59 volumio go-librespot[17540]: time="2025-11-01T08:08:59Z" level=debug msg="completed keyexchange" Nov 01 08:08:59 volumio go-librespot[17540]: time="2025-11-01T08:08:59Z" level=debug msg="completed challenge" Nov 01 08:08:59 volumio go-librespot[17540]: time="2025-11-01T08:08:59Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:08:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:08:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:08:59 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 01 08:09:01 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:09:01 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:09:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 149. Nov 01 08:09:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:02 volumio go-librespot[17561]: go-librespot daemon starting... Nov 01 08:09:02 volumio go-librespot[17562]: time="2025-11-01T08:09:02Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:09:02 volumio go-librespot[17562]: time="2025-11-01T08:09:02Z" level=debug msg="app state loaded" Nov 01 08:09:02 volumio go-librespot[17562]: time="2025-11-01T08:09:02Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:09:02 volumio go-librespot[17562]: time="2025-11-01T08:09:02Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:09:02 volumio go-librespot[17562]: time="2025-11-01T08:09:02Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:09:02 volumio go-librespot[17562]: time="2025-11-01T08:09:02Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:09:02 volumio go-librespot[17562]: time="2025-11-01T08:09:02Z" level=info msg="zeroconf server listening on port 37161" Nov 01 08:09:02 volumio go-librespot[17562]: time="2025-11-01T08:09:02Z" level=debug msg="obtained new client token: AAAhPmnVMN7BS7SoT+Vpz8rFrblx3TmQJxqQQwXaaj9muTVlTlnWkTYi/PhJy78mOEOsNdGVl8FpSc68fyXTi/0ItN0siUtDLol7xy0sjRCSktuFpxvAjrY/NeXUaO4Cd89U5DgklRf9sLWOGV8FdTL5+ZVZajNzDaU62oWHNAY/fR6pfyruJHZ69D5TwPE7dW3rRkABCkpD6dyGZ9czDKeaZ8u46jcMY/U+l0RE6Sga0iViIRaWsYU=" Nov 01 08:09:02 volumio go-librespot[17562]: time="2025-11-01T08:09:02Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:09:02 volumio go-librespot[17562]: time="2025-11-01T08:09:02Z" level=debug msg="completed keyexchange" Nov 01 08:09:02 volumio go-librespot[17562]: time="2025-11-01T08:09:02Z" level=debug msg="completed challenge" Nov 01 08:09:03 volumio go-librespot[17562]: time="2025-11-01T08:09:03Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:09:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:09:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:09:04 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:09:04 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:09:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 150. Nov 01 08:09:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:06 volumio go-librespot[17569]: go-librespot daemon starting... Nov 01 08:09:06 volumio go-librespot[17570]: time="2025-11-01T08:09:06Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:09:06 volumio go-librespot[17570]: time="2025-11-01T08:09:06Z" level=debug msg="app state loaded" Nov 01 08:09:06 volumio go-librespot[17570]: time="2025-11-01T08:09:06Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:09:06 volumio go-librespot[17570]: time="2025-11-01T08:09:06Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:09:06 volumio go-librespot[17570]: time="2025-11-01T08:09:06Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:09:06 volumio go-librespot[17570]: time="2025-11-01T08:09:06Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:09:06 volumio go-librespot[17570]: time="2025-11-01T08:09:06Z" level=info msg="zeroconf server listening on port 39971" Nov 01 08:09:06 volumio go-librespot[17570]: time="2025-11-01T08:09:06Z" level=debug msg="obtained new client token: AABcuHjd6CFmE18XdI45OhD1sCp1r/N7bJ2sjKN687NMDWSNVY39wn5JpxYCwULbEJrCsLlLfoXiBjhFsmOP1ydOs+ddhGR/KFBd6p0bbRLG5pPxFf0fXeNPtZBvjQBUfEpkhIfRHHrrAaRXqtAhZTYjKj2bciJ2JAm1BePOLhyv7lSmB/k1eyvjtMp3pM1dV60RtB4jg8UnLWLpmPw7At4Lz+NbdaGafZMMXpLcTigmVaN4270glag=" Nov 01 08:09:06 volumio go-librespot[17570]: time="2025-11-01T08:09:06Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:09:06 volumio go-librespot[17570]: time="2025-11-01T08:09:06Z" level=debug msg="completed keyexchange" Nov 01 08:09:06 volumio go-librespot[17570]: time="2025-11-01T08:09:06Z" level=debug msg="completed challenge" Nov 01 08:09:06 volumio go-librespot[17570]: time="2025-11-01T08:09:06Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:09:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:09:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:09:07 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:09:07 volumio volumio[16875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:09:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 151. Nov 01 08:09:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:09 volumio go-librespot[17581]: go-librespot daemon starting... Nov 01 08:09:09 volumio go-librespot[17582]: time="2025-11-01T08:09:09Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:09:09 volumio go-librespot[17582]: time="2025-11-01T08:09:09Z" level=debug msg="app state loaded" Nov 01 08:09:09 volumio go-librespot[17582]: time="2025-11-01T08:09:09Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:09:10 volumio volumio[16875]: info: Initializing connection to go-librespot Websocket Nov 01 08:09:10 volumio go-librespot[17582]: time="2025-11-01T08:09:10Z" level=debug msg="new websocket client" Nov 01 08:09:10 volumio volumio[16875]: info: Connection to go-librespot Websocket established Nov 01 08:09:13 volumio volumio[16875]: info: Getting Spotify volume Nov 01 08:09:13 volumio volumio[16875]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Nov 01 08:09:13 volumio go-librespot[17582]: time="2025-11-01T08:09:13Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:09:13 volumio go-librespot[17582]: time="2025-11-01T08:09:13Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:09:13 volumio go-librespot[17582]: time="2025-11-01T08:09:13Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:09:13 volumio go-librespot[17582]: time="2025-11-01T08:09:13Z" level=info msg="zeroconf server listening on port 36093" Nov 01 08:09:13 volumio volumio[16875]: info: CoreCommandRouter::volumioGetState Nov 01 08:09:13 volumio volumio[16875]: info: CorePlayQueue::getTrack 0 Nov 01 08:09:13 volumio volumio[16875]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 Nov 01 08:09:13 volumio volumio[16875]: SPOTIFY: SPOTIFY VOLUME undefined Nov 01 08:09:13 volumio volumio[16875]: SPOTIFY: VOLUMIO VOLUME 33 Nov 01 08:09:13 volumio volumio[16875]: info: Aligning Spotify Volume to Volumio Volume Nov 01 08:09:13 volumio volumio[16875]: info: CoreCommandRouter::volumioGetState Nov 01 08:09:13 volumio volumio[16875]: info: CorePlayQueue::getTrack 0 Nov 01 08:09:13 volumio volumio[16875]: info: Setting Spotify Volume from Volumio: 33 Nov 01 08:09:13 volumio go-librespot[17582]: time="2025-11-01T08:09:13Z" level=debug msg="obtained new client token: AAC+0KbmLOo2ZPmg6gbeuLaxNFEWvmMgUEhjyMyc9AykX/FEyehYawvsfLCeAq42zVeGBmGh/EYmnfqQmsCQJ1k8/l7FtF3URetqZN0viBzcmOjDLa4Ki/LNvY9HbGwndqNkaTCjfWGT1PWovBp42bp7qMAUfIZhmAa/e7SJsRic/sRc82xBqSIQRuT7faR8hhglORZmDmPUTZ3zDbIFy/cvBp63QNyqRAHjzulDvE1fCe56bgf2" Nov 01 08:09:13 volumio go-librespot[17582]: time="2025-11-01T08:09:13Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:09:13 volumio go-librespot[17582]: time="2025-11-01T08:09:13Z" level=debug msg="completed keyexchange" Nov 01 08:09:13 volumio go-librespot[17582]: time="2025-11-01T08:09:13Z" level=debug msg="completed challenge" Nov 01 08:09:13 volumio go-librespot[17582]: time="2025-11-01T08:09:13Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:09:13 volumio volumio[16875]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 08:09:13 volumio volumio[16875]: Error: socket hang up Nov 01 08:09:13 volumio volumio[16875]: at connResetException (node:internal/errors:720:14) Nov 01 08:09:13 volumio volumio[16875]: at Socket.socketOnEnd (node:_http_client:519:23) Nov 01 08:09:13 volumio volumio[16875]: at Socket.emit (node:events:526:35) Nov 01 08:09:13 volumio volumio[16875]: at endReadableNT (node:internal/streams/readable:1376:12) Nov 01 08:09:13 volumio volumio[16875]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Nov 01 08:09:13 volumio volumio[16875]: code: 'ECONNRESET', Nov 01 08:09:13 volumio volumio[16875]: response: undefined Nov 01 08:09:13 volumio volumio[16875]: } Nov 01 08:09:13 volumio volumio[16875]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 08:09:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:09:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:09:13 volumio sudo[17617]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-11-01 08:08' Nov 01 08:09:13 volumio sudo[17617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:13 volumio sudo[17617]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:13 volumio volumio-remote-updater[874]: [2025-11-01 08:09:13] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Nov 01 08:09:13 volumio volumio-remote-updater[874]: [2025-11-01 08:09:13] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Nov 01 08:09:13 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:09:13 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Nov 01 08:09:13 volumio systemd[1]: volumio.service: Consumed 8.397s CPU time. Nov 01 08:09:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Nov 01 08:09:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Nov 01 08:09:13 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4463. Nov 01 08:09:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Nov 01 08:09:13 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Nov 01 08:09:13 volumio systemd[1]: volumio.service: Consumed 8.397s CPU time. Nov 01 08:09:13 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Nov 01 08:09:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Nov 01 08:09:14 volumio volumio[17639]: info: ------------------------------------------- Nov 01 08:09:14 volumio volumio[17639]: info: ----- Volumio3 ---- Nov 01 08:09:14 volumio volumio[17639]: info: ------------------------------------------- Nov 01 08:09:14 volumio volumio[17639]: info: ----- System startup ---- Nov 01 08:09:14 volumio volumio[17639]: info: ------------------------------------------- Nov 01 08:09:14 volumio volumio[17639]: info: MYVOLUMIO Environment detected Nov 01 08:09:14 volumio volumio[17639]: info: Plugin folders cleanup Nov 01 08:09:14 volumio volumio[17639]: info: Scanning into folder /volumio/app/plugins/ Nov 01 08:09:14 volumio volumio[17639]: info: Scanning category audio_interface Nov 01 08:09:14 volumio volumio[17639]: info: Scanning category miscellanea Nov 01 08:09:14 volumio volumio[17639]: info: Scanning category music_service Nov 01 08:09:14 volumio volumio[17639]: info: Scanning category plugins.json Nov 01 08:09:14 volumio volumio[17639]: info: Scanning category system_controller Nov 01 08:09:14 volumio volumio[17639]: info: Scanning category user_interface Nov 01 08:09:14 volumio volumio[17639]: info: Scanning into folder /data/plugins/ Nov 01 08:09:14 volumio volumio[17639]: info: Scanning category music_service Nov 01 08:09:14 volumio volumio[17639]: info: Scanning category user_interface Nov 01 08:09:14 volumio volumio[17639]: info: Plugin folders cleanup completed Nov 01 08:09:14 volumio volumio[17639]: info: ------------------------------------------- Nov 01 08:09:14 volumio volumio[17639]: info: ----- Core plugins startup ---- Nov 01 08:09:14 volumio volumio[17639]: info: ------------------------------------------- Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugins from folder /volumio/app/plugins/ Nov 01 08:09:14 volumio volumio[17639]: info: Adding plugin upnp to MyMusic Plugins Nov 01 08:09:14 volumio volumio[17639]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 01 08:09:14 volumio volumio[17639]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugins from folder /data/plugins/ Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "system"... Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "appearance"... Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "network"... Nov 01 08:09:14 volumio volumio[17639]: info: Refreshing Cached IP Addresses Nov 01 08:09:14 volumio sudo[17664]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 01 08:09:14 volumio sudo[17664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:14 volumio sudo[17664]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "services"... Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "alsa_controller"... Nov 01 08:09:14 volumio sudo[17666]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 01 08:09:14 volumio sudo[17666]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:14 volumio sudo[17666]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:14 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "wizard"... Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "networkfs"... Nov 01 08:09:14 volumio volumio[17639]: info: Cannot mount NAS NAS at system boot, trial number 1 ,retrying in 5 seconds Nov 01 08:09:14 volumio volumio[17639]: info: Starting Udev Watcher for removable devices Nov 01 08:09:14 volumio volumio[17639]: info: Ignoring mount for partition: boot Nov 01 08:09:14 volumio volumio[17639]: info: Ignoring mount for partition: volumio Nov 01 08:09:14 volumio volumio[17639]: info: Ignoring mount for partition: volumio_data Nov 01 08:09:14 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "volumio_command_line_client"... Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "upnp"... Nov 01 08:09:14 volumio volumio[17639]: info: [1761984554552] Starting Upmpd Daemon Nov 01 08:09:14 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "my_music"... Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "mpd"... Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "upnp_browser"... Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "alarm-clock"... Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "airplay_emulation"... Nov 01 08:09:14 volumio volumio[17639]: info: Starting Shairport Sync Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "last_100"... Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "webradio"... Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "i2s_dacs"... Nov 01 08:09:14 volumio volumio[17639]: info: I2S DAC not set, start Auto-detection Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "volumiodiscovery"... Nov 01 08:09:14 volumio volumio[17639]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 01 08:09:14 volumio volumio[17639]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 08:09:14 volumio volumio[17639]: *** WARNING *** For more information see Nov 01 08:09:14 volumio volumio[17639]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 01 08:09:14 volumio volumio[17639]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 08:09:14 volumio volumio[17639]: *** WARNING *** For more information see Nov 01 08:09:14 volumio node[17639]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 01 08:09:14 volumio node[17639]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 08:09:14 volumio node[17639]: *** WARNING *** For more information see Nov 01 08:09:14 volumio node[17639]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 01 08:09:14 volumio node[17639]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 08:09:14 volumio node[17639]: *** WARNING *** For more information see Nov 01 08:09:14 volumio volumio[17639]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 01 08:09:14 volumio volumio[17639]: info: Discovery: Started advertising with name: Volumio Nov 01 08:09:14 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 08:09:14 volumio volumio[17639]: info: Loading plugin "spop"... Nov 01 08:09:15 volumio volumio[17639]: info: Loading plugin "ytcr"... Nov 01 08:09:15 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 01 08:09:15 volumio volumio[17639]: info: Loading plugin "outputs"... Nov 01 08:09:15 volumio volumio[17639]: info: Loading plugin "albumart"... Nov 01 08:09:15 volumio volumio[17639]: info: Plugin example_plugin is not enabled Nov 01 08:09:15 volumio volumio[17639]: info: Loading plugin "inputs"... Nov 01 08:09:15 volumio volumio[17639]: info: Loading plugin "updater_comm"... Nov 01 08:09:15 volumio volumio[17639]: info: Plugin mpdemulation is not enabled Nov 01 08:09:15 volumio volumio[17639]: info: Loading plugin "rest_api"... Nov 01 08:09:15 volumio volumio[17639]: info: Loading plugin "websocket"... Nov 01 08:09:15 volumio volumio[17639]: info: Starting Socket.io Server version 1.7.4 Nov 01 08:09:15 volumio volumio[17639]: info: Loading plugin "Systeminfo"... Nov 01 08:09:15 volumio volumio[17639]: info: Loading i18n strings for locale en Nov 01 08:09:15 volumio volumio[17639]: Updating browse sources language Nov 01 08:09:15 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 08:09:15 volumio volumio[17696]: Forking 3 albumart workers Nov 01 08:09:15 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 08:09:15 volumio volumio[17639]: info: CoreCommandRouter::initPlayerControls Nov 01 08:09:15 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:15 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:15 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:15 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:15 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:15 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:15 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:15 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:15 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 08:09:15 volumio volumio[17639]: Express server listening on port 3000 Nov 01 08:09:15 volumio volumio[17639]: [Metrics] WebUI: 1s 933.86ms Nov 01 08:09:15 volumio volumio[17639]: info: CoreStateMachine::resetVolumioState Nov 01 08:09:15 volumio volumio[17639]: info: CoreStateMachine::getcurrentVolume Nov 01 08:09:15 volumio volumio[17639]: info: CoreCommandRouter::volumioRetrievevolume Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: Cannot read play queue from file Nov 01 08:09:16 volumio volumio[17639]: info: Volumio Network Manager: Network status updated: 1 Nov 01 08:09:16 volumio volumio[17639]: info: VolumeController:: Volume=33 Mute =false Nov 01 08:09:16 volumio volumio[17639]: info: CoreStateMachine::pushState Nov 01 08:09:16 volumio volumio[17639]: info: CorePlayQueue::getTrack 0 Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::volumioPushState Nov 01 08:09:16 volumio volumio[17639]: info: CoreStateMachine::updateTrackBlock Nov 01 08:09:16 volumio volumio[17639]: info: CorePlayQueue::getTrackBlock Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::volumioRetrievevolume Nov 01 08:09:16 volumio volumio[17639]: info: CoreStateMachine::setRepeat null single undefined Nov 01 08:09:16 volumio volumio[17639]: info: CoreStateMachine::pushState Nov 01 08:09:16 volumio volumio[17639]: info: CorePlayQueue::getTrack 0 Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::volumioPushState Nov 01 08:09:16 volumio volumio[17639]: info: CoreStateMachine::setRandom null Nov 01 08:09:16 volumio volumio[17639]: info: CoreStateMachine::pushState Nov 01 08:09:16 volumio volumio[17639]: info: CorePlayQueue::getTrack 0 Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::volumioPushState Nov 01 08:09:16 volumio volumio[17639]: info: Setting Device type: Raspberry PI Nov 01 08:09:16 volumio volumio[17639]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Nov 01 08:09:16 volumio volumio[17639]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b04170 Nov 01 08:09:16 volumio volumio[17639]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Nov 01 08:09:16 volumio volumio[17639]: info: VolumeController:: Volume=33 Mute =false Nov 01 08:09:16 volumio volumio[17639]: info: CoreStateMachine::pushState Nov 01 08:09:16 volumio volumio[17639]: info: CorePlayQueue::getTrack 0 Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::volumioPushState Nov 01 08:09:16 volumio volumio[17639]: info: Completed loading Core Plugins Nov 01 08:09:16 volumio volumio[17639]: info: Preparing to generate the ALSA configuration file Nov 01 08:09:16 volumio volumio[17639]: info: Asound.conf file unchanged, so no further update is needed Nov 01 08:09:16 volumio volumio[17639]: info: Output device has changed, restarting MPD Nov 01 08:09:16 volumio sudo[17753]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 01 08:09:16 volumio sudo[17753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:16 volumio volumio[17639]: info: Output device has changed, restarting Shairport Sync Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio sudo[17753]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:16 volumio sudo[17755]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 01 08:09:16 volumio sudo[17755]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:16 volumio volumio[17639]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 08:09:16 volumio volumio[17639]: info: ___________ START PLUGINS ___________ Nov 01 08:09:16 volumio volumio[17639]: info: ControllerMpd::onStart: Initializing MPD Nov 01 08:09:16 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Nov 01 08:09:16 volumio volumio[17639]: info: Creating MPD Configuration file Nov 01 08:09:16 volumio sudo[17763]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 01 08:09:16 volumio sudo[17763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:16 volumio systemd[1]: mpd.service: Deactivated successfully. Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 08:09:16 volumio volumio[17639]: info: [1761984556307] CoreMusicLibrary::Adding element Media Servers Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 08:09:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 01 08:09:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 01 08:09:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 01 08:09:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 01 08:09:16 volumio sudo[17763]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:16 volumio sudo[17766]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:16 volumio sudo[17766]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:16 volumio volumio[17707]: Starting albumart workers Nov 01 08:09:16 volumio volumio[17639]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 01 08:09:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 01 08:09:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 152. Nov 01 08:09:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:16 volumio volumio[17639]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 08:09:16 volumio volumio[17639]: info: [1761984556379] CoreMusicLibrary::Adding element Last_100 Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 08:09:16 volumio volumio[17639]: info: [1761984556380] CoreMusicLibrary::Adding element Webradio Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 08:09:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:16 volumio go-librespot[17778]: go-librespot daemon starting... Nov 01 08:09:16 volumio go-librespot[17779]: time="2025-11-01T08:09:16Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:09:16 volumio go-librespot[17779]: time="2025-11-01T08:09:16Z" level=debug msg="app state loaded" Nov 01 08:09:16 volumio go-librespot[17779]: time="2025-11-01T08:09:16Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:09:16 volumio volumio[17639]: info: Initializing BBC Radios Nov 01 08:09:16 volumio systemd[1]: mpd.service: Deactivated successfully. Nov 01 08:09:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 01 08:09:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 01 08:09:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 01 08:09:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 01 08:09:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 01 08:09:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 01 08:09:16 volumio volumio[17708]: Starting albumart workers Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:16 volumio volumio[17706]: Starting albumart workers Nov 01 08:09:16 volumio volumio[17639]: info: Creating Spotify config file Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio sudo[17790]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 01 08:09:16 volumio sudo[17790]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 01 08:09:16 volumio go-librespot[17779]: time="2025-11-01T08:09:16Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 01 08:09:16 volumio go-librespot[17779]: time="2025-11-01T08:09:16Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 01 08:09:16 volumio go-librespot[17779]: time="2025-11-01T08:09:16Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 01 08:09:16 volumio go-librespot[17779]: time="2025-11-01T08:09:16Z" level=info msg="zeroconf server listening on port 41911" Nov 01 08:09:16 volumio sudo[17790]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:16 volumio go-librespot[17779]: time="2025-11-01T08:09:16Z" level=debug msg="obtained new client token: AAAkTRRWNrxr4R5HJac/f9BvZ+dfwzLQInFuwipx7DnmPGUhoSSCHEFV6mp/4OnAfHQOEb+y7BWH7Ybi6CBiWevnsSVnEk8E/ofHqF5MCtPXMKj0g9yZNPmtqxmBmaLWLMU+R2J8XYJEOQBWYHGQN8SsOJoMMUUcLVAv6dGiVi3uIFstnDUDG+uvv1eJnF9kCed3W8ekkEMmchTqy1GiZpjLwMY2LMsORyjwk1ipBEIm8q/MXkamiyk=" Nov 01 08:09:16 volumio go-librespot[17779]: time="2025-11-01T08:09:16Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:09:16 volumio go-librespot[17779]: time="2025-11-01T08:09:16Z" level=debug msg="completed keyexchange" Nov 01 08:09:16 volumio go-librespot[17779]: time="2025-11-01T08:09:16Z" level=debug msg="completed challenge" Nov 01 08:09:16 volumio volumio[17639]: info: Volumio Calling Home Nov 01 08:09:16 volumio go-librespot[17779]: time="2025-11-01T08:09:16Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:09:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:09:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:09:16 volumio volumio[17639]: info: MPD Permissions set Nov 01 08:09:16 volumio volumio[17639]: info: MPD Permissions set Nov 01 08:09:16 volumio volumio[17639]: info: Spotify config file written Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio sudo[17825]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:16 volumio sudo[17825]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 08:09:16 volumio volumio[17639]: info: Volumio called home Nov 01 08:09:16 volumio volumio[17639]: info: No need to fix Spotify hosts Nov 01 08:09:16 volumio volumio[17639]: info: Starting Shairport Sync Nov 01 08:09:16 volumio go-librespot[17836]: go-librespot daemon starting... Nov 01 08:09:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:16 volumio volumio[17639]: info: Starting Shairport Sync Nov 01 08:09:16 volumio sudo[17825]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:16 volumio volumio[17639]: info: Starting Shairport Sync Nov 01 08:09:16 volumio go-librespot[17840]: time="2025-11-01T08:09:16Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:09:16 volumio go-librespot[17840]: time="2025-11-01T08:09:16Z" level=debug msg="app state loaded" Nov 01 08:09:16 volumio go-librespot[17840]: time="2025-11-01T08:09:16Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:09:16 volumio sudo[17847]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 01 08:09:16 volumio sudo[17847]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:16 volumio sudo[17849]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 01 08:09:16 volumio sudo[17849]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:16 volumio sudo[17839]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 01 08:09:16 volumio sudo[17839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:16 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 01 08:09:16 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 01 08:09:16 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 01 08:09:16 volumio systemd[1]: shairport-sync.service: Consumed 1.591s CPU time. Nov 01 08:09:16 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 01 08:09:16 volumio sudo[17847]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:16 volumio sudo[17839]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:16 volumio sudo[17849]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:16 volumio volumio[17639]: info: Shairport-Sync Started Nov 01 08:09:16 volumio volumio[17639]: Error adding Membership: Error: addMembership EINVAL Nov 01 08:09:16 volumio volumio[17639]: info: Shairport-Sync Started Nov 01 08:09:16 volumio volumio[17639]: info: Shairport-Sync Started Nov 01 08:09:16 volumio go-librespot[17840]: time="2025-11-01T08:09:16Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:09:16 volumio go-librespot[17840]: time="2025-11-01T08:09:16Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:09:16 volumio go-librespot[17840]: time="2025-11-01T08:09:16Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:09:16 volumio go-librespot[17840]: time="2025-11-01T08:09:16Z" level=info msg="zeroconf server listening on port 42605" Nov 01 08:09:16 volumio go-librespot[17840]: time="2025-11-01T08:09:16Z" level=debug msg="obtained new client token: AACfJz+hK9fWSSF0pfoiHZGCuwFCapjLa3BtNvL4DT6sRdynLEzjYBS8Z74KkKB5nmdFQkmpxS5XqszgiYKuOByo9uuIoWoZeuQ3L6n+uJjn/7F0YLudYQPWFLywmFSks+GII+svH9ymDYzmwF1MiaMTBjAc6/T5ehA2sFa8Tac/EVkrKXk27v9rpyVPHIgtSYzGMKIyfMZAJpkwi+0/2Tbye/wwWZV66OA0EUAQou3O6Wkt5FxPIi8=" Nov 01 08:09:16 volumio go-librespot[17840]: time="2025-11-01T08:09:16Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:09:17 volumio mpd[17802]: 2025-11-01T08:09:17 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 01 08:09:17 volumio systemd[1]: Started mpd.service - Music Player Daemon. Nov 01 08:09:17 volumio sudo[17755]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:17 volumio go-librespot[17840]: time="2025-11-01T08:09:17Z" level=debug msg="completed keyexchange" Nov 01 08:09:17 volumio sudo[17766]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:17 volumio go-librespot[17840]: time="2025-11-01T08:09:17Z" level=debug msg="completed challenge" Nov 01 08:09:17 volumio volumio[17639]: error: updateQueue error: null Nov 01 08:09:17 volumio volumio[17639]: error: updateQueue error: null Nov 01 08:09:17 volumio volumio[17639]: info: MPD running with PID17802 Nov 01 08:09:17 volumio volumio[17639]: ,establishing connection Nov 01 08:09:17 volumio volumio[17639]: error: updateQueue error: null Nov 01 08:09:17 volumio go-librespot[17840]: time="2025-11-01T08:09:17Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:09:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:09:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:09:18 volumio volumio-remote-updater[874]: [2025-11-01 08:09:18] [connect] Successful connection Nov 01 08:09:18 volumio volumio-remote-updater[874]: [2025-11-01 08:09:18] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1761984558 101 Nov 01 08:09:18 volumio volumio[17639]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Nov 01 08:09:18 volumio volumio[17639]: info: Discovery: adding 70853f74-8210-4683-a3fa-e1217517bd40 Nov 01 08:09:18 volumio volumio[17639]: info: Discovery: Found device Volumio Nov 01 08:09:18 volumio volumio[17639]: info: CoreCommandRouter::volumioGetState Nov 01 08:09:18 volumio volumio[17639]: info: CorePlayQueue::getTrack 0 Nov 01 08:09:18 volumio volumio[17639]: info: Discovery: this is already registered, 70853f74-8210-4683-a3fa-e1217517bd40 Nov 01 08:09:18 volumio volumio[17639]: info: Discovery: Found device Volumio Nov 01 08:09:18 volumio volumio[17639]: info: CoreCommandRouter::volumioGetState Nov 01 08:09:18 volumio volumio[17639]: info: CorePlayQueue::getTrack 0 Nov 01 08:09:18 volumio volumio[17639]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Nov 01 08:09:18 volumio volumio[17639]: info: CoreCommandRouter::volumioGetState Nov 01 08:09:18 volumio volumio[17639]: info: CorePlayQueue::getTrack 0 Nov 01 08:09:18 volumio volumio[17639]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 01 08:09:18 volumio volumio[17639]: SPOTIFY: BQB3JVPTZSYS_A7Li8r61Iy70QCZCmMu-XNJtotA7EGIim3tRyG7NtsIIuv_sC64fSHHllAPpfY902S11c6c0d6MjwViqOqEhMjjzP-4uYcFtf5vnJwa4lrt_EPxIudmTygrVzWDNX_eovJUue5-n5Ab5bDOabhYQP7LZ8lQS_KFai8LzwZbYfFdAKnBOIAHxHGAc1MEYuJPlpPKKmvTCHf-bxdHuPC99-qjNfP8NksOgEcX38AdPoxuwcW0Tc8qTTkojyHwiziK2dA3LEFcjCRYjCEVhqysjENQZHvJ3i4uQYJWGQo Nov 01 08:09:18 volumio volumio[17639]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 01 08:09:18 volumio volumio[17639]: info: New Spotify access token = BQB3JVPTZSYS_A7Li8r61Iy70QCZCmMu-XNJtotA7EGIim3tRyG7NtsIIuv_sC64fSHHllAPpfY902S11c6c0d6MjwViqOqEhMjjzP-4uYcFtf5vnJwa4lrt_EPxIudmTygrVzWDNX_eovJUue5-n5Ab5bDOabhYQP7LZ8lQS_KFai8LzwZbYfFdAKnBOIAHxHGAc1MEYuJPlpPKKmvTCHf-bxdHuPC99-qjNfP8NksOgEcX38AdPoxuwcW0Tc8qTTkojyHwiziK2dA3LEFcjCRYjCEVhqysjENQZHvJ3i4uQYJWGQo Nov 01 08:09:18 volumio volumio[17639]: info: Spotify credentials grant success - running version from March 24, 2019 Nov 01 08:09:19 volumio volumio[17639]: SPOTIFY: User informations: {"country":"DE","display_name":"lapman","email":"ylm19961214@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31hyzsop5elyyfayaiyk5tmkxmky"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31hyzsop5elyyfayaiyk5tmkxmky","id":"31hyzsop5elyyfayaiyk5tmkxmky","images":[],"product":"free","type":"user","uri":"spotify:user:31hyzsop5elyyfayaiyk5tmkxmky"} Nov 01 08:09:19 volumio volumio[17639]: info: Spotify Successfully logged in Nov 01 08:09:19 volumio volumio[17639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 08:09:19 volumio volumio[17639]: info: [1761984559067] CoreMusicLibrary::Adding element Spotify Nov 01 08:09:19 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 08:09:19 volumio volumio[17639]: Cannot find translation for source Spotify Nov 01 08:09:19 volumio volumio[17639]: info: [yt-cast-receiver] DIAL server listening on port 8098 Nov 01 08:09:19 volumio volumio[17639]: info: CoreCommandRouter::volumioRetrievevolume Nov 01 08:09:19 volumio volumio[17639]: info: VolumeController:: Volume=33 Mute =false Nov 01 08:09:19 volumio volumio[17639]: info: CoreCommandRouter::volumioGetState Nov 01 08:09:19 volumio volumio[17639]: info: CorePlayQueue::getTrack 0 Nov 01 08:09:19 volumio volumio[17639]: info: CoreStateMachine::pushState Nov 01 08:09:19 volumio volumio[17639]: info: CorePlayQueue::getTrack 0 Nov 01 08:09:19 volumio volumio[17639]: info: CoreCommandRouter::volumioPushState Nov 01 08:09:19 volumio volumio[17639]: info: Completed starting Core Plugins Nov 01 08:09:19 volumio volumio[17639]: info: ------------------------------------------- Nov 01 08:09:19 volumio volumio[17639]: info: ----- MyVolumio plugins startup ---- Nov 01 08:09:19 volumio volumio[17639]: info: ------------------------------------------- Nov 01 08:09:19 volumio volumio[17639]: info: [MyVolumio PluginManager] Fetching plans data.... Nov 01 08:09:19 volumio volumio[17639]: info: Cannot mount NAS NAS at system boot, trial number 2 ,retrying in 5 seconds Nov 01 08:09:19 volumio volumio[17639]: info: go-librespot daemon successfully initialized Nov 01 08:09:20 volumio sudo[17878]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 01 08:09:20 volumio sudo[17878]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:20 volumio sudo[17880]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 01 08:09:20 volumio sudo[17880]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:20 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Nov 01 08:09:20 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Nov 01 08:09:20 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Nov 01 08:09:20 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Nov 01 08:09:20 volumio mpd_monitor.sh[17883]: MPD Monitor Service: Starting MPD Monitor Service Nov 01 08:09:20 volumio sudo[17878]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:20 volumio sudo[17880]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:20 volumio volumio[17639]: info: Successfully started MPD Monitor Nov 01 08:09:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 153. Nov 01 08:09:20 volumio volumio[17639]: info: Successfully started MPD Monitor Nov 01 08:09:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:20 volumio go-librespot[17888]: go-librespot daemon starting... Nov 01 08:09:20 volumio go-librespot[17889]: time="2025-11-01T08:09:20Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:09:20 volumio go-librespot[17889]: time="2025-11-01T08:09:20Z" level=debug msg="app state loaded" Nov 01 08:09:20 volumio go-librespot[17889]: time="2025-11-01T08:09:20Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:09:20 volumio go-librespot[17889]: time="2025-11-01T08:09:20Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 01 08:09:20 volumio go-librespot[17889]: time="2025-11-01T08:09:20Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 01 08:09:20 volumio go-librespot[17889]: time="2025-11-01T08:09:20Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 01 08:09:20 volumio go-librespot[17889]: time="2025-11-01T08:09:20Z" level=info msg="zeroconf server listening on port 42545" Nov 01 08:09:20 volumio go-librespot[17889]: time="2025-11-01T08:09:20Z" level=debug msg="obtained new client token: AADKv0Z0+eoQb0EcQMqSrV+KoCUm3c3cYVGSbQQQZmsYI5VlNLU0ZISXJQzS9lJWM6rYLqf4vf7xaG90BzJcnCK/LxFUrE6rgRxb5JpBlyq9Cn/v2nA+ERg/QOtqpuKWwHFdLNp4NrUpHidrJISuvQzApYPIC5GMnxDhR5C4lSbq68RTLH1Jgd403yJgBdOxl6lqChpuY4CHEABRLF6pp3q4Bu9wR/bLGYVVUygVoFUmHKYKI4p6" Nov 01 08:09:20 volumio go-librespot[17889]: time="2025-11-01T08:09:20Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:09:20 volumio go-librespot[17889]: time="2025-11-01T08:09:20Z" level=debug msg="completed keyexchange" Nov 01 08:09:20 volumio go-librespot[17889]: time="2025-11-01T08:09:20Z" level=debug msg="completed challenge" Nov 01 08:09:20 volumio go-librespot[17889]: time="2025-11-01T08:09:20Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:09:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:09:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:09:22 volumio volumio[17639]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Nov 01 08:09:22 volumio volumio[17639]: info: Initializing connection to go-librespot Websocket Nov 01 08:09:22 volumio volumio[17639]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:09:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 154. Nov 01 08:09:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:23 volumio go-librespot[17896]: go-librespot daemon starting... Nov 01 08:09:23 volumio go-librespot[17897]: time="2025-11-01T08:09:23Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:09:23 volumio go-librespot[17897]: time="2025-11-01T08:09:23Z" level=debug msg="app state loaded" Nov 01 08:09:23 volumio go-librespot[17897]: time="2025-11-01T08:09:23Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:09:23 volumio go-librespot[17897]: time="2025-11-01T08:09:23Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:09:23 volumio go-librespot[17897]: time="2025-11-01T08:09:23Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:09:23 volumio go-librespot[17897]: time="2025-11-01T08:09:23Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:09:23 volumio go-librespot[17897]: time="2025-11-01T08:09:23Z" level=info msg="zeroconf server listening on port 45375" Nov 01 08:09:23 volumio go-librespot[17897]: time="2025-11-01T08:09:23Z" level=debug msg="obtained new client token: AAD/nRhLi1Sqx47w5HjDcebrYf96OFgqT9r7aJipmexU0hYSfdyeGUPghmNRovlOEB2AJV+L8pTufKyaNSQyAN9LSB0UtH3FgxNV5fLQTfyXz23RNpjrz8TzSE3pSgNm4IkfcrbcTB2OrrXsX3LVV8mRx+ew2jRZZA1MO1n11kvemYY6SsmVs8s/ktZJwhy9iqlnLcLUoi4gzo6TNwllAVza3BAfbfBf0+LJQPkCoYXZIsU/NBQl4Tc=" Nov 01 08:09:23 volumio go-librespot[17897]: time="2025-11-01T08:09:23Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:09:23 volumio go-librespot[17897]: time="2025-11-01T08:09:23Z" level=debug msg="completed keyexchange" Nov 01 08:09:23 volumio go-librespot[17897]: time="2025-11-01T08:09:23Z" level=debug msg="completed challenge" Nov 01 08:09:23 volumio go-librespot[17897]: time="2025-11-01T08:09:23Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:09:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:09:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:09:24 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 01 08:09:24 volumio volumio[17639]: info: Cannot mount NAS NAS at system boot, trial number 3 ,retrying in 5 seconds Nov 01 08:09:24 volumio sudo[17919]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 01 08:09:24 volumio sudo[17919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:24 volumio sudo[17919]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:24 volumio sudo[17921]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 01 08:09:24 volumio sudo[17921]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:24 volumio sudo[17921]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:24 volumio sudo[17925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 01 08:09:24 volumio sudo[17925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:24 volumio sudo[17925]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:24 volumio volumio[17639]: info: Upmpdcli Daemon Started Nov 01 08:09:25 volumio volumio[17639]: info: Initializing connection to go-librespot Websocket Nov 01 08:09:25 volumio volumio[17639]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:09:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 155. Nov 01 08:09:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:27 volumio go-librespot[17927]: go-librespot daemon starting... Nov 01 08:09:27 volumio go-librespot[17928]: time="2025-11-01T08:09:27Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:09:27 volumio go-librespot[17928]: time="2025-11-01T08:09:27Z" level=debug msg="app state loaded" Nov 01 08:09:27 volumio go-librespot[17928]: time="2025-11-01T08:09:27Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:09:27 volumio go-librespot[17928]: time="2025-11-01T08:09:27Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 01 08:09:27 volumio go-librespot[17928]: time="2025-11-01T08:09:27Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 01 08:09:27 volumio go-librespot[17928]: time="2025-11-01T08:09:27Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 01 08:09:27 volumio go-librespot[17928]: time="2025-11-01T08:09:27Z" level=info msg="zeroconf server listening on port 46755" Nov 01 08:09:27 volumio go-librespot[17928]: time="2025-11-01T08:09:27Z" level=debug msg="obtained new client token: AABD8LNcAs1jTT/8vcUsAEbtJ5RVVmt7MquvYiAtJG5PRSwFjaK6VrHyv1Kt/6OzN9ew3La4ZkYvARZsi5gHFfCSRqWT1N60poP6NbJDG1ur0hGqoRoCkCtOOeimDgp8W5xSeys2xfZQ+KNo8gUSWa4T60vARuZvn1KgF9LLX7NdQEkMDXyd3nKruPV1rjUSTra7dih/tk4csN396rR3AizJlxMovf0JvXrUt0wruEKQaqbq0a3x" Nov 01 08:09:27 volumio go-librespot[17928]: time="2025-11-01T08:09:27Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:09:27 volumio go-librespot[17928]: time="2025-11-01T08:09:27Z" level=debug msg="completed keyexchange" Nov 01 08:09:27 volumio go-librespot[17928]: time="2025-11-01T08:09:27Z" level=debug msg="completed challenge" Nov 01 08:09:27 volumio go-librespot[17928]: time="2025-11-01T08:09:27Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:09:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:09:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Nov 01 08:09:27 volumio volumio[17639]: info: Adding plugin bluetooth to MyMusic Plugins Nov 01 08:09:27 volumio volumio[17639]: info: Adding plugin multiroom to MyMusic Plugins Nov 01 08:09:27 volumio volumio[17639]: info: Adding plugin metavolumio to MyMusic Plugins Nov 01 08:09:27 volumio volumio[17639]: info: Adding plugin cd_controller to MyMusic Plugins Nov 01 08:09:27 volumio volumio[17639]: info: Adding plugin qobuzconnect to MyMusic Plugins Nov 01 08:09:27 volumio volumio[17639]: info: Adding plugin smart_inputs to MyMusic Plugins Nov 01 08:09:27 volumio volumio[17639]: info: Adding plugin tidalconnect to MyMusic Plugins Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Nov 01 08:09:27 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:27 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:27 volumio volumio[17639]: info: Starting MyVolumio Remote Streaming Endpoints Nov 01 08:09:27 volumio volumio[17639]: info: MyVolumio login type: Token Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Nov 01 08:09:27 volumio volumio[17639]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Nov 01 08:09:28 volumio volumio[17639]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 01 08:09:28 volumio volumio[17639]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 01 08:09:28 volumio volumio[17639]: info: Streaming services startup Nov 01 08:09:28 volumio volumio[17639]: info: Starting Streaming Daemon Nov 01 08:09:28 volumio sudo[17937]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 01 08:09:28 volumio sudo[17937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:28 volumio volumio[17639]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Nov 01 08:09:28 volumio sudo[17937]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:28 volumio volumio[17639]: error: Cannot start Volumio Streaming Daemon Nov 01 08:09:28 volumio volumio[17639]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 01 08:09:28 volumio volumio[17639]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 01 08:09:28 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Nov 01 08:09:28 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Nov 01 08:09:28 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Nov 01 08:09:28 volumio volumio[17639]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Nov 01 08:09:28 volumio volumio[17639]: info: Initializing connection to go-librespot Websocket Nov 01 08:09:28 volumio volumio[17639]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:09:28 volumio volumio[17639]: info: MyVolumio token set successfully Nov 01 08:09:28 volumio volumio[17639]: info: MYVOLUMIO: Adding device Nov 01 08:09:28 volumio volumio[17639]: info: MYVOLUMIO: Evaluating Server Nov 01 08:09:29 volumio volumio[17639]: info: MyVolumio status changed Nov 01 08:09:29 volumio volumio[17639]: info: Streaming services startup Nov 01 08:09:29 volumio volumio[17639]: info: Starting Streaming Daemon Nov 01 08:09:29 volumio volumio[17639]: info: Removing browser output: myVolumio user plan is not superstar Nov 01 08:09:29 volumio volumio[17639]: info: Removing audio output: Nov 01 08:09:29 volumio volumio[17639]: info: Stoppping Tunnel 1 Nov 01 08:09:29 volumio sudo[17986]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 01 08:09:29 volumio sudo[17986]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:29 volumio sudo[17988]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Nov 01 08:09:29 volumio sudo[17988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 08:09:29 volumio sudo[17986]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:29 volumio volumio[17639]: error: Cannot start Volumio Streaming Daemon Nov 01 08:09:29 volumio volumio[17639]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 01 08:09:29 volumio volumio[17639]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 01 08:09:29 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 01 08:09:29 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 01 08:09:29 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 01 08:09:29 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 01 08:09:29 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 01 08:09:29 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 01 08:09:29 volumio sudo[17988]: pam_unix(sudo:session): session closed for user root Nov 01 08:09:29 volumio volumio[17639]: info: Remote SSH Stopped Nov 01 08:09:29 volumio volumio[17639]: info: Setting Geolocation for MyVolumio to eu3 Nov 01 08:09:29 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:29 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:29 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:29 volumio volumio[17639]: info: Cannot mount NAS NAS at system boot, trial number 4 ,retrying in 5 seconds Nov 01 08:09:29 volumio volumio[17639]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 01 08:09:30 volumio volumio[17639]: info: Updating MyVolumio device info Nov 01 08:09:30 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:30 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:30 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 156. Nov 01 08:09:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:30 volumio go-librespot[17991]: go-librespot daemon starting... Nov 01 08:09:30 volumio go-librespot[17992]: time="2025-11-01T08:09:30Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:09:30 volumio go-librespot[17992]: time="2025-11-01T08:09:30Z" level=debug msg="app state loaded" Nov 01 08:09:30 volumio go-librespot[17992]: time="2025-11-01T08:09:30Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:09:30 volumio volumio[17639]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 01 08:09:30 volumio go-librespot[17992]: time="2025-11-01T08:09:30Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:09:30 volumio go-librespot[17992]: time="2025-11-01T08:09:30Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:09:30 volumio go-librespot[17992]: time="2025-11-01T08:09:30Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:09:30 volumio go-librespot[17992]: time="2025-11-01T08:09:30Z" level=info msg="zeroconf server listening on port 33705" Nov 01 08:09:30 volumio go-librespot[17992]: time="2025-11-01T08:09:30Z" level=debug msg="obtained new client token: AABD7R1r4TTEgmHrHTTtC4PeyZfRqX+87GXq7Rnge/hlmHI1dH7+Gemfta31l5WHOzG9ZIOTj6bxsoScURKDtq57yo+mSeRcrv9NQCC0RB2u3GWw9nz2m2I4EzAZhhzCpdQr+k3yZx1iH/CKi68eird4ug2yavrnErYf1RHg0Y8zu+achRPSELhTEcOjDzKV++s4Kmrsq202ZkvmJFLq9R2ItBsb7cIUt4N2h90ed+zSBcdHAKwavLU=" Nov 01 08:09:30 volumio go-librespot[17992]: time="2025-11-01T08:09:30Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:09:30 volumio go-librespot[17992]: time="2025-11-01T08:09:30Z" level=debug msg="completed keyexchange" Nov 01 08:09:30 volumio go-librespot[17992]: time="2025-11-01T08:09:30Z" level=debug msg="completed challenge" Nov 01 08:09:30 volumio go-librespot[17992]: time="2025-11-01T08:09:30Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:09:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:09:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:09:31 volumio volumio[17639]: info: Initializing connection to go-librespot Websocket Nov 01 08:09:31 volumio volumio[17639]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:09:33 volumio volumio[17639]: info: MYVOLUMIO: Adding device Nov 01 08:09:33 volumio volumio[17639]: info: MYVOLUMIO: Evaluating Server Nov 01 08:09:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 157. Nov 01 08:09:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:34 volumio volumio[17639]: info: Setting Geolocation for MyVolumio to eu3 Nov 01 08:09:34 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:34 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:34 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:34 volumio go-librespot[18014]: go-librespot daemon starting... Nov 01 08:09:34 volumio go-librespot[18015]: time="2025-11-01T08:09:34Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:09:34 volumio go-librespot[18015]: time="2025-11-01T08:09:34Z" level=debug msg="app state loaded" Nov 01 08:09:34 volumio go-librespot[18015]: time="2025-11-01T08:09:34Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:09:34 volumio go-librespot[18015]: time="2025-11-01T08:09:34Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:09:34 volumio go-librespot[18015]: time="2025-11-01T08:09:34Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:09:34 volumio go-librespot[18015]: time="2025-11-01T08:09:34Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:09:34 volumio go-librespot[18015]: time="2025-11-01T08:09:34Z" level=info msg="zeroconf server listening on port 45751" Nov 01 08:09:34 volumio go-librespot[18015]: time="2025-11-01T08:09:34Z" level=debug msg="obtained new client token: AABUrjDYNmvZ7RdM9dCZ4Ox2th8ak61chiv063SpPZLfo988CGyHUXAaaF9GlkEfiRsj8bIbb7OZiuYvPzLuGLv8smYvv8wdVGLnQuPa3tLogP5GKfm87XYrSuB9oSGHVrjTSJcLphgJb++Gt4Pofl9N70mMtXIn2KpBsqXAe5kl1gdoqclKzK7CWnSs1DyyTn15zjynqvxGF1iXH+z6ZccOZ8X8KQM54OTXoJDaMFwUyoc5Ojci" Nov 01 08:09:34 volumio go-librespot[18015]: time="2025-11-01T08:09:34Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:09:34 volumio go-librespot[18015]: time="2025-11-01T08:09:34Z" level=debug msg="completed keyexchange" Nov 01 08:09:34 volumio go-librespot[18015]: time="2025-11-01T08:09:34Z" level=debug msg="completed challenge" Nov 01 08:09:34 volumio volumio[17639]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 01 08:09:34 volumio go-librespot[18015]: time="2025-11-01T08:09:34Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:09:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:09:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:09:34 volumio volumio[17639]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Nov 01 08:09:34 volumio volumio[17639]: info: Initializing connection to go-librespot Websocket Nov 01 08:09:34 volumio volumio[17639]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:09:35 volumio volumio[17639]: info: Updating MyVolumio device info Nov 01 08:09:35 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:35 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:35 volumio volumio[17639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 08:09:35 volumio volumio[17639]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 01 08:09:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 158. Nov 01 08:09:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 08:09:37 volumio go-librespot[18036]: go-librespot daemon starting... Nov 01 08:09:37 volumio go-librespot[18037]: time="2025-11-01T08:09:37Z" level=info msg="running go-librespot 0.4.0" Nov 01 08:09:37 volumio go-librespot[18037]: time="2025-11-01T08:09:37Z" level=debug msg="app state loaded" Nov 01 08:09:37 volumio go-librespot[18037]: time="2025-11-01T08:09:37Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 08:09:37 volumio go-librespot[18037]: time="2025-11-01T08:09:37Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 08:09:37 volumio go-librespot[18037]: time="2025-11-01T08:09:37Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 08:09:37 volumio go-librespot[18037]: time="2025-11-01T08:09:37Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 08:09:37 volumio go-librespot[18037]: time="2025-11-01T08:09:37Z" level=info msg="zeroconf server listening on port 32861" Nov 01 08:09:37 volumio go-librespot[18037]: time="2025-11-01T08:09:37Z" level=debug msg="obtained new client token: AAAeEeHgNCQ77jfu9D2S0l1s9Qdw1BBS1EbXnm3gzN42/QhZBQG+A0UTcDLOpCPaSzqjN8zDpvLbXyt/gi5vxUK2APV8WI1NLlUR7Fb4Q6ivIPvThCyiuzxjKprn4O4yaoipr85H3kY2WaQ5XeC0sWSrhdBlToKSoQWR3YTuWcwEy78DGHMiHYu6qC6XvXiAGoAu+HLbk4KUhBdJWitPpDCngfdDFn3mz/Sqzkc1QiVDUDCyhtpxKEc=" Nov 01 08:09:37 volumio go-librespot[18037]: time="2025-11-01T08:09:37Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 08:09:37 volumio go-librespot[18037]: time="2025-11-01T08:09:37Z" level=debug msg="completed keyexchange" Nov 01 08:09:37 volumio go-librespot[18037]: time="2025-11-01T08:09:37Z" level=debug msg="completed challenge" Nov 01 08:09:37 volumio volumio[17639]: info: Initializing connection to go-librespot Websocket Nov 01 08:09:37 volumio go-librespot[18037]: time="2025-11-01T08:09:37Z" level=debug msg="new websocket client" Nov 01 08:09:37 volumio volumio[17639]: info: Connection to go-librespot Websocket established Nov 01 08:09:37 volumio go-librespot[18037]: time="2025-11-01T08:09:37Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 08:09:37 volumio volumio[17639]: info: Connection to go-librespot Websocket closed Nov 01 08:09:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 08:09:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 08:09:40 volumio volumio[17639]: info: Getting Spotify volume Nov 01 08:09:40 volumio volumio[17639]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 08:09:40 volumio volumio[17639]: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 08:09:40 volumio volumio[17639]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Nov 01 08:09:40 volumio volumio[17639]: errno: -111, Nov 01 08:09:40 volumio volumio[17639]: code: 'ECONNREFUSED', Nov 01 08:09:40 volumio volumio[17639]: syscall: 'connect', Nov 01 08:09:40 volumio volumio[17639]: address: '127.0.0.1', Nov 01 08:09:40 volumio volumio[17639]: port: 9879, Nov 01 08:09:40 volumio volumio[17639]: response: undefined Nov 01 08:09:40 volumio volumio[17639]: } Nov 01 08:09:40 volumio volumio[17639]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 08:09:40 volumio sudo[18061]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-11-01 08:08' Nov 01 08:09:40 volumio sudo[18061]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="c22b72a8acb34a699a626adb0a09a6b88ee7233a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="40400d6a6fa57cf20e36499e510876b3654e9c4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Oct 4 16:40:08 UTC 2025" VOLUMIO_VERSION="4.061" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="7f8ace80645f85765fa10c72d1769d04"