Nov 02 04:11:02 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:02 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 94. Nov 02 04:11:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:02 volumio go-librespot[2971]: go-librespot daemon starting... Nov 02 04:11:02 volumio go-librespot[2972]: time="2025-11-02T04:11:02Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:11:02 volumio go-librespot[2972]: time="2025-11-02T04:11:02Z" level=debug msg="app state loaded" Nov 02 04:11:02 volumio go-librespot[2972]: time="2025-11-02T04:11:02Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:11:02 volumio go-librespot[2972]: time="2025-11-02T04:11: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 02 04:11:02 volumio go-librespot[2972]: time="2025-11-02T04:11:02Z" 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 02 04:11:02 volumio go-librespot[2972]: time="2025-11-02T04:11:02Z" 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 02 04:11:02 volumio go-librespot[2972]: time="2025-11-02T04:11:02Z" level=info msg="zeroconf server listening on port 40879" Nov 02 04:11:02 volumio go-librespot[2972]: time="2025-11-02T04:11:02Z" level=debug msg="obtained new client token: AABHDaGWTkwRNLc3BfjZNj8M5ElI8QGrF7gN9di/25KrknGgFn90XpfK8JATm5eVupQb2lERjDa3w0zQx+bU7KeFaRCh4uRVjbcvxxHFWnKt9Cn0T1ylPeFzlrh5/ASS+umGPan8iNkO0izUJq07qmKqIYVR21ocKHPpPzXH/GXF+xVhddNf8Vj/skxm/nyZrHRg9U3CqZkaipsc/A0Ahksh7/HB7oOHOmYJ6riC3jtZ2DLXshpa7P0=" Nov 02 04:11:02 volumio go-librespot[2972]: time="2025-11-02T04:11:02Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:11:02 volumio go-librespot[2972]: time="2025-11-02T04:11:02Z" level=debug msg="completed keyexchange" Nov 02 04:11:02 volumio go-librespot[2972]: time="2025-11-02T04:11:02Z" level=debug msg="completed challenge" Nov 02 04:11:02 volumio go-librespot[2972]: time="2025-11-02T04:11:02Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 04:11:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:11:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:11:05 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:05 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:05 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 02 04:11:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 95. Nov 02 04:11:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:06 volumio go-librespot[2979]: go-librespot daemon starting... Nov 02 04:11:06 volumio go-librespot[2980]: time="2025-11-02T04:11:06Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:11:06 volumio go-librespot[2980]: time="2025-11-02T04:11:06Z" level=debug msg="app state loaded" Nov 02 04:11:06 volumio go-librespot[2980]: time="2025-11-02T04:11:06Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:11:06 volumio go-librespot[2980]: time="2025-11-02T04:11: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-gae2.spotify.com:80]" Nov 02 04:11:06 volumio go-librespot[2980]: time="2025-11-02T04:11:06Z" 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 02 04:11:06 volumio go-librespot[2980]: time="2025-11-02T04:11:06Z" 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 02 04:11:06 volumio go-librespot[2980]: time="2025-11-02T04:11:06Z" level=info msg="zeroconf server listening on port 42907" Nov 02 04:11:06 volumio go-librespot[2980]: time="2025-11-02T04:11:06Z" level=debug msg="obtained new client token: AACI37QhUSW0/pQnPW7FWmA4A4QjZSJyLLq9ALw2plBUDjfXa9rCAZYgCXkJHFfqZGwic9AKoT8vtEc3FvCGgdNUmBsioq5Rw4qK1/uip+Kt6WjC8H7EV7ldbwk+FCMkrK+hzWF1QZs4dupIEQkcD31lnc4rpnflYtK9gE699qoIlj9YSKAnRf4n0j+CdVUnJCil2Y3cSA5zCMNKVrCS1emM/zKXZkYx951dFJ9io9qI2tONSZXW" Nov 02 04:11:06 volumio go-librespot[2980]: time="2025-11-02T04:11:06Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:11:06 volumio go-librespot[2980]: time="2025-11-02T04:11:06Z" level=debug msg="completed keyexchange" Nov 02 04:11:06 volumio go-librespot[2980]: time="2025-11-02T04:11:06Z" level=debug msg="completed challenge" Nov 02 04:11:06 volumio go-librespot[2980]: time="2025-11-02T04:11: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 02 04:11:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:11:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:11:08 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:08 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 96. Nov 02 04:11:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:09 volumio go-librespot[3003]: go-librespot daemon starting... Nov 02 04:11:09 volumio go-librespot[3004]: time="2025-11-02T04:11:09Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:11:09 volumio go-librespot[3004]: time="2025-11-02T04:11:09Z" level=debug msg="app state loaded" Nov 02 04:11:09 volumio go-librespot[3004]: time="2025-11-02T04:11:09Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:11:09 volumio go-librespot[3004]: time="2025-11-02T04:11:09Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 02 04:11:09 volumio go-librespot[3004]: time="2025-11-02T04:11:09Z" 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 02 04:11:09 volumio go-librespot[3004]: time="2025-11-02T04:11:09Z" 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 02 04:11:09 volumio go-librespot[3004]: time="2025-11-02T04:11:09Z" level=info msg="zeroconf server listening on port 43997" Nov 02 04:11:09 volumio go-librespot[3004]: time="2025-11-02T04:11:09Z" level=debug msg="obtained new client token: AACEoSgMf4TQjqinktd273X+D6mph30sOWieNgTn3jUbobmhhP0bMK6XSAvMj0ehc0PQ0NRXDwlb1Jk3ZfYk6E5cS+UhrmllnGwwh6YJzRyxhHfKemAyachNkBoL02OEoW5lfLzfEU8v/xX2wtkASK+gaQ4hk75tRtBpxMBVjFrZj5lJ6L34+/oXliUgsHrbT//Ujf+vPQiPD+6wxJ1WlmWYlyWZZvBOERm2lywpFYEwYQ7XAVlgTmM=" Nov 02 04:11:09 volumio go-librespot[3004]: time="2025-11-02T04:11:09Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:11:09 volumio go-librespot[3004]: time="2025-11-02T04:11:09Z" level=debug msg="completed keyexchange" Nov 02 04:11:09 volumio go-librespot[3004]: time="2025-11-02T04:11:09Z" level=debug msg="completed challenge" Nov 02 04:11:09 volumio go-librespot[3004]: time="2025-11-02T04:11:09Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 04:11:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:11:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:11:11 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:11 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 97. Nov 02 04:11:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:13 volumio go-librespot[3011]: go-librespot daemon starting... Nov 02 04:11:13 volumio go-librespot[3012]: time="2025-11-02T04:11:13Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:11:13 volumio go-librespot[3012]: time="2025-11-02T04:11:13Z" level=debug msg="app state loaded" Nov 02 04:11:13 volumio go-librespot[3012]: time="2025-11-02T04:11:13Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:11:13 volumio go-librespot[3012]: time="2025-11-02T04:11: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 02 04:11:13 volumio go-librespot[3012]: time="2025-11-02T04:11: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 02 04:11:13 volumio go-librespot[3012]: time="2025-11-02T04:11: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 02 04:11:13 volumio go-librespot[3012]: time="2025-11-02T04:11:13Z" level=info msg="zeroconf server listening on port 35003" Nov 02 04:11:13 volumio go-librespot[3012]: time="2025-11-02T04:11:13Z" level=debug msg="obtained new client token: AAAif8/HckpR+Pn1763rhuvUNWt+L5NQASadrVYDFuLKqkrz2vy3jEiXjqlCezjfDou86o/ec81Y304qgZ6XOaYBmNQTAQIMeAYqel9FZgyXMJhr9Z5lMO1qP3cAI3r1Gihg3iJTFrZz+ebneOpbiE+sTaT8Ck4juShuCOi1pGWt4g1ZrBr5mQJ4TATah3ZvfPFH/vCxbaSIVlHjetoxw5SL7g8/G/1QqpIWVC59Ch7DbBwb3lk5" Nov 02 04:11:13 volumio go-librespot[3012]: time="2025-11-02T04:11:13Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:11:13 volumio go-librespot[3012]: time="2025-11-02T04:11:13Z" level=debug msg="completed keyexchange" Nov 02 04:11:13 volumio go-librespot[3012]: time="2025-11-02T04:11:13Z" level=debug msg="completed challenge" Nov 02 04:11:13 volumio go-librespot[3012]: time="2025-11-02T04:11: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 02 04:11:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:11:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:11:14 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:14 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 98. Nov 02 04:11:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:16 volumio go-librespot[3022]: go-librespot daemon starting... Nov 02 04:11:16 volumio go-librespot[3023]: time="2025-11-02T04:11:16Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:11:16 volumio go-librespot[3023]: time="2025-11-02T04:11:16Z" level=debug msg="app state loaded" Nov 02 04:11:16 volumio go-librespot[3023]: time="2025-11-02T04:11:16Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:11:16 volumio go-librespot[3023]: time="2025-11-02T04:11: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 02 04:11:16 volumio go-librespot[3023]: time="2025-11-02T04:11: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 02 04:11:16 volumio go-librespot[3023]: time="2025-11-02T04:11: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 02 04:11:16 volumio go-librespot[3023]: time="2025-11-02T04:11:16Z" level=info msg="zeroconf server listening on port 38947" Nov 02 04:11:16 volumio go-librespot[3023]: time="2025-11-02T04:11:16Z" level=debug msg="obtained new client token: AAD3bn8XzPSV6QGtJQ1ho6SznFASYZGnEe2QTLhI1K2SDaDbnSNlJ2DdzXbx2eQbZ47rlqakwaIMbckryRmR7Bo5oWB1EOzgNwLq7IGhkCnU+vC9VGxbl3EeWVt/brO5GY2+8j20UZRO0hStQ3LbtuKO0dcMbe3Acb9ESwg+gdtmk63G8rovZG8A5Y0CJuU3BytiwzJxz890VO6L9wfxDdFAVbnWOzNYt4QQn0UUlbj+N+iaFLEEqrA=" Nov 02 04:11:16 volumio go-librespot[3023]: time="2025-11-02T04:11:16Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:11:16 volumio go-librespot[3023]: time="2025-11-02T04:11:16Z" level=debug msg="completed keyexchange" Nov 02 04:11:16 volumio go-librespot[3023]: time="2025-11-02T04:11:16Z" level=debug msg="completed challenge" Nov 02 04:11:16 volumio go-librespot[3023]: time="2025-11-02T04:11: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 02 04:11:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:11:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:11:17 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:17 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:17 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 02 04:11:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99. Nov 02 04:11:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:20 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:20 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:20 volumio go-librespot[3044]: go-librespot daemon starting... Nov 02 04:11:20 volumio go-librespot[3045]: time="2025-11-02T04:11:20Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:11:20 volumio go-librespot[3045]: time="2025-11-02T04:11:20Z" level=debug msg="app state loaded" Nov 02 04:11:20 volumio go-librespot[3045]: time="2025-11-02T04:11:20Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:11:20 volumio go-librespot[3045]: time="2025-11-02T04:11: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 02 04:11:20 volumio go-librespot[3045]: time="2025-11-02T04:11:20Z" 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 02 04:11:20 volumio go-librespot[3045]: time="2025-11-02T04:11:20Z" 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 02 04:11:20 volumio go-librespot[3045]: time="2025-11-02T04:11:20Z" level=info msg="zeroconf server listening on port 36003" Nov 02 04:11:20 volumio go-librespot[3045]: time="2025-11-02T04:11:20Z" level=debug msg="obtained new client token: AACvzRkdBFWTm5aeVTAps5SZrsDCRhLULR0jMxfD8kh+RrJDwuhaFRIV1suAxFA12608c8il1ZtxYwRRJhHCbdI6KyGuaZB400oK0uA7v9t3Ff3E/VrKsttrfBIIAhc2+EYVftau7/M9O3ic+8gYdIViH7ThyxZ/0LGiqfupSLD7EEJHGViFUwKCdiH1M4/pY5IlrhrDAoVHz8a8JpIcDKlpA26bGoyUqlgjJad2W7gbf3fAC2+x" Nov 02 04:11:20 volumio go-librespot[3045]: time="2025-11-02T04:11:20Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:11:20 volumio go-librespot[3045]: time="2025-11-02T04:11:20Z" level=debug msg="completed keyexchange" Nov 02 04:11:20 volumio go-librespot[3045]: time="2025-11-02T04:11:20Z" level=debug msg="completed challenge" Nov 02 04:11:20 volumio go-librespot[3045]: time="2025-11-02T04:11: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 02 04:11:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:11:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:11:23 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:23 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 100. Nov 02 04:11:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:23 volumio go-librespot[3052]: go-librespot daemon starting... Nov 02 04:11:23 volumio go-librespot[3053]: time="2025-11-02T04:11:23Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:11:23 volumio go-librespot[3053]: time="2025-11-02T04:11:23Z" level=debug msg="app state loaded" Nov 02 04:11:23 volumio go-librespot[3053]: time="2025-11-02T04:11:23Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:11:23 volumio go-librespot[3053]: time="2025-11-02T04:11:23Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 02 04:11:23 volumio go-librespot[3053]: time="2025-11-02T04:11:23Z" 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 02 04:11:23 volumio go-librespot[3053]: time="2025-11-02T04:11:23Z" 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 02 04:11:23 volumio go-librespot[3053]: time="2025-11-02T04:11:23Z" level=info msg="zeroconf server listening on port 38613" Nov 02 04:11:23 volumio go-librespot[3053]: time="2025-11-02T04:11:23Z" level=debug msg="obtained new client token: AABvXPptwEi8hL+PmsP8ARBv+afAsx+/S1UQz/psTvu80tfMLA/1zOnwBr3+Vy7scnDnbskIHermM0sy/wobMvu5tXfEGTYDcEQ0Jp1zru2R1DHx/2MUEffwnxtQDG7s88x23IhQzrGUbFAjJ5XcaWV2IeWWvxnTJU+MlKKRg3ViZ8mqKsDyFX7bRhAC+vbGFlmOEH3OVf0T4wD015uqh2iEiVyuUTYKc7dfcWZCQEkv1eYouvUbVXs=" Nov 02 04:11:23 volumio go-librespot[3053]: time="2025-11-02T04:11:23Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:11:23 volumio go-librespot[3053]: time="2025-11-02T04:11:23Z" level=debug msg="completed keyexchange" Nov 02 04:11:23 volumio go-librespot[3053]: time="2025-11-02T04:11:23Z" level=debug msg="completed challenge" Nov 02 04:11:23 volumio go-librespot[3053]: time="2025-11-02T04:11: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 02 04:11:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:11:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:11:26 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:26 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 101. Nov 02 04:11:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:27 volumio go-librespot[3060]: go-librespot daemon starting... Nov 02 04:11:27 volumio go-librespot[3061]: time="2025-11-02T04:11:27Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:11:27 volumio go-librespot[3061]: time="2025-11-02T04:11:27Z" level=debug msg="app state loaded" Nov 02 04:11:27 volumio go-librespot[3061]: time="2025-11-02T04:11:27Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:11:27 volumio go-librespot[3061]: time="2025-11-02T04:11: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 02 04:11:27 volumio go-librespot[3061]: time="2025-11-02T04:11: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 02 04:11:27 volumio go-librespot[3061]: time="2025-11-02T04:11: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 02 04:11:27 volumio go-librespot[3061]: time="2025-11-02T04:11:27Z" level=info msg="zeroconf server listening on port 33565" Nov 02 04:11:27 volumio go-librespot[3061]: time="2025-11-02T04:11:27Z" level=debug msg="obtained new client token: AAC2J8OqzRRVvnEUT0WgbSHInD1VtD4vklOw9q4wdpplMcn2Vypt6LUPWMu+GgwM2OTJzwx6yJXivJf18bETYI9aToKka07+5d8DxXl7nqHiq0rgJlPhfn7WmdRc+sdeOVB1WZLRbgG4uq1+epbwhPGpgRBqwmZRP3bDZVKrHLpN5QZym7izWSqpbILHUqACikrwFkuesNFwk5Hyzax7gGomvvOly0QnCbsnnlnleup4dhbbYFdr" Nov 02 04:11:27 volumio go-librespot[3061]: time="2025-11-02T04:11:27Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:11:27 volumio go-librespot[3061]: time="2025-11-02T04:11:27Z" level=debug msg="completed keyexchange" Nov 02 04:11:27 volumio go-librespot[3061]: time="2025-11-02T04:11:27Z" level=debug msg="completed challenge" Nov 02 04:11:27 volumio go-librespot[3061]: time="2025-11-02T04:11: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 02 04:11:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:11:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:11:29 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:29 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 102. Nov 02 04:11:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:30 volumio go-librespot[3084]: go-librespot daemon starting... Nov 02 04:11:30 volumio go-librespot[3085]: time="2025-11-02T04:11:30Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:11:30 volumio go-librespot[3085]: time="2025-11-02T04:11:30Z" level=debug msg="app state loaded" Nov 02 04:11:30 volumio go-librespot[3085]: time="2025-11-02T04:11:30Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:11:30 volumio go-librespot[3085]: time="2025-11-02T04:11:30Z" 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 02 04:11:30 volumio go-librespot[3085]: time="2025-11-02T04:11:30Z" 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 02 04:11:30 volumio go-librespot[3085]: time="2025-11-02T04:11:30Z" 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 02 04:11:30 volumio go-librespot[3085]: time="2025-11-02T04:11:30Z" level=info msg="zeroconf server listening on port 42509" Nov 02 04:11:30 volumio go-librespot[3085]: time="2025-11-02T04:11:30Z" level=debug msg="obtained new client token: AACCbdXsq/kgp6pnhbwthvMV449/Mobsd3cgUZU8CobUIAU1wNJ3YZ1CJMrsc1nMLNVhRJiWklF+pryB3mM0lXps4YvgoV8bKtQRdUwymGsWKwXGnWtPKH54itRGQ/kDErHbfVnDAz6jehW1WlM180nS4rYL0aOHdv3ksI/y8VrADtiaziHuoLrtSpyNan5mPVCdeqhhI/kt/ulxQMe8qws3jaG4KozDa3skUa+XqDX0J9LyIsSi7Vs=" Nov 02 04:11:30 volumio go-librespot[3085]: time="2025-11-02T04:11:30Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:11:30 volumio go-librespot[3085]: time="2025-11-02T04:11:30Z" level=debug msg="completed keyexchange" Nov 02 04:11:30 volumio go-librespot[3085]: time="2025-11-02T04:11:30Z" level=debug msg="completed challenge" Nov 02 04:11:30 volumio go-librespot[3085]: time="2025-11-02T04:11: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 02 04:11:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:11:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:11:32 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:32 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 103. Nov 02 04:11:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:34 volumio go-librespot[3095]: go-librespot daemon starting... Nov 02 04:11:34 volumio go-librespot[3096]: time="2025-11-02T04:11:34Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:11:34 volumio go-librespot[3096]: time="2025-11-02T04:11:34Z" level=debug msg="app state loaded" Nov 02 04:11:34 volumio go-librespot[3096]: time="2025-11-02T04:11:34Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:11:34 volumio go-librespot[3096]: time="2025-11-02T04:11: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 02 04:11:34 volumio go-librespot[3096]: time="2025-11-02T04:11:34Z" 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 02 04:11:34 volumio go-librespot[3096]: time="2025-11-02T04:11:34Z" 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 02 04:11:34 volumio go-librespot[3096]: time="2025-11-02T04:11:34Z" level=info msg="zeroconf server listening on port 40501" Nov 02 04:11:34 volumio go-librespot[3096]: time="2025-11-02T04:11:34Z" level=debug msg="obtained new client token: AAAo5gbu8eY/YZ8ZhHuIId3nY1ws8f3j9PGdeI/136iq/xh9hP3r6paWtS0C3OVcAcgoOBy8WuJY/2fzYw4jp7gU02+c7xihRxdCycl3wbDVW3YzB1qoCMWnIkFmcxojOrt725fPPtcHKTYDdaHkmyjnqXjm8VeefJX1eTZ+j+x5YneiLXTiRiRC9fOAUsRD+e1XSFKhF6rZifgPKQsm3MSr4j9zTpkXW2ei2OzNHqD1S2JLzT2S" Nov 02 04:11:34 volumio go-librespot[3096]: time="2025-11-02T04:11:34Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Nov 02 04:11:34 volumio go-librespot[3096]: time="2025-11-02T04:11:34Z" level=debug msg="connected to ap-gew1.spotify.com:443" Nov 02 04:11:34 volumio go-librespot[3096]: time="2025-11-02T04:11:34Z" level=debug msg="completed keyexchange" Nov 02 04:11:34 volumio go-librespot[3096]: time="2025-11-02T04:11:34Z" level=debug msg="completed challenge" Nov 02 04:11:34 volumio go-librespot[3096]: time="2025-11-02T04:11: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 02 04:11:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:11:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:11:35 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:35 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:36 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 02 04:11:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 104. Nov 02 04:11:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:37 volumio go-librespot[3103]: go-librespot daemon starting... Nov 02 04:11:37 volumio go-librespot[3104]: time="2025-11-02T04:11:37Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:11:37 volumio go-librespot[3104]: time="2025-11-02T04:11:37Z" level=debug msg="app state loaded" Nov 02 04:11:37 volumio go-librespot[3104]: time="2025-11-02T04:11:37Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:11:37 volumio go-librespot[3104]: time="2025-11-02T04:11:37Z" 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 02 04:11:37 volumio go-librespot[3104]: time="2025-11-02T04:11:37Z" 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 02 04:11:37 volumio go-librespot[3104]: time="2025-11-02T04:11:37Z" 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 02 04:11:37 volumio go-librespot[3104]: time="2025-11-02T04:11:37Z" level=info msg="zeroconf server listening on port 42653" Nov 02 04:11:37 volumio go-librespot[3104]: time="2025-11-02T04:11:37Z" level=debug msg="obtained new client token: AADqzYKCyW/yRnWU8ZokmKJGiIWlhfQPbmDszBCFCKnYSRvejCKsmoN3IPbuk15W2h7n0TSlxAe0ZO0Xu2dC/7QleYhyCKN5+O+wsVXT1iyeY+asNIqaB1mX3kZ3qjvdzo673Yio1gykVSS4Uq4W3PReDxHKnmlDRctMe5zlNHUFaeHo7wQPRtbAkJ3Os+7vgifoJoDDv82iwcwbUQCTN3rohmmyQj2vJ1jYNJTzhrrCdiG+UsPEJzI=" Nov 02 04:11:37 volumio go-librespot[3104]: time="2025-11-02T04:11:37Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:11:37 volumio go-librespot[3104]: time="2025-11-02T04:11:37Z" level=debug msg="completed keyexchange" Nov 02 04:11:37 volumio go-librespot[3104]: time="2025-11-02T04:11:37Z" level=debug msg="completed challenge" Nov 02 04:11:37 volumio go-librespot[3104]: time="2025-11-02T04:11: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 02 04:11:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:11:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:11:38 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:38 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 105. Nov 02 04:11:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:41 volumio go-librespot[3125]: go-librespot daemon starting... Nov 02 04:11:41 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:41 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:41 volumio go-librespot[3126]: time="2025-11-02T04:11:41Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:11:41 volumio go-librespot[3126]: time="2025-11-02T04:11:41Z" level=debug msg="app state loaded" Nov 02 04:11:41 volumio go-librespot[3126]: time="2025-11-02T04:11:41Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:11:41 volumio go-librespot[3126]: time="2025-11-02T04:11:41Z" 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 02 04:11:41 volumio go-librespot[3126]: time="2025-11-02T04:11:41Z" 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 02 04:11:41 volumio go-librespot[3126]: time="2025-11-02T04:11:41Z" 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 02 04:11:41 volumio go-librespot[3126]: time="2025-11-02T04:11:41Z" level=info msg="zeroconf server listening on port 33657" Nov 02 04:11:41 volumio go-librespot[3126]: time="2025-11-02T04:11:41Z" level=debug msg="obtained new client token: AAC7RrrvzdqH0ggdQ9qm84lVtTQbLhEhK794OEs/H0dcL1TkhAdCbVWoyLfoyuKKpVFWoHxLWBcYXDentsne/CfFi8/BaMrjmkfBZAaBwhJVhBKVYM/ADF5i2yKfDPEQ7RWXrm/r0x1/nOUYV08Xj7a9nVTHTKZYYok8YOh7Jy13g4gbCSfSDNOBbmUKzP6xXV6UDPiYdm24QBii6uVV6uEY08TInhkjubHEJFFHAiJMCQRfX3fF" Nov 02 04:11:41 volumio go-librespot[3126]: time="2025-11-02T04:11:41Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:11:41 volumio go-librespot[3126]: time="2025-11-02T04:11:41Z" level=debug msg="completed keyexchange" Nov 02 04:11:41 volumio go-librespot[3126]: time="2025-11-02T04:11:41Z" level=debug msg="completed challenge" Nov 02 04:11:41 volumio go-librespot[3126]: time="2025-11-02T04:11:41Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 04:11:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:11:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:11:41 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 02 04:11:44 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:44 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 106. Nov 02 04:11:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:44 volumio go-librespot[3133]: go-librespot daemon starting... Nov 02 04:11:44 volumio go-librespot[3134]: time="2025-11-02T04:11:44Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:11:44 volumio go-librespot[3134]: time="2025-11-02T04:11:44Z" level=debug msg="app state loaded" Nov 02 04:11:44 volumio go-librespot[3134]: time="2025-11-02T04:11:44Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:11:44 volumio go-librespot[3134]: time="2025-11-02T04:11:44Z" 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 02 04:11:44 volumio go-librespot[3134]: time="2025-11-02T04:11:44Z" 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 02 04:11:44 volumio go-librespot[3134]: time="2025-11-02T04:11:44Z" 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 02 04:11:44 volumio go-librespot[3134]: time="2025-11-02T04:11:44Z" level=info msg="zeroconf server listening on port 43587" Nov 02 04:11:44 volumio go-librespot[3134]: time="2025-11-02T04:11:44Z" level=debug msg="obtained new client token: AACfxvFPoBsXclRfT+l479zc8Rl4If/WJD3zaKoTEgribt2sfD5ra+ziTI6660yhLPcO1KAGXRPzdd0NvYhvpEQtx6oi97T//XqamWBUm2p5nKER4AR2wNGyKirmHS8HUbYP2J2e1IK1m2E6ji3VgkFQiqAJI1DdIN+kPBbVzF7Z62eAghRAdupp8HxQgpJnLv02svXLTPomZ5+68KvtrV+ARfC7dilB5U4OYBV3WZ0vhXfA9BGiLCk=" Nov 02 04:11:44 volumio go-librespot[3134]: time="2025-11-02T04:11:44Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:11:44 volumio go-librespot[3134]: time="2025-11-02T04:11:44Z" level=debug msg="completed keyexchange" Nov 02 04:11:44 volumio go-librespot[3134]: time="2025-11-02T04:11:44Z" level=debug msg="completed challenge" Nov 02 04:11:44 volumio go-librespot[3134]: time="2025-11-02T04:11:44Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 04:11:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:11:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:11:47 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:47 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 107. Nov 02 04:11:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:48 volumio go-librespot[3143]: go-librespot daemon starting... Nov 02 04:11:48 volumio go-librespot[3144]: time="2025-11-02T04:11:48Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:11:48 volumio go-librespot[3144]: time="2025-11-02T04:11:48Z" level=debug msg="app state loaded" Nov 02 04:11:48 volumio go-librespot[3144]: time="2025-11-02T04:11:48Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:11:48 volumio go-librespot[3144]: time="2025-11-02T04:11: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-gae2.spotify.com:80]" Nov 02 04:11:48 volumio go-librespot[3144]: time="2025-11-02T04:11:48Z" 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 02 04:11:48 volumio go-librespot[3144]: time="2025-11-02T04:11:48Z" 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 02 04:11:48 volumio go-librespot[3144]: time="2025-11-02T04:11:48Z" level=info msg="zeroconf server listening on port 34267" Nov 02 04:11:48 volumio go-librespot[3144]: time="2025-11-02T04:11:48Z" level=debug msg="obtained new client token: AABAHijgbFA7CYm0ybemt2vHBeatmePX/k5dv3U8283ZvD5efbAanfNNAw3i3roAf/rh7OxhLVfP9mcxSumd5mVvl5KhEAPxNhSxlAOfQ7RG6x8CPJu8W9T1qP0tDUuL1KOpCgvGrOgF8VihmY/QCV6CXZ1lQas9RBwkVqPDSLfCusdYZEfDRY9tKPZzBcVrgCCAt6s/v6Bn4EkMLH9AUQBONdn3jAif/Ta/mbiuIkUWYwk++B/y" Nov 02 04:11:48 volumio go-librespot[3144]: time="2025-11-02T04:11:48Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:11:48 volumio go-librespot[3144]: time="2025-11-02T04:11:48Z" level=debug msg="completed keyexchange" Nov 02 04:11:48 volumio go-librespot[3144]: time="2025-11-02T04:11:48Z" level=debug msg="completed challenge" Nov 02 04:11:48 volumio go-librespot[3144]: time="2025-11-02T04:11:48Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 04:11:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:11:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:11:50 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:50 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 108. Nov 02 04:11:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:51 volumio go-librespot[3165]: go-librespot daemon starting... Nov 02 04:11:51 volumio go-librespot[3166]: time="2025-11-02T04:11:51Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:11:51 volumio go-librespot[3166]: time="2025-11-02T04:11:51Z" level=debug msg="app state loaded" Nov 02 04:11:51 volumio go-librespot[3166]: time="2025-11-02T04:11:51Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:11:51 volumio go-librespot[3166]: time="2025-11-02T04:11:51Z" 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 02 04:11:51 volumio go-librespot[3166]: time="2025-11-02T04:11:51Z" 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 02 04:11:51 volumio go-librespot[3166]: time="2025-11-02T04:11:51Z" 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 02 04:11:51 volumio go-librespot[3166]: time="2025-11-02T04:11:51Z" level=info msg="zeroconf server listening on port 40471" Nov 02 04:11:51 volumio go-librespot[3166]: time="2025-11-02T04:11:51Z" level=debug msg="obtained new client token: AABnCR2Exgu2Aw/T1Hyg89lF9Dt6ldXX9dt1DG10R5nxZYh4XpAXzvmrO4nb1HN05Rb9Upxu8nvpxKV24HEV/fxVYJflWjczYKfkX17SZheZGBC8ZExkEihcvDA81d20kQolWnQBzdM/jAslQu9KOt4sPwzTgPS085itHLMoO0NhMxkb0x41C07rgGdC3yintFeeBocp52S8DP27oGbYMOXmmksWSe/2csHYUw5zLqS8Ea7MqkggJog=" Nov 02 04:11:51 volumio go-librespot[3166]: time="2025-11-02T04:11:51Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Nov 02 04:11:51 volumio go-librespot[3166]: time="2025-11-02T04:11:51Z" level=debug msg="connected to ap-gew1.spotify.com:443" Nov 02 04:11:51 volumio go-librespot[3166]: time="2025-11-02T04:11:51Z" level=debug msg="completed keyexchange" Nov 02 04:11:51 volumio go-librespot[3166]: time="2025-11-02T04:11:51Z" level=debug msg="completed challenge" Nov 02 04:11:51 volumio go-librespot[3166]: time="2025-11-02T04:11:51Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 04:11:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:11:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:11:53 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:53 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:54 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 02 04:11:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 109. Nov 02 04:11:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:55 volumio go-librespot[3176]: go-librespot daemon starting... Nov 02 04:11:55 volumio go-librespot[3177]: time="2025-11-02T04:11:55Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:11:55 volumio go-librespot[3177]: time="2025-11-02T04:11:55Z" level=debug msg="app state loaded" Nov 02 04:11:55 volumio go-librespot[3177]: time="2025-11-02T04:11:55Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:11:55 volumio go-librespot[3177]: time="2025-11-02T04:11:55Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 02 04:11:55 volumio go-librespot[3177]: time="2025-11-02T04:11:55Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 02 04:11:55 volumio go-librespot[3177]: time="2025-11-02T04:11:55Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 02 04:11:55 volumio go-librespot[3177]: time="2025-11-02T04:11:55Z" level=info msg="zeroconf server listening on port 32799" Nov 02 04:11:55 volumio go-librespot[3177]: time="2025-11-02T04:11:55Z" level=debug msg="obtained new client token: AAAAbZSfB/HbA33e+2wcY6LdhMo7uH3CZuANluIQWy688DwE92udzxSdb4AeKE1BWZGwoPkYN+FBGF4TYeLAV4MXhgfkP7cQ6EfBjG4lec7sY/gZzhSn4r7Lyb35mmEQNh/kfGi3vJO8+35BPGLzCKK5zsHAZgE8Jw/7sr4q6HKX6XEJBBfCd6wtJTbOJSvgZKgpgm/PM3JmTlj4PAI9UgkMdhwRNqpONEDuIqbm3nSWkDMf4YPe" Nov 02 04:11:55 volumio go-librespot[3177]: time="2025-11-02T04:11:55Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Nov 02 04:11:55 volumio go-librespot[3177]: time="2025-11-02T04:11:55Z" level=debug msg="connected to ap-gew1.spotify.com:443" Nov 02 04:11:55 volumio go-librespot[3177]: time="2025-11-02T04:11:55Z" level=debug msg="completed keyexchange" Nov 02 04:11:55 volumio go-librespot[3177]: time="2025-11-02T04:11:55Z" level=debug msg="completed challenge" Nov 02 04:11:55 volumio go-librespot[3177]: time="2025-11-02T04:11:55Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 04:11:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:11:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:11:56 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:56 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:11:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 110. Nov 02 04:11:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:11:58 volumio go-librespot[3198]: go-librespot daemon starting... Nov 02 04:11:58 volumio go-librespot[3199]: time="2025-11-02T04:11:58Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:11:58 volumio go-librespot[3199]: time="2025-11-02T04:11:58Z" level=debug msg="app state loaded" Nov 02 04:11:58 volumio go-librespot[3199]: time="2025-11-02T04:11:58Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:11:58 volumio go-librespot[3199]: time="2025-11-02T04:11:58Z" 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 02 04:11:58 volumio go-librespot[3199]: time="2025-11-02T04:11:58Z" 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 02 04:11:58 volumio go-librespot[3199]: time="2025-11-02T04:11:58Z" 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 02 04:11:58 volumio go-librespot[3199]: time="2025-11-02T04:11:58Z" level=info msg="zeroconf server listening on port 41915" Nov 02 04:11:58 volumio go-librespot[3199]: time="2025-11-02T04:11:58Z" level=debug msg="obtained new client token: AACLa49yXP7QtuUi98Hzy+dLAl1qFYUtY98mG3/GgDWLSbHX4TitSyiY5a5hVb8wGAHezqCT9J9uAeI+bOxDJyb6QsrVhA8DVSJC2wmUK0lVJBL476XxegykeOZ/t/gSDY+T/9fv2lia9YXWx+xpn1cc9DLLiZTFTbPxO86YkYYvPgj0GroKoBHQqaIhXJABDHT6McOiCcUWBGy3hYQD5VgO1kLvhnjbhZP1KVNh65TVEH+Iclqg8hM=" Nov 02 04:11:58 volumio go-librespot[3199]: time="2025-11-02T04:11:58Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:11:58 volumio go-librespot[3199]: time="2025-11-02T04:11:58Z" level=debug msg="completed keyexchange" Nov 02 04:11:58 volumio go-librespot[3199]: time="2025-11-02T04:11:58Z" level=debug msg="completed challenge" Nov 02 04:11:58 volumio go-librespot[3199]: time="2025-11-02T04:11:58Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 04:11:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:11:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:11:59 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:11:59 volumio volumio[2206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:12:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 111. Nov 02 04:12:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:12:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:12:02 volumio go-librespot[3206]: go-librespot daemon starting... Nov 02 04:12:02 volumio go-librespot[3207]: time="2025-11-02T04:12:02Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:12:02 volumio go-librespot[3207]: time="2025-11-02T04:12:02Z" level=debug msg="app state loaded" Nov 02 04:12:02 volumio go-librespot[3207]: time="2025-11-02T04:12:02Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:12:02 volumio volumio[2206]: info: Initializing connection to go-librespot Websocket Nov 02 04:12:02 volumio go-librespot[3207]: time="2025-11-02T04:12:02Z" level=debug msg="new websocket client" Nov 02 04:12:02 volumio volumio[2206]: info: Connection to go-librespot Websocket established Nov 02 04:12:02 volumio go-librespot[3207]: time="2025-11-02T04:12: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 02 04:12:02 volumio go-librespot[3207]: time="2025-11-02T04:12: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 02 04:12:02 volumio go-librespot[3207]: time="2025-11-02T04:12: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 02 04:12:02 volumio go-librespot[3207]: time="2025-11-02T04:12:02Z" level=info msg="zeroconf server listening on port 39081" Nov 02 04:12:02 volumio go-librespot[3207]: time="2025-11-02T04:12:02Z" level=debug msg="obtained new client token: AAAivqDk0/sXDCKfnFIYn4iKLh77cmyRi1sTXUwgBBA3+pne4qsl0FoMgrqj6wz5NAWFxR52xkx4iWQX6mJaKtbP5O+CvUlV2ll+PuHB+6k3bdRvDc0gUhKpcgTi5UqA9AiIEaPOaI5eUcK5u8XtFN8gY2m09X8QnzGlkBTXJ0lbFxFEgXMRFndwO7dXQny+6y+QAvO+f6ZqNBQZiAwYcVglm4NEXOV7Gh8AN9fW6kgb72GvnW0v" Nov 02 04:12:02 volumio go-librespot[3207]: time="2025-11-02T04:12:02Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:12:02 volumio go-librespot[3207]: time="2025-11-02T04:12:02Z" level=debug msg="completed keyexchange" Nov 02 04:12:02 volumio go-librespot[3207]: time="2025-11-02T04:12:02Z" level=debug msg="completed challenge" Nov 02 04:12:02 volumio go-librespot[3207]: time="2025-11-02T04:12:02Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 04:12:02 volumio volumio[2206]: info: Connection to go-librespot Websocket closed Nov 02 04:12:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:12:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:12:05 volumio volumio[2206]: info: Getting Spotify volume Nov 02 04:12:05 volumio volumio[2206]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 02 04:12:05 volumio volumio[2206]: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:12:05 volumio volumio[2206]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Nov 02 04:12:05 volumio volumio[2206]: errno: -111, Nov 02 04:12:05 volumio volumio[2206]: code: 'ECONNREFUSED', Nov 02 04:12:05 volumio volumio[2206]: syscall: 'connect', Nov 02 04:12:05 volumio volumio[2206]: address: '127.0.0.1', Nov 02 04:12:05 volumio volumio[2206]: port: 9879, Nov 02 04:12:05 volumio volumio[2206]: response: undefined Nov 02 04:12:05 volumio volumio[2206]: } Nov 02 04:12:05 volumio volumio[2206]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 02 04:12:05 volumio sudo[3228]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-11-02 04:11' Nov 02 04:12:05 volumio sudo[3228]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 04:12:05 volumio sudo[3228]: pam_unix(sudo:session): session closed for user root Nov 02 04:12:05 volumio volumio-remote-updater[874]: [2025-11-02 04:12:05] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Nov 02 04:12:05 volumio volumio-remote-updater[874]: [2025-11-02 04:12:05] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Nov 02 04:12:05 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:12:05 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Nov 02 04:12:05 volumio systemd[1]: volumio.service: Consumed 8.454s CPU time. Nov 02 04:12:05 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Nov 02 04:12:05 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Nov 02 04:12:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 112. Nov 02 04:12:05 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 5141. Nov 02 04:12:05 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Nov 02 04:12:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:12:05 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Nov 02 04:12:05 volumio systemd[1]: volumio.service: Consumed 8.454s CPU time. Nov 02 04:12:05 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Nov 02 04:12:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:12:05 volumio go-librespot[3248]: go-librespot daemon starting... Nov 02 04:12:05 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Nov 02 04:12:05 volumio go-librespot[3249]: time="2025-11-02T04:12:05Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:12:05 volumio go-librespot[3249]: time="2025-11-02T04:12:05Z" level=debug msg="app state loaded" Nov 02 04:12:05 volumio go-librespot[3249]: time="2025-11-02T04:12:05Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:12:05 volumio go-librespot[3249]: time="2025-11-02T04:12:05Z" 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 02 04:12:05 volumio go-librespot[3249]: time="2025-11-02T04:12:05Z" 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 02 04:12:05 volumio go-librespot[3249]: time="2025-11-02T04:12:05Z" 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 02 04:12:05 volumio go-librespot[3249]: time="2025-11-02T04:12:05Z" level=info msg="zeroconf server listening on port 42205" Nov 02 04:12:05 volumio go-librespot[3249]: time="2025-11-02T04:12:05Z" level=debug msg="obtained new client token: AAA7jgvqpmYrF4hcU6AsBy9oz0Y15Db5fnfBZfb2Aa7DExRD2bFzQCXvEYjvu8bU/r6tIVsaF8q7WIlCdFfZ+rpRWM+9VfSPRNyJgcIvwWXjspFB9WdxtURG6KzfoyaAGIQGpLkotpJmq7Rc0Qa1Wjx8S0ixMhvoZjPuMQrnuzeIBDUC7IAtYpc399dUGME96HqUTjE9jJ4/T1PlUGe/Pvk/fiaWPkU7/OQwqh2dSlEEV5Sw25gU4xQ=" Nov 02 04:12:05 volumio go-librespot[3249]: time="2025-11-02T04:12:05Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:12:05 volumio go-librespot[3249]: time="2025-11-02T04:12:05Z" level=debug msg="completed keyexchange" Nov 02 04:12:05 volumio go-librespot[3249]: time="2025-11-02T04:12:05Z" level=debug msg="completed challenge" Nov 02 04:12:05 volumio go-librespot[3249]: time="2025-11-02T04:12:05Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 04:12:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:12:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:12:05 volumio volumio[3243]: info: ------------------------------------------- Nov 02 04:12:05 volumio volumio[3243]: info: ----- Volumio3 ---- Nov 02 04:12:05 volumio volumio[3243]: info: ------------------------------------------- Nov 02 04:12:05 volumio volumio[3243]: info: ----- System startup ---- Nov 02 04:12:05 volumio volumio[3243]: info: ------------------------------------------- Nov 02 04:12:06 volumio volumio[3243]: info: MYVOLUMIO Environment detected Nov 02 04:12:06 volumio volumio[3243]: info: Plugin folders cleanup Nov 02 04:12:06 volumio volumio[3243]: info: Scanning into folder /volumio/app/plugins/ Nov 02 04:12:06 volumio volumio[3243]: info: Scanning category audio_interface Nov 02 04:12:06 volumio volumio[3243]: info: Scanning category miscellanea Nov 02 04:12:06 volumio volumio[3243]: info: Scanning category music_service Nov 02 04:12:06 volumio volumio[3243]: info: Scanning category plugins.json Nov 02 04:12:06 volumio volumio[3243]: info: Scanning category system_controller Nov 02 04:12:06 volumio volumio[3243]: info: Scanning category user_interface Nov 02 04:12:06 volumio volumio[3243]: info: Scanning into folder /data/plugins/ Nov 02 04:12:06 volumio volumio[3243]: info: Scanning category music_service Nov 02 04:12:06 volumio volumio[3243]: info: Scanning category user_interface Nov 02 04:12:06 volumio volumio[3243]: info: Plugin folders cleanup completed Nov 02 04:12:06 volumio volumio[3243]: info: ------------------------------------------- Nov 02 04:12:06 volumio volumio[3243]: info: ----- Core plugins startup ---- Nov 02 04:12:06 volumio volumio[3243]: info: ------------------------------------------- Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugins from folder /volumio/app/plugins/ Nov 02 04:12:06 volumio volumio[3243]: info: Adding plugin upnp to MyMusic Plugins Nov 02 04:12:06 volumio volumio[3243]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 02 04:12:06 volumio volumio[3243]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugins from folder /data/plugins/ Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "system"... Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "appearance"... Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "network"... Nov 02 04:12:06 volumio volumio[3243]: info: Refreshing Cached IP Addresses Nov 02 04:12:06 volumio sudo[3278]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 02 04:12:06 volumio sudo[3278]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "services"... Nov 02 04:12:06 volumio sudo[3278]: pam_unix(sudo:session): session closed for user root Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "alsa_controller"... Nov 02 04:12:06 volumio sudo[3280]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 02 04:12:06 volumio sudo[3280]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 04:12:06 volumio sudo[3280]: pam_unix(sudo:session): session closed for user root Nov 02 04:12:06 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "wizard"... Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "networkfs"... Nov 02 04:12:06 volumio volumio[3243]: info: Cannot mount NAS NAS at system boot, trial number 1 ,retrying in 5 seconds Nov 02 04:12:06 volumio volumio[3243]: info: Starting Udev Watcher for removable devices Nov 02 04:12:06 volumio volumio[3243]: info: Ignoring mount for partition: boot Nov 02 04:12:06 volumio volumio[3243]: info: Ignoring mount for partition: volumio Nov 02 04:12:06 volumio volumio[3243]: info: Ignoring mount for partition: volumio_data Nov 02 04:12:06 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "volumio_command_line_client"... Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "upnp"... Nov 02 04:12:06 volumio volumio[3243]: info: [1762056726313] Starting Upmpd Daemon Nov 02 04:12:06 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "my_music"... Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "mpd"... Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "upnp_browser"... Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "alarm-clock"... Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "airplay_emulation"... Nov 02 04:12:06 volumio volumio[3243]: info: Starting Shairport Sync Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "last_100"... Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "webradio"... Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "i2s_dacs"... Nov 02 04:12:06 volumio volumio[3243]: info: I2S DAC not set, start Auto-detection Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "volumiodiscovery"... Nov 02 04:12:06 volumio volumio[3243]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 02 04:12:06 volumio volumio[3243]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 02 04:12:06 volumio volumio[3243]: *** WARNING *** For more information see Nov 02 04:12:06 volumio volumio[3243]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 02 04:12:06 volumio volumio[3243]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 02 04:12:06 volumio volumio[3243]: *** WARNING *** For more information see Nov 02 04:12:06 volumio node[3243]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 02 04:12:06 volumio node[3243]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 02 04:12:06 volumio node[3243]: *** WARNING *** For more information see Nov 02 04:12:06 volumio node[3243]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 02 04:12:06 volumio node[3243]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 02 04:12:06 volumio node[3243]: *** WARNING *** For more information see Nov 02 04:12:06 volumio volumio[3243]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 02 04:12:06 volumio volumio[3243]: info: Discovery: Started advertising with name: Volumio Nov 02 04:12:06 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "spop"... Nov 02 04:12:06 volumio volumio[3243]: info: Loading plugin "ytcr"... Nov 02 04:12:07 volumio volumio[3243]: info: Loading plugin "outputs"... Nov 02 04:12:07 volumio volumio[3243]: info: Loading plugin "albumart"... Nov 02 04:12:07 volumio volumio[3243]: info: Plugin example_plugin is not enabled Nov 02 04:12:07 volumio volumio[3243]: info: Loading plugin "inputs"... Nov 02 04:12:07 volumio volumio[3243]: info: Loading plugin "updater_comm"... Nov 02 04:12:07 volumio volumio[3243]: info: Plugin mpdemulation is not enabled Nov 02 04:12:07 volumio volumio[3243]: info: Loading plugin "rest_api"... Nov 02 04:12:07 volumio volumio[3243]: info: Loading plugin "websocket"... Nov 02 04:12:07 volumio volumio[3243]: info: Starting Socket.io Server version 1.7.4 Nov 02 04:12:07 volumio volumio[3243]: info: Loading plugin "Systeminfo"... Nov 02 04:12:07 volumio volumio[3243]: info: Loading i18n strings for locale en Nov 02 04:12:07 volumio volumio[3243]: Updating browse sources language Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 02 04:12:07 volumio volumio[3310]: Forking 3 albumart workers Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::initPlayerControls Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 02 04:12:07 volumio volumio[3243]: Express server listening on port 3000 Nov 02 04:12:07 volumio volumio[3243]: [Metrics] WebUI: 1s 931.09ms Nov 02 04:12:07 volumio volumio[3243]: info: CoreStateMachine::resetVolumioState Nov 02 04:12:07 volumio volumio[3243]: info: CoreStateMachine::getcurrentVolume Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::volumioRetrievevolume Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 04:12:07 volumio volumio[3243]: info: Cannot read play queue from file Nov 02 04:12:07 volumio volumio[3243]: info: Volumio Network Manager: Network status updated: 1 Nov 02 04:12:07 volumio volumio[3243]: info: VolumeController:: Volume=33 Mute =false Nov 02 04:12:07 volumio volumio[3243]: info: CoreStateMachine::pushState Nov 02 04:12:07 volumio volumio[3243]: info: CorePlayQueue::getTrack 0 Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::volumioPushState Nov 02 04:12:07 volumio volumio[3243]: info: CoreStateMachine::updateTrackBlock Nov 02 04:12:07 volumio volumio[3243]: info: CorePlayQueue::getTrackBlock Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::volumioRetrievevolume Nov 02 04:12:07 volumio volumio[3243]: info: CoreStateMachine::setRepeat null single undefined Nov 02 04:12:07 volumio volumio[3243]: info: CoreStateMachine::pushState Nov 02 04:12:07 volumio volumio[3243]: info: CorePlayQueue::getTrack 0 Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::volumioPushState Nov 02 04:12:07 volumio volumio[3243]: info: CoreStateMachine::setRandom null Nov 02 04:12:07 volumio volumio[3243]: info: CoreStateMachine::pushState Nov 02 04:12:07 volumio volumio[3243]: info: CorePlayQueue::getTrack 0 Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::volumioPushState Nov 02 04:12:07 volumio volumio[3243]: info: Setting Device type: Raspberry PI Nov 02 04:12:07 volumio volumio[3243]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Nov 02 04:12:07 volumio volumio[3243]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b04170 Nov 02 04:12:07 volumio volumio[3243]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Nov 02 04:12:07 volumio volumio[3243]: info: Discovery: adding 70853f74-8210-4683-a3fa-e1217517bd40 Nov 02 04:12:07 volumio volumio[3243]: info: Discovery: Found device Volumio Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::volumioGetState Nov 02 04:12:07 volumio volumio[3243]: info: CorePlayQueue::getTrack 0 Nov 02 04:12:07 volumio volumio[3243]: info: VolumeController:: Volume=33 Mute =false Nov 02 04:12:07 volumio volumio[3243]: info: CoreStateMachine::pushState Nov 02 04:12:07 volumio volumio[3243]: info: CorePlayQueue::getTrack 0 Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::volumioPushState Nov 02 04:12:07 volumio volumio[3243]: info: Discovery: this is already registered, 70853f74-8210-4683-a3fa-e1217517bd40 Nov 02 04:12:07 volumio volumio[3243]: info: Discovery: Found device Volumio Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::volumioGetState Nov 02 04:12:07 volumio volumio[3243]: info: CorePlayQueue::getTrack 0 Nov 02 04:12:07 volumio volumio[3243]: info: Completed loading Core Plugins Nov 02 04:12:07 volumio volumio[3243]: info: Preparing to generate the ALSA configuration file Nov 02 04:12:07 volumio volumio[3243]: info: Asound.conf file unchanged, so no further update is needed Nov 02 04:12:07 volumio volumio[3243]: info: Output device has changed, restarting MPD Nov 02 04:12:07 volumio sudo[3368]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 02 04:12:07 volumio sudo[3368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 04:12:07 volumio sudo[3368]: pam_unix(sudo:session): session closed for user root Nov 02 04:12:07 volumio volumio[3243]: info: Output device has changed, restarting Shairport Sync Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:07 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 04:12:07 volumio sudo[3370]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 02 04:12:07 volumio sudo[3370]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 04:12:07 volumio volumio[3243]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 02 04:12:07 volumio volumio[3243]: info: ___________ START PLUGINS ___________ Nov 02 04:12:07 volumio volumio[3243]: info: ControllerMpd::onStart: Initializing MPD Nov 02 04:12:07 volumio volumio[3243]: info: Creating MPD Configuration file Nov 02 04:12:07 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Nov 02 04:12:08 volumio sudo[3377]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 02 04:12:08 volumio sudo[3377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 02 04:12:08 volumio systemd[1]: mpd.service: Deactivated successfully. Nov 02 04:12:08 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 02 04:12:08 volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 02 04:12:08 volumio volumio[3243]: info: [1762056728018] CoreMusicLibrary::Adding element Media Servers Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 02 04:12:08 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 02 04:12:08 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 02 04:12:08 volumio sudo[3377]: pam_unix(sudo:session): session closed for user root Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 04:12:08 volumio sudo[3379]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 02 04:12:08 volumio sudo[3379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 04:12:08 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 02 04:12:08 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 02 04:12:08 volumio volumio[3243]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 02 04:12:08 volumio volumio[3243]: info: [1762056728063] CoreMusicLibrary::Adding element Last_100 Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 02 04:12:08 volumio volumio[3243]: info: [1762056728064] CoreMusicLibrary::Adding element Webradio Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 02 04:12:08 volumio volumio[3243]: info: Initializing BBC Radios Nov 02 04:12:08 volumio systemd[1]: mpd.service: Deactivated successfully. Nov 02 04:12:08 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 02 04:12:08 volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 02 04:12:08 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 02 04:12:08 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 02 04:12:08 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 02 04:12:08 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 04:12:08 volumio volumio[3320]: Starting albumart workers Nov 02 04:12:08 volumio volumio[3243]: info: Creating Spotify config file Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio sudo[3401]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 02 04:12:08 volumio sudo[3401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 02 04:12:08 volumio sudo[3401]: pam_unix(sudo:session): session closed for user root Nov 02 04:12:08 volumio volumio[3243]: info: Volumio Calling Home Nov 02 04:12:08 volumio volumio[3321]: Starting albumart workers Nov 02 04:12:08 volumio volumio[3330]: Starting albumart workers Nov 02 04:12:08 volumio volumio[3243]: info: MPD Permissions set Nov 02 04:12:08 volumio volumio[3243]: info: MPD Permissions set Nov 02 04:12:08 volumio volumio[3243]: info: Volumio called home Nov 02 04:12:08 volumio volumio[3243]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Nov 02 04:12:08 volumio volumio[3243]: info: Spotify config file written Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio sudo[3419]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 02 04:12:08 volumio sudo[3419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 04:12:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:12:08 volumio go-librespot[3426]: go-librespot daemon starting... Nov 02 04:12:08 volumio volumio[3243]: info: No need to fix Spotify hosts Nov 02 04:12:08 volumio sudo[3419]: pam_unix(sudo:session): session closed for user root Nov 02 04:12:08 volumio go-librespot[3432]: time="2025-11-02T04:12:08Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:12:08 volumio go-librespot[3432]: time="2025-11-02T04:12:08Z" level=debug msg="app state loaded" Nov 02 04:12:08 volumio go-librespot[3432]: time="2025-11-02T04:12:08Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:12:08 volumio volumio[3243]: info: Starting Shairport Sync Nov 02 04:12:08 volumio volumio[3243]: info: Starting Shairport Sync Nov 02 04:12:08 volumio volumio[3243]: info: Starting Shairport Sync Nov 02 04:12:08 volumio sudo[3442]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 02 04:12:08 volumio sudo[3442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 04:12:08 volumio sudo[3440]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 02 04:12:08 volumio sudo[3440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 04:12:08 volumio sudo[3451]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 02 04:12:08 volumio sudo[3451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 04:12:08 volumio go-librespot[3432]: time="2025-11-02T04:12:08Z" 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 02 04:12:08 volumio go-librespot[3432]: time="2025-11-02T04:12:08Z" 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 02 04:12:08 volumio go-librespot[3432]: time="2025-11-02T04:12:08Z" 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 02 04:12:08 volumio go-librespot[3432]: time="2025-11-02T04:12:08Z" level=info msg="zeroconf server listening on port 39237" Nov 02 04:12:08 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 02 04:12:08 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 02 04:12:08 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 02 04:12:08 volumio systemd[1]: shairport-sync.service: Consumed 1.636s CPU time. Nov 02 04:12:08 volumio volumio[3243]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 02 04:12:08 volumio volumio[3243]: SPOTIFY: BQCvgT3rYmHH_9WsQ7hAcst8_MAzxWc8p6UfQZTmn63ZsvYtFq8QVbADT0aND8XLaPcAVWJKVyJSVb8-Zm8sVn6-Jzqjh4yRh15YhFCY78Saq-MVmaNn_98mzdeRKFc8AJh9T52UHMSsmeqXtjsRRnkVuCrs6LZsM07HFbJk6WrSQEewCHxIodOEPh6AMZoTUKK_whMACP0NEUxCxFFUV-JWJPZoVriwfxXw05_95b4zrl7K_8-DhciDc2E1vDlWp_qe1fvU9f2l22gxLnOGs2fWhi1bz8ViA1dHfVN5Bw4FIA3thMY Nov 02 04:12:08 volumio volumio[3243]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 02 04:12:08 volumio volumio[3243]: info: New Spotify access token = BQCvgT3rYmHH_9WsQ7hAcst8_MAzxWc8p6UfQZTmn63ZsvYtFq8QVbADT0aND8XLaPcAVWJKVyJSVb8-Zm8sVn6-Jzqjh4yRh15YhFCY78Saq-MVmaNn_98mzdeRKFc8AJh9T52UHMSsmeqXtjsRRnkVuCrs6LZsM07HFbJk6WrSQEewCHxIodOEPh6AMZoTUKK_whMACP0NEUxCxFFUV-JWJPZoVriwfxXw05_95b4zrl7K_8-DhciDc2E1vDlWp_qe1fvU9f2l22gxLnOGs2fWhi1bz8ViA1dHfVN5Bw4FIA3thMY Nov 02 04:12:08 volumio volumio[3243]: info: Spotify credentials grant success - running version from March 24, 2019 Nov 02 04:12:08 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 02 04:12:08 volumio sudo[3442]: pam_unix(sudo:session): session closed for user root Nov 02 04:12:08 volumio sudo[3451]: pam_unix(sudo:session): session closed for user root Nov 02 04:12:08 volumio sudo[3440]: pam_unix(sudo:session): session closed for user root Nov 02 04:12:08 volumio go-librespot[3432]: time="2025-11-02T04:12:08Z" level=debug msg="obtained new client token: AACJJTGm9clmHud5AXVE05ZHTuvKNfzWCTEfzCeQ3hzvSD4gJquoj0N4+UG/fs5m5hWUK6DOb56rp62kKFKlx4K1U5BmDMFb3hjCRz+T0dSdfZ/78D3EhqTJMZO2XrO/EN4zpvsOU5RP7NmjcjtMHr9IZM+nha8e2dfLKJRqctAuCAFszrHaunsM94CgBvr0VbOaFG28PDZF8AWrQ8TTpJjEjI4v1MUkqZLHOYgl7EKJkyzgGVZC+HA=" Nov 02 04:12:08 volumio volumio[3243]: info: Shairport-Sync Started Nov 02 04:12:08 volumio volumio[3243]: Error adding Membership: Error: addMembership EINVAL Nov 02 04:12:08 volumio volumio[3243]: info: Shairport-Sync Started Nov 02 04:12:08 volumio volumio[3243]: info: Shairport-Sync Started Nov 02 04:12:08 volumio go-librespot[3432]: time="2025-11-02T04:12:08Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::volumioGetState Nov 02 04:12:08 volumio volumio[3243]: info: CorePlayQueue::getTrack 0 Nov 02 04:12:08 volumio mpd[3408]: 2025-11-02T04:12:08 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 02 04:12:08 volumio systemd[1]: Started mpd.service - Music Player Daemon. Nov 02 04:12:08 volumio sudo[3379]: pam_unix(sudo:session): session closed for user root Nov 02 04:12:08 volumio sudo[3370]: pam_unix(sudo:session): session closed for user root Nov 02 04:12:08 volumio go-librespot[3432]: time="2025-11-02T04:12:08Z" level=debug msg="completed keyexchange" Nov 02 04:12:08 volumio go-librespot[3432]: time="2025-11-02T04:12:08Z" level=debug msg="completed challenge" Nov 02 04:12:08 volumio volumio[3243]: error: MPD error: The expression evaluated to a falsy value: Nov 02 04:12:08 volumio volumio[3243]: assert.ok(self.idling) Nov 02 04:12:08 volumio volumio[3243]: error: The expression evaluated to a falsy value: Nov 02 04:12:08 volumio volumio[3243]: assert.ok(self.idling) Nov 02 04:12:08 volumio volumio[3243]: error: updateQueue error: null Nov 02 04:12:08 volumio volumio[3243]: info: MPD running with PID3408 Nov 02 04:12:08 volumio volumio[3243]: ,establishing connection Nov 02 04:12:08 volumio go-librespot[3432]: time="2025-11-02T04:12:08Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 04:12:08 volumio volumio[3243]: error: updateQueue error: null Nov 02 04:12:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:12:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:12:08 volumio volumio[3243]: 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 02 04:12:08 volumio volumio[3243]: info: Spotify Successfully logged in Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 02 04:12:08 volumio volumio[3243]: info: [1762056728807] CoreMusicLibrary::Adding element Spotify Nov 02 04:12:08 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 02 04:12:08 volumio volumio[3243]: Cannot find translation for source Spotify Nov 02 04:12:08 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 02 04:12:09 volumio volumio[3243]: info: [yt-cast-receiver] DIAL server listening on port 8098 Nov 02 04:12:09 volumio volumio[3243]: info: CoreCommandRouter::volumioRetrievevolume Nov 02 04:12:09 volumio volumio[3243]: info: VolumeController:: Volume=33 Mute =false Nov 02 04:12:09 volumio volumio[3243]: info: CoreCommandRouter::volumioGetState Nov 02 04:12:09 volumio volumio[3243]: info: CorePlayQueue::getTrack 0 Nov 02 04:12:09 volumio volumio[3243]: info: CoreStateMachine::pushState Nov 02 04:12:09 volumio volumio[3243]: info: CorePlayQueue::getTrack 0 Nov 02 04:12:09 volumio volumio[3243]: info: CoreCommandRouter::volumioPushState Nov 02 04:12:09 volumio volumio[3243]: info: Completed starting Core Plugins Nov 02 04:12:09 volumio volumio[3243]: info: ------------------------------------------- Nov 02 04:12:09 volumio volumio[3243]: info: ----- MyVolumio plugins startup ---- Nov 02 04:12:09 volumio volumio[3243]: info: ------------------------------------------- Nov 02 04:12:09 volumio volumio[3243]: info: [MyVolumio PluginManager] Fetching plans data.... Nov 02 04:12:10 volumio volumio-remote-updater[874]: [2025-11-02 04:12:10] [connect] Successful connection Nov 02 04:12:10 volumio volumio-remote-updater[874]: [2025-11-02 04:12:10] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1762056730 101 Nov 02 04:12:10 volumio volumio[3243]: 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: 2 Nov 02 04:12:11 volumio volumio[3243]: info: Cannot mount NAS NAS at system boot, trial number 2 ,retrying in 5 seconds Nov 02 04:12:11 volumio volumio[3243]: info: go-librespot daemon successfully initialized Nov 02 04:12:11 volumio sudo[3483]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 02 04:12:11 volumio sudo[3483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 04:12:11 volumio sudo[3485]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 02 04:12:11 volumio sudo[3485]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 04:12:11 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Nov 02 04:12:11 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Nov 02 04:12:11 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Nov 02 04:12:11 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Nov 02 04:12:11 volumio mpd_monitor.sh[3488]: MPD Monitor Service: Starting MPD Monitor Service Nov 02 04:12:11 volumio sudo[3483]: pam_unix(sudo:session): session closed for user root Nov 02 04:12:11 volumio sudo[3485]: pam_unix(sudo:session): session closed for user root Nov 02 04:12:11 volumio volumio[3243]: info: Successfully started MPD Monitor Nov 02 04:12:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 113. Nov 02 04:12:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:12:11 volumio volumio[3243]: info: Successfully started MPD Monitor Nov 02 04:12:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:12:11 volumio go-librespot[3492]: go-librespot daemon starting... Nov 02 04:12:11 volumio go-librespot[3493]: time="2025-11-02T04:12:11Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:12:11 volumio go-librespot[3493]: time="2025-11-02T04:12:11Z" level=debug msg="app state loaded" Nov 02 04:12:11 volumio go-librespot[3493]: time="2025-11-02T04:12:11Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:12:11 volumio go-librespot[3493]: time="2025-11-02T04:12:11Z" 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 02 04:12:11 volumio go-librespot[3493]: time="2025-11-02T04:12:11Z" 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 02 04:12:11 volumio go-librespot[3493]: time="2025-11-02T04:12:11Z" 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 02 04:12:11 volumio go-librespot[3493]: time="2025-11-02T04:12:11Z" level=info msg="zeroconf server listening on port 38961" Nov 02 04:12:11 volumio go-librespot[3493]: time="2025-11-02T04:12:11Z" level=debug msg="obtained new client token: AAB58lvLrT+38pQaSGmEmi5CKcGEsIkkkUn4d6uKBjIvThQYOhBT+LDXSY+I6jh9zTNVggJl9tyeaFokJ9vgNfbuKuO0pRT+3k5e7sFl2fUAf1SVm/4U/q/lJngI9VPmuR+tkcqX/P61y+bFSFtaC/JzImPvZJhk8VCFha0PB1nbXejb8oHuAN4jI/OGRvXVBIVG/d2NnspnIRttgaU0ZoEnI0T2DpMAt2Ci/qQROhZC8g4Li1cMBkQ=" Nov 02 04:12:11 volumio go-librespot[3493]: time="2025-11-02T04:12:11Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:12:12 volumio go-librespot[3493]: time="2025-11-02T04:12:12Z" level=debug msg="completed keyexchange" Nov 02 04:12:12 volumio go-librespot[3493]: time="2025-11-02T04:12:12Z" level=debug msg="completed challenge" Nov 02 04:12:12 volumio go-librespot[3493]: time="2025-11-02T04:12:12Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 04:12:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:12:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:12:13 volumio volumio[3243]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Nov 02 04:12:14 volumio volumio[3243]: info: Initializing connection to go-librespot Websocket Nov 02 04:12:14 volumio volumio[3243]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:12:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 114. Nov 02 04:12:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:12:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:12:15 volumio go-librespot[3502]: go-librespot daemon starting... Nov 02 04:12:15 volumio go-librespot[3503]: time="2025-11-02T04:12:15Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:12:15 volumio go-librespot[3503]: time="2025-11-02T04:12:15Z" level=debug msg="app state loaded" Nov 02 04:12:15 volumio go-librespot[3503]: time="2025-11-02T04:12:15Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:12:15 volumio go-librespot[3503]: time="2025-11-02T04:12:15Z" 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 02 04:12:15 volumio go-librespot[3503]: time="2025-11-02T04:12:15Z" 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 02 04:12:15 volumio go-librespot[3503]: time="2025-11-02T04:12:15Z" 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 02 04:12:15 volumio go-librespot[3503]: time="2025-11-02T04:12:15Z" level=info msg="zeroconf server listening on port 41045" Nov 02 04:12:15 volumio go-librespot[3503]: time="2025-11-02T04:12:15Z" level=debug msg="obtained new client token: AADSeonKvNC0jaekc1g4Ls5xLdhryu/20MK3J5Sij8aE5qU4jeIcmCY3rSO5labR38Y99TcMM624tRK59kI9EpWtx8Sz9f/7NlSXJbHFY8U0LnCbyTwhwz9FgKwWNLhROLiHILvj0812IN2yHT+A0v+zFx1oNyFjI3MxXv041vmqZSGiagQ91IddwEioAGZAYnnhVAoOKf6oHOGasQikGwD8ERGUUldUTocyxbgHNJcVTc+JbVSghAU=" Nov 02 04:12:15 volumio go-librespot[3503]: time="2025-11-02T04:12:15Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:12:15 volumio go-librespot[3503]: time="2025-11-02T04:12:15Z" level=debug msg="completed keyexchange" Nov 02 04:12:15 volumio go-librespot[3503]: time="2025-11-02T04:12:15Z" level=debug msg="completed challenge" Nov 02 04:12:15 volumio go-librespot[3503]: time="2025-11-02T04:12:15Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 04:12:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:12:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:12:16 volumio volumio[3243]: info: Cannot mount NAS NAS at system boot, trial number 3 ,retrying in 5 seconds Nov 02 04:12:16 volumio sudo[3525]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 02 04:12:16 volumio sudo[3525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 04:12:16 volumio sudo[3527]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 02 04:12:16 volumio sudo[3525]: pam_unix(sudo:session): session closed for user root Nov 02 04:12:16 volumio sudo[3527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 04:12:16 volumio sudo[3527]: pam_unix(sudo:session): session closed for user root Nov 02 04:12:16 volumio sudo[3531]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 02 04:12:16 volumio sudo[3531]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 04:12:16 volumio sudo[3531]: pam_unix(sudo:session): session closed for user root Nov 02 04:12:16 volumio volumio[3243]: info: Upmpdcli Daemon Started Nov 02 04:12:17 volumio volumio[3243]: info: Initializing connection to go-librespot Websocket Nov 02 04:12:17 volumio volumio[3243]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:12:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 115. Nov 02 04:12:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:12:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:12:18 volumio go-librespot[3533]: go-librespot daemon starting... Nov 02 04:12:18 volumio go-librespot[3534]: time="2025-11-02T04:12:18Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:12:18 volumio go-librespot[3534]: time="2025-11-02T04:12:18Z" level=debug msg="app state loaded" Nov 02 04:12:18 volumio go-librespot[3534]: time="2025-11-02T04:12:18Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:12:18 volumio go-librespot[3534]: time="2025-11-02T04:12:18Z" 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 02 04:12:18 volumio go-librespot[3534]: time="2025-11-02T04:12:18Z" 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 02 04:12:18 volumio go-librespot[3534]: time="2025-11-02T04:12:18Z" 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 02 04:12:18 volumio go-librespot[3534]: time="2025-11-02T04:12:18Z" level=info msg="zeroconf server listening on port 39789" Nov 02 04:12:18 volumio go-librespot[3534]: time="2025-11-02T04:12:18Z" level=debug msg="obtained new client token: AADKb2jUkbQ4IBM93/FhbjXMaDtXw81s4Uhzu5/i0T3T78ByE2nyvkEmcAA22f7e1H/iWMt+WKCwH6bf0NaAyWhXZyPk5qYU5r8XdaXutghwR3f2P2kCaAY991IC+WFIAYR9Q6OEAgv8tkAMcUNCZxAlZSbCKDQTPJ8ahjWTa7tbX+8uJXBzjAd0C+pqu/8VOHb2jC5zcox31NhijJd/JY4JW9cVv/r0G1x1HC1H7DGn51YDTHDQaq4=" Nov 02 04:12:18 volumio go-librespot[3534]: time="2025-11-02T04:12:18Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:12:18 volumio go-librespot[3534]: time="2025-11-02T04:12:18Z" level=debug msg="completed keyexchange" Nov 02 04:12:18 volumio go-librespot[3534]: time="2025-11-02T04:12:18Z" level=debug msg="completed challenge" Nov 02 04:12:19 volumio go-librespot[3534]: time="2025-11-02T04:12:19Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 04:12:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:12:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:12:20 volumio volumio[3243]: info: Initializing connection to go-librespot Websocket Nov 02 04:12:20 volumio volumio[3243]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 04:12:21 volumio volumio[3243]: info: Cannot mount NAS NAS at system boot, trial number 4 ,retrying in 5 seconds Nov 02 04:12:22 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 02 04:12:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 116. Nov 02 04:12:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:12:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 04:12:22 volumio go-librespot[3541]: go-librespot daemon starting... Nov 02 04:12:22 volumio go-librespot[3542]: time="2025-11-02T04:12:22Z" level=info msg="running go-librespot 0.4.0" Nov 02 04:12:22 volumio go-librespot[3542]: time="2025-11-02T04:12:22Z" level=debug msg="app state loaded" Nov 02 04:12:22 volumio go-librespot[3542]: time="2025-11-02T04:12:22Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 04:12:22 volumio go-librespot[3542]: time="2025-11-02T04:12:22Z" 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 02 04:12:22 volumio go-librespot[3542]: time="2025-11-02T04:12:22Z" 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 02 04:12:22 volumio go-librespot[3542]: time="2025-11-02T04:12:22Z" 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 02 04:12:22 volumio go-librespot[3542]: time="2025-11-02T04:12:22Z" level=info msg="zeroconf server listening on port 37579" Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Nov 02 04:12:22 volumio volumio[3243]: info: Adding plugin bluetooth to MyMusic Plugins Nov 02 04:12:22 volumio volumio[3243]: info: Adding plugin multiroom to MyMusic Plugins Nov 02 04:12:22 volumio volumio[3243]: info: Adding plugin metavolumio to MyMusic Plugins Nov 02 04:12:22 volumio volumio[3243]: info: Adding plugin cd_controller to MyMusic Plugins Nov 02 04:12:22 volumio volumio[3243]: info: Adding plugin qobuzconnect to MyMusic Plugins Nov 02 04:12:22 volumio volumio[3243]: info: Adding plugin smart_inputs to MyMusic Plugins Nov 02 04:12:22 volumio volumio[3243]: info: Adding plugin tidalconnect to MyMusic Plugins Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Nov 02 04:12:22 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 04:12:22 volumio volumio[3243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 04:12:22 volumio volumio[3243]: info: Starting MyVolumio Remote Streaming Endpoints Nov 02 04:12:22 volumio volumio[3243]: info: MyVolumio login type: Token Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Nov 02 04:12:22 volumio volumio[3243]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Nov 02 04:12:23 volumio volumio[3243]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 02 04:12:23 volumio volumio[3243]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 02 04:12:23 volumio volumio[3243]: info: Streaming services startup Nov 02 04:12:23 volumio volumio[3243]: info: Starting Streaming Daemon Nov 02 04:12:23 volumio sudo[3550]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 02 04:12:23 volumio sudo[3550]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 04:12:23 volumio volumio[3243]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Nov 02 04:12:23 volumio sudo[3550]: pam_unix(sudo:session): session closed for user root Nov 02 04:12:23 volumio volumio[3243]: error: Cannot start Volumio Streaming Daemon Nov 02 04:12:23 volumio volumio[3243]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 02 04:12:23 volumio volumio[3243]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 02 04:12:23 volumio volumio[3243]: info: Initializing connection to go-librespot Websocket Nov 02 04:12:23 volumio go-librespot[3542]: time="2025-11-02T04:12:23Z" level=debug msg="new websocket client" Nov 02 04:12:23 volumio volumio[3243]: info: Connection to go-librespot Websocket established Nov 02 04:12:26 volumio volumio[3243]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Nov 02 04:12:26 volumio volumio[3243]: info: Getting Spotify volume Nov 02 04:12:26 volumio volumio[3243]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Nov 02 04:12:26 volumio volumio[3243]: info: CoreCommandRouter::volumioGetState Nov 02 04:12:26 volumio volumio[3243]: info: CorePlayQueue::getTrack 0 Nov 02 04:12:26 volumio volumio[3243]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 Nov 02 04:12:26 volumio volumio[3243]: SPOTIFY: SPOTIFY VOLUME undefined Nov 02 04:12:26 volumio volumio[3243]: SPOTIFY: VOLUMIO VOLUME 33 Nov 02 04:12:26 volumio volumio[3243]: info: Aligning Spotify Volume to Volumio Volume Nov 02 04:12:26 volumio volumio[3243]: info: CoreCommandRouter::volumioGetState Nov 02 04:12:26 volumio volumio[3243]: info: CorePlayQueue::getTrack 0 Nov 02 04:12:26 volumio volumio[3243]: info: Setting Spotify Volume from Volumio: 33 Nov 02 04:12:28 volumio volumio[3243]: SPOTIFY: SETTING SPOTIFY VOLUME 33 Nov 02 04:12:28 volumio volumio[3243]: info: Sending Spotify command with payload to local API: /player/volume Nov 02 04:12:32 volumio go-librespot[3542]: time="2025-11-02T04:12:32Z" level=debug msg="obtained new client token: AABIeW2klxf7g9XhMDgvn5WJd6chviqZzfC6Etw2ELd0+Fv0Y/qDEXPBSMgPQZn+zvQMmJwWS89zfc+LBrcu8EEswVTQs4DVuaatbSxLiLU7Hvx3qiHjc6VaC+t7st23QtIc+hKHEDp6FpL/YV3Sobxiz2tZg8czUkpJi7zJ46fJG3VZ8dSC7apP2Bz2D3twdIvdQSffZo4kJURhLkC8wA4iDz/WoStNia+BO62lsXVK61ak4vXb6cc=" Nov 02 04:12:32 volumio go-librespot[3542]: time="2025-11-02T04:12:32Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 04:12:32 volumio go-librespot[3542]: time="2025-11-02T04:12:32Z" level=debug msg="completed keyexchange" Nov 02 04:12:32 volumio go-librespot[3542]: time="2025-11-02T04:12:32Z" level=debug msg="completed challenge" Nov 02 04:12:32 volumio go-librespot[3542]: time="2025-11-02T04:12:32Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 04:12:32 volumio volumio[3243]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Nov 02 04:12:32 volumio volumio[3243]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 02 04:12:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 04:12:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 04:12:32 volumio volumio[3243]: Error: socket hang up Nov 02 04:12:32 volumio volumio[3243]: at connResetException (node:internal/errors:720:14) Nov 02 04:12:32 volumio volumio[3243]: at Socket.socketOnEnd (node:_http_client:519:23) Nov 02 04:12:32 volumio volumio[3243]: at Socket.emit (node:events:526:35) Nov 02 04:12:32 volumio volumio[3243]: at endReadableNT (node:internal/streams/readable:1376:12) Nov 02 04:12:32 volumio volumio[3243]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Nov 02 04:12:32 volumio volumio[3243]: code: 'ECONNRESET', Nov 02 04:12:32 volumio volumio[3243]: response: undefined Nov 02 04:12:32 volumio volumio[3243]: } Nov 02 04:12:32 volumio volumio[3243]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 02 04:12:32 volumio sudo[3588]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-11-02 04:11' Nov 02 04:12:32 volumio sudo[3588]: 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"