-- Logs begin at Sat 2025-12-06 06:37:56 CET, end at Sat 2025-12-06 09:14:09 CET. -- Dec 06 09:13:00 volumio volumio[740]: info: Initializing connection to go-librespot Websocket Dec 06 09:13:00 volumio volumio[740]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 09:13:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 06 09:13:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 117857. Dec 06 09:13:01 volumio systemd[1]: Stopped go-librespot Daemon. Dec 06 09:13:01 volumio systemd[1]: Started go-librespot Daemon. Dec 06 09:13:01 volumio go-librespot[22159]: go-librespot daemon starting... Dec 06 09:13:01 volumio go-librespot[22159]: time="2025-12-06T09:13:01+01:00" level=info msg="running go-librespot 0.4.0" Dec 06 09:13:01 volumio go-librespot[22159]: time="2025-12-06T09:13:01+01:00" level=debug msg="app state loaded" Dec 06 09:13:01 volumio go-librespot[22159]: time="2025-12-06T09:13:01+01:00" level=debug msg="stored credentials not found" Dec 06 09:13:01 volumio go-librespot[22159]: time="2025-12-06T09:13:01+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 09:13:02 volumio go-librespot[22159]: time="2025-12-06T09:13:02+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 06 09:13:02 volumio go-librespot[22159]: time="2025-12-06T09:13:02+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 06 09:13:02 volumio go-librespot[22159]: time="2025-12-06T09:13:02+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 06 09:13:02 volumio go-librespot[22159]: time="2025-12-06T09:13:02+01:00" level=info msg="zeroconf server listening on port 44045" Dec 06 09:13:02 volumio go-librespot[22159]: time="2025-12-06T09:13:02+01:00" level=debug msg="obtained new client token: AACIGC6PvOZxvmNl5LZyIhgRYUcxuUzV97Oa3XJx9OOC9fn+VHcCKq16RsuvWNKdT/jQ+TAxAdLnpJ2i4xGcot/DzhqKg7Z//ceVuiH+c70eziwsNH20Lnx2cnm2ovXiFrUNh0k240wBEN61geVEtEs7GoRoJ1Hfy9DNyKhG6rENKDO5/Yg6eG0y/ZCF48gCalqIDWyWQ42tbXHJQZLBam06CHxq9gKnPogss3eiq8fHo0sn9frbtvsVPx4=" Dec 06 09:13:02 volumio go-librespot[22159]: time="2025-12-06T09:13:02+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 06 09:13:02 volumio go-librespot[22159]: time="2025-12-06T09:13:02+01:00" level=debug msg="completed keyexchange" Dec 06 09:13:02 volumio go-librespot[22159]: time="2025-12-06T09:13:02+01:00" level=debug msg="completed challenge" Dec 06 09:13:02 volumio go-librespot[22159]: time="2025-12-06T09:13:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 09:13:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 09:13:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 09:13:03 volumio volumio[740]: info: Initializing connection to go-librespot Websocket Dec 06 09:13:03 volumio volumio[740]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 09:13:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 06 09:13:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 117858. Dec 06 09:13:05 volumio systemd[1]: Stopped go-librespot Daemon. Dec 06 09:13:05 volumio systemd[1]: Started go-librespot Daemon. Dec 06 09:13:05 volumio go-librespot[22168]: go-librespot daemon starting... Dec 06 09:13:05 volumio go-librespot[22168]: time="2025-12-06T09:13:05+01:00" level=info msg="running go-librespot 0.4.0" Dec 06 09:13:05 volumio go-librespot[22168]: time="2025-12-06T09:13:05+01:00" level=debug msg="app state loaded" Dec 06 09:13:05 volumio go-librespot[22168]: time="2025-12-06T09:13:05+01:00" level=debug msg="stored credentials not found" Dec 06 09:13:05 volumio go-librespot[22168]: time="2025-12-06T09:13:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 09:13:06 volumio go-librespot[22168]: time="2025-12-06T09:13:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 06 09:13:06 volumio go-librespot[22168]: time="2025-12-06T09:13:06+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 06 09:13:06 volumio go-librespot[22168]: time="2025-12-06T09:13:06+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 06 09:13:06 volumio go-librespot[22168]: time="2025-12-06T09:13:06+01:00" level=info msg="zeroconf server listening on port 46785" Dec 06 09:13:06 volumio go-librespot[22168]: time="2025-12-06T09:13:06+01:00" level=debug msg="obtained new client token: AADY+gHOzwb1mlP3fzIgyRt08Rlc9ktPrFlVru+kPntROLSMvrg6x5YtwPMlMXsKOX9R0jGqq5fvD+Yf3WYg7QwScP9atNDo1kOWFSppel6YDEMS1zabDQY+yNFQer3uiXW95NpOvacistJyEOjOusg8TcWYRncZiRNEQYqbTxFEY5BNf0h9lLDDrW2qCYWOZSl58EnbS9uRyAYUAqbFH+SzSZESn0gCPaG3WmsySS8ka0GKQb3VVT2N0us=" Dec 06 09:13:06 volumio go-librespot[22168]: time="2025-12-06T09:13:06+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Dec 06 09:13:06 volumio go-librespot[22168]: time="2025-12-06T09:13:06+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Dec 06 09:13:06 volumio go-librespot[22168]: time="2025-12-06T09:13:06+01:00" level=debug msg="completed keyexchange" Dec 06 09:13:06 volumio go-librespot[22168]: time="2025-12-06T09:13:06+01:00" level=debug msg="completed challenge" Dec 06 09:13:06 volumio go-librespot[22168]: time="2025-12-06T09:13:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 09:13:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 09:13:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 09:13:06 volumio volumio[740]: info: Initializing connection to go-librespot Websocket Dec 06 09:13:06 volumio volumio[740]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 09:13:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 06 09:13:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 117859. Dec 06 09:13:09 volumio systemd[1]: Stopped go-librespot Daemon. Dec 06 09:13:09 volumio systemd[1]: Started go-librespot Daemon. Dec 06 09:13:09 volumio go-librespot[22193]: go-librespot daemon starting... Dec 06 09:13:09 volumio volumio[740]: info: Initializing connection to go-librespot Websocket Dec 06 09:13:09 volumio volumio[740]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 09:13:09 volumio go-librespot[22193]: time="2025-12-06T09:13:09+01:00" level=info msg="running go-librespot 0.4.0" Dec 06 09:13:09 volumio go-librespot[22193]: time="2025-12-06T09:13:09+01:00" level=debug msg="app state loaded" Dec 06 09:13:09 volumio go-librespot[22193]: time="2025-12-06T09:13:09+01:00" level=debug msg="stored credentials not found" Dec 06 09:13:09 volumio go-librespot[22193]: time="2025-12-06T09:13:09+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 09:13:10 volumio go-librespot[22193]: time="2025-12-06T09:13:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 06 09:13:10 volumio go-librespot[22193]: time="2025-12-06T09:13:10+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 06 09:13:10 volumio go-librespot[22193]: time="2025-12-06T09:13:10+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 06 09:13:10 volumio go-librespot[22193]: time="2025-12-06T09:13:10+01:00" level=info msg="zeroconf server listening on port 33167" Dec 06 09:13:10 volumio go-librespot[22193]: time="2025-12-06T09:13:10+01:00" level=debug msg="obtained new client token: AABkmu3U4/OGJTDQBp/PErCtAY1VXEaVan4QmC9n7XPgBHwEYY16uTPFeBkOqJ5i9Bk+eFXzqWv/oI8AGbz0JUYgLUdUCeCLBS269i8j1acRl2pfjwE3jJbVxp7EZ2pWHr7lI1Tk0DMafvphQALG1cEhb2lf8Ftnfbe9IZ7jNqEtxJOdPL0SobFHGrg+OLKE+vZkymOKJONJ3LtR637ky+g/N7MxLOIX/E5qJol65A+85AH03FcGW6Bcamg=" Dec 06 09:13:10 volumio go-librespot[22193]: time="2025-12-06T09:13:10+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 06 09:13:10 volumio go-librespot[22193]: time="2025-12-06T09:13:10+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Dec 06 09:13:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 09:13:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 09:13:12 volumio volumio[740]: info: Initializing connection to go-librespot Websocket Dec 06 09:13:12 volumio volumio[740]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 09:13:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 06 09:13:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 117860. Dec 06 09:13:13 volumio systemd[1]: Stopped go-librespot Daemon. Dec 06 09:13:13 volumio systemd[1]: Started go-librespot Daemon. Dec 06 09:13:13 volumio go-librespot[22201]: go-librespot daemon starting... Dec 06 09:13:13 volumio go-librespot[22201]: time="2025-12-06T09:13:13+01:00" level=info msg="running go-librespot 0.4.0" Dec 06 09:13:13 volumio go-librespot[22201]: time="2025-12-06T09:13:13+01:00" level=debug msg="app state loaded" Dec 06 09:13:13 volumio go-librespot[22201]: time="2025-12-06T09:13:13+01:00" level=debug msg="stored credentials not found" Dec 06 09:13:13 volumio go-librespot[22201]: time="2025-12-06T09:13:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 09:13:14 volumio go-librespot[22201]: time="2025-12-06T09:13:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 06 09:13:14 volumio go-librespot[22201]: time="2025-12-06T09:13:14+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 06 09:13:14 volumio go-librespot[22201]: time="2025-12-06T09:13:14+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 06 09:13:14 volumio go-librespot[22201]: time="2025-12-06T09:13:14+01:00" level=info msg="zeroconf server listening on port 43985" Dec 06 09:13:14 volumio go-librespot[22201]: time="2025-12-06T09:13:14+01:00" level=debug msg="obtained new client token: AADH3EuMvgk5u9801PDEBlR72VXnYzXCXLhXmMPw7USRVcIEMG+hZlSzUv8zMg3RbYmO8CbDTiTziPOMINv1NLEgrWQ4Z/E1E1qjEqcQvT5cokmAf7yA80EuTijUctF+nHYySJnlY7a2zkdSVvYmfvvrwJwJlY09CtHPU+3M4C9sY0PYSA/QcK95b19jC+wYW9ThWciKvhppPjhXovSpmMcOmU51E9CQ4oKilizf7vqzIP/nq+J+2ZsUqCY=" Dec 06 09:13:14 volumio go-librespot[22201]: time="2025-12-06T09:13:14+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 06 09:13:14 volumio go-librespot[22201]: time="2025-12-06T09:13:14+01:00" level=debug msg="completed keyexchange" Dec 06 09:13:14 volumio go-librespot[22201]: time="2025-12-06T09:13:14+01:00" level=debug msg="completed challenge" Dec 06 09:13:14 volumio go-librespot[22201]: time="2025-12-06T09:13:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 09:13:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 09:13:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 09:13:15 volumio volumio[740]: info: Initializing connection to go-librespot Websocket Dec 06 09:13:15 volumio volumio[740]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 09:13:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 06 09:13:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 117861. Dec 06 09:13:17 volumio systemd[1]: Stopped go-librespot Daemon. Dec 06 09:13:17 volumio systemd[1]: Started go-librespot Daemon. Dec 06 09:13:17 volumio go-librespot[22223]: go-librespot daemon starting... Dec 06 09:13:17 volumio go-librespot[22223]: time="2025-12-06T09:13:17+01:00" level=info msg="running go-librespot 0.4.0" Dec 06 09:13:17 volumio go-librespot[22223]: time="2025-12-06T09:13:17+01:00" level=debug msg="app state loaded" Dec 06 09:13:17 volumio go-librespot[22223]: time="2025-12-06T09:13:17+01:00" level=debug msg="stored credentials not found" Dec 06 09:13:17 volumio go-librespot[22223]: time="2025-12-06T09:13:17+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 09:13:18 volumio go-librespot[22223]: time="2025-12-06T09:13:18+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 06 09:13:18 volumio go-librespot[22223]: time="2025-12-06T09:13:18+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 06 09:13:18 volumio go-librespot[22223]: time="2025-12-06T09:13:18+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 06 09:13:18 volumio go-librespot[22223]: time="2025-12-06T09:13:18+01:00" level=info msg="zeroconf server listening on port 40019" Dec 06 09:13:18 volumio go-librespot[22223]: time="2025-12-06T09:13:18+01:00" level=debug msg="obtained new client token: AABlOXgtssYPMYcdzzzibz8mosp/QlYCGudYOx8hXefezH1CBLcjLEJ2UqI5MR8Zrg/OatXuwJPlb8qASaDQsT7FOft9ZYdMJt/vGB9eCqSYND/aoEYcXCP07+LgweWJ2E0YfDRiRXaKEQGjK5Vn7R5Wj5/VuGYF7/zTK/XBAarvvK44RZP2Gcs7gtzVS+g/tIjui7z61BvyjO76XUtYpK97UmJJp+qtQFaOmT1VZcUzV0qPIDURpSguvyk=" Dec 06 09:13:18 volumio go-librespot[22223]: time="2025-12-06T09:13:18+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 06 09:13:18 volumio go-librespot[22223]: time="2025-12-06T09:13:18+01:00" level=debug msg="completed keyexchange" Dec 06 09:13:18 volumio go-librespot[22223]: time="2025-12-06T09:13:18+01:00" level=debug msg="completed challenge" Dec 06 09:13:18 volumio go-librespot[22223]: time="2025-12-06T09:13:18+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 09:13:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 09:13:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 09:13:18 volumio volumio[740]: info: Initializing connection to go-librespot Websocket Dec 06 09:13:18 volumio volumio[740]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 09:13:20 volumio volumio[740]: verbose: New Socket.io Connection to 192.168.0.202:3000 from 192.168.0.157 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Dec 06 09:13:20 volumio volumio[740]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 06 09:13:20 volumio volumio[740]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 06 09:13:20 volumio volumio[740]: info: Discovery: Getting this device information Dec 06 09:13:20 volumio volumio[740]: info: CoreCommandRouter::volumioGetState Dec 06 09:13:20 volumio volumio[740]: info: CorePlayQueue::getTrack 0 Dec 06 09:13:20 volumio volumio[740]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 06 09:13:20 volumio volumio[740]: verbose: New Socket.io Connection to 192.168.0.202 from 192.168.0.157 UA: Mozilla/5.0 (Linux; Android 14; 23021RAA2Y Build/UKQ1.230917.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.102 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Dec 06 09:13:20 volumio volumio[740]: info: CoreCommandRouter::volumioGetState Dec 06 09:13:20 volumio volumio[740]: info: CorePlayQueue::getTrack 0 Dec 06 09:13:20 volumio volumio[740]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 06 09:13:20 volumio volumio[740]: info: Listing playlists Dec 06 09:13:20 volumio volumio[740]: info: CoreCommandRouter::volumioGetQueue Dec 06 09:13:20 volumio volumio[740]: info: CoreStateMachine::getQueue Dec 06 09:13:20 volumio volumio[740]: info: CorePlayQueue::getQueue Dec 06 09:13:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 06 09:13:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 117862. Dec 06 09:13:21 volumio systemd[1]: Stopped go-librespot Daemon. Dec 06 09:13:21 volumio systemd[1]: Started go-librespot Daemon. Dec 06 09:13:21 volumio go-librespot[22269]: go-librespot daemon starting... Dec 06 09:13:21 volumio go-librespot[22269]: time="2025-12-06T09:13:21+01:00" level=info msg="running go-librespot 0.4.0" Dec 06 09:13:21 volumio go-librespot[22269]: time="2025-12-06T09:13:21+01:00" level=debug msg="app state loaded" Dec 06 09:13:21 volumio go-librespot[22269]: time="2025-12-06T09:13:21+01:00" level=debug msg="stored credentials not found" Dec 06 09:13:21 volumio go-librespot[22269]: time="2025-12-06T09:13:21+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 09:13:21 volumio volumio[740]: info: Initializing connection to go-librespot Websocket Dec 06 09:13:21 volumio go-librespot[22269]: time="2025-12-06T09:13:21+01:00" level=debug msg="new websocket client" Dec 06 09:13:21 volumio volumio[740]: info: Connection to go-librespot Websocket established Dec 06 09:13:22 volumio go-librespot[22269]: time="2025-12-06T09:13:22+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 06 09:13:22 volumio go-librespot[22269]: time="2025-12-06T09:13:22+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 06 09:13:22 volumio go-librespot[22269]: time="2025-12-06T09:13:22+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 06 09:13:22 volumio go-librespot[22269]: time="2025-12-06T09:13:22+01:00" level=info msg="zeroconf server listening on port 42909" Dec 06 09:13:22 volumio go-librespot[22269]: time="2025-12-06T09:13:22+01:00" level=debug msg="obtained new client token: AAAncVZ9xxoAU31/5n+54RYFnLzn89xSs0akrVvonxdxV/lb172YyxK2XSC8QqAr07qSXXG7gMbSeEyimiq0AviIZBWZqkOj1q5aR6b0DNpU5KyZy4XA0584kHBxOtvd+674y1ydp3Vcjhb9hs/HZmwiRLmxOsJJhqO2hIYa8WiPihbCAQF8HaItnO+KnAZCp60nYRUsjFO/0fGO35gHS+geZs7e8KdRO3QO3ZU1zt2cwyZKsabVq0Xc8W0=" Dec 06 09:13:22 volumio go-librespot[22269]: time="2025-12-06T09:13:22+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 06 09:13:22 volumio go-librespot[22269]: time="2025-12-06T09:13:22+01:00" level=debug msg="completed keyexchange" Dec 06 09:13:22 volumio go-librespot[22269]: time="2025-12-06T09:13:22+01:00" level=debug msg="completed challenge" Dec 06 09:13:22 volumio go-librespot[22269]: time="2025-12-06T09:13:22+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 09:13:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 09:13:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 09:13:22 volumio volumio[740]: info: Connection to go-librespot Websocket closed Dec 06 09:13:24 volumio volumio[740]: info: Getting Spotify volume Dec 06 09:13:24 volumio volumio[740]: (node:740) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 09:13:24 volumio volumio[740]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 06 09:13:24 volumio volumio[740]: (node:740) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 7905) Dec 06 09:13:24 volumio volumio[740]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 06 09:13:24 volumio volumio[740]: info: CoreCommandRouter::volumioGetState Dec 06 09:13:24 volumio volumio[740]: info: CorePlayQueue::getTrack 0 Dec 06 09:13:25 volumio volumio[740]: info: Initializing connection to go-librespot Websocket Dec 06 09:13:25 volumio volumio[740]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 09:13:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 06 09:13:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 117863. Dec 06 09:13:25 volumio systemd[1]: Stopped go-librespot Daemon. Dec 06 09:13:25 volumio systemd[1]: Started go-librespot Daemon. Dec 06 09:13:25 volumio go-librespot[22278]: go-librespot daemon starting... Dec 06 09:13:25 volumio go-librespot[22278]: time="2025-12-06T09:13:25+01:00" level=info msg="running go-librespot 0.4.0" Dec 06 09:13:25 volumio go-librespot[22278]: time="2025-12-06T09:13:25+01:00" level=debug msg="app state loaded" Dec 06 09:13:25 volumio go-librespot[22278]: time="2025-12-06T09:13:25+01:00" level=debug msg="stored credentials not found" Dec 06 09:13:25 volumio go-librespot[22278]: time="2025-12-06T09:13:25+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 09:13:26 volumio go-librespot[22278]: time="2025-12-06T09:13:26+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 06 09:13:26 volumio go-librespot[22278]: time="2025-12-06T09:13:26+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 06 09:13:26 volumio go-librespot[22278]: time="2025-12-06T09:13:26+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 06 09:13:26 volumio go-librespot[22278]: time="2025-12-06T09:13:26+01:00" level=info msg="zeroconf server listening on port 43563" Dec 06 09:13:26 volumio go-librespot[22278]: time="2025-12-06T09:13:26+01:00" level=debug msg="obtained new client token: AAAwl1gy04L/pi6LIt/9uZc98+nRoifDc97GoWwy4Tjna5mypyGuc0KlzYMPGdLZBqkmeHGa+gutQYL30bJeudx27b+g2Txs5DBFz9d4mPjsgEnBSVGh7VUZVnRcH4SwZxhRgia8b/uFt2cf50qOZebQDUYXZ2o/BTpK+nOlzLGWfsHcpfAPjR3D5IjgK72eh/zekQ1mma+F2XNZJVkezL4KEtMuzJXtwJabz3isaU7S2KB40O2c8tuM1LE=" Dec 06 09:13:26 volumio go-librespot[22278]: time="2025-12-06T09:13:26+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 06 09:13:26 volumio go-librespot[22278]: time="2025-12-06T09:13:26+01:00" level=debug msg="completed keyexchange" Dec 06 09:13:26 volumio go-librespot[22278]: time="2025-12-06T09:13:26+01:00" level=debug msg="completed challenge" Dec 06 09:13:26 volumio go-librespot[22278]: time="2025-12-06T09:13:26+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 09:13:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 09:13:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 09:13:28 volumio volumio[740]: info: Initializing connection to go-librespot Websocket Dec 06 09:13:28 volumio volumio[740]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 09:13:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 06 09:13:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 117864. Dec 06 09:13:29 volumio systemd[1]: Stopped go-librespot Daemon. Dec 06 09:13:29 volumio systemd[1]: Started go-librespot Daemon. Dec 06 09:13:29 volumio go-librespot[22303]: go-librespot daemon starting... Dec 06 09:13:29 volumio go-librespot[22303]: time="2025-12-06T09:13:29+01:00" level=info msg="running go-librespot 0.4.0" Dec 06 09:13:29 volumio go-librespot[22303]: time="2025-12-06T09:13:29+01:00" level=debug msg="app state loaded" Dec 06 09:13:29 volumio go-librespot[22303]: time="2025-12-06T09:13:29+01:00" level=debug msg="stored credentials not found" Dec 06 09:13:29 volumio go-librespot[22303]: time="2025-12-06T09:13:29+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 09:13:30 volumio go-librespot[22303]: time="2025-12-06T09:13:30+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 06 09:13:30 volumio go-librespot[22303]: time="2025-12-06T09:13:30+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 06 09:13:30 volumio go-librespot[22303]: time="2025-12-06T09:13:30+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 06 09:13:30 volumio go-librespot[22303]: time="2025-12-06T09:13:30+01:00" level=info msg="zeroconf server listening on port 40501" Dec 06 09:13:30 volumio go-librespot[22303]: time="2025-12-06T09:13:30+01:00" level=debug msg="obtained new client token: AAA6vpVeAd5azkygM6hEMj1Pu9539PDDXHITj7IIxQuWz0alDPQe6gpj8i8aiuOxkHUTFc1fC1JZevd10Sm1F/o7+RpkguT4+I4lFkmZzTrtY35BtBUgZrSrcNeyxsUow/BLBWJzozEnpkRqRZHya35debvBTr6NFM2qdhO+/fEr2sXb4prJLw3OHir6qqaDgdXLSO0J8unONaJLTQkjJ5pBqe7CVvVUuy6G+jh1U8kehuKMyEa+MmnBnNA=" Dec 06 09:13:30 volumio go-librespot[22303]: time="2025-12-06T09:13:30+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 06 09:13:30 volumio go-librespot[22303]: time="2025-12-06T09:13:30+01:00" level=debug msg="completed keyexchange" Dec 06 09:13:30 volumio go-librespot[22303]: time="2025-12-06T09:13:30+01:00" level=debug msg="completed challenge" Dec 06 09:13:30 volumio go-librespot[22303]: time="2025-12-06T09:13:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 09:13:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 09:13:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 09:13:31 volumio volumio[740]: info: Initializing connection to go-librespot Websocket Dec 06 09:13:31 volumio volumio[740]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 09:13:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 06 09:13:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 117865. Dec 06 09:13:33 volumio systemd[1]: Stopped go-librespot Daemon. Dec 06 09:13:33 volumio systemd[1]: Started go-librespot Daemon. Dec 06 09:13:33 volumio go-librespot[22311]: go-librespot daemon starting... Dec 06 09:13:33 volumio go-librespot[22311]: time="2025-12-06T09:13:33+01:00" level=info msg="running go-librespot 0.4.0" Dec 06 09:13:33 volumio go-librespot[22311]: time="2025-12-06T09:13:33+01:00" level=debug msg="app state loaded" Dec 06 09:13:33 volumio go-librespot[22311]: time="2025-12-06T09:13:33+01:00" level=debug msg="stored credentials not found" Dec 06 09:13:33 volumio go-librespot[22311]: time="2025-12-06T09:13:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 09:13:34 volumio go-librespot[22311]: time="2025-12-06T09:13:34+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 06 09:13:34 volumio go-librespot[22311]: time="2025-12-06T09:13:34+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 06 09:13:34 volumio go-librespot[22311]: time="2025-12-06T09:13:34+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 06 09:13:34 volumio go-librespot[22311]: time="2025-12-06T09:13:34+01:00" level=info msg="zeroconf server listening on port 45719" Dec 06 09:13:34 volumio go-librespot[22311]: time="2025-12-06T09:13:34+01:00" level=debug msg="obtained new client token: AAD4c4EJiAeU09ImqxFYAoyD+ScOcgDNpOjs7MxTgXFVj7ynFjttZ9KRCLLmMwTA4sFs+63WVcJQVjML85uPb6UkK4JSo/2siZjKmk82vmuqatPmgkE4n+sWDFJIOXNdpnEa+m0n33fJdgQ9HDQxwpQ6Gczc5276ATZVGgGuzbD+kStyCymYXbUuUPCVLM7w4f4N/Ny1tvq0iyyrhgHc606QHS6SATYF5aoEE4wPQZJH+gGqjtoRJWh7LSw=" Dec 06 09:13:34 volumio go-librespot[22311]: time="2025-12-06T09:13:34+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Dec 06 09:13:34 volumio go-librespot[22311]: time="2025-12-06T09:13:34+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Dec 06 09:13:34 volumio volumio[740]: info: Initializing connection to go-librespot Websocket Dec 06 09:13:34 volumio go-librespot[22311]: time="2025-12-06T09:13:34+01:00" level=debug msg="new websocket client" Dec 06 09:13:34 volumio volumio[740]: info: Connection to go-librespot Websocket established Dec 06 09:13:37 volumio volumio[740]: info: Getting Spotify volume Dec 06 09:13:37 volumio volumio[740]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 06 09:13:37 volumio volumio[740]: info: CoreCommandRouter::volumioGetState Dec 06 09:13:37 volumio volumio[740]: info: CorePlayQueue::getTrack 0 Dec 06 09:13:41 volumio volumio[740]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 06 09:13:41 volumio volumio[740]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 06 09:13:41 volumio volumio[740]: info: Discovery: Getting this device information Dec 06 09:13:41 volumio volumio[740]: info: CoreCommandRouter::volumioGetState Dec 06 09:13:41 volumio volumio[740]: info: CorePlayQueue::getTrack 0 Dec 06 09:13:41 volumio volumio[740]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 06 09:13:42 volumio volumio[740]: verbose: New Socket.io Connection to 192.168.0.202:3000 from 192.168.0.157 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Dec 06 09:13:42 volumio volumio[740]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 06 09:13:42 volumio volumio[740]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 06 09:14:05 volumio volumio[740]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/fusiondsp/volumio/buster/armhf Dec 06 09:14:08 volumio volumio[740]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/fusiondsp/volumio/buster/armhf Dec 06 09:14:08 volumio volumio[740]: info: FusionDsp - Stopping FusionDsp service Dec 06 09:14:08 volumio volumio[740]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 06 09:14:08 volumio volumio[740]: TypeError: Cannot read property 'stop' of null Dec 06 09:14:08 volumio volumio[740]: at FusionDsp.onStop (/data/plugins/audio_interface/fusiondsp/index.js:109:23) Dec 06 09:14:08 volumio volumio[740]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Dec 06 09:14:08 volumio volumio[740]: at /volumio/app/pluginmanager.js:956:12 Dec 06 09:14:08 volumio volumio[740]: at ChildProcess.exithandler (child_process.js:299:7) Dec 06 09:14:08 volumio volumio[740]: at ChildProcess.emit (events.js:315:20) Dec 06 09:14:08 volumio volumio[740]: at maybeClose (internal/child_process.js:1048:16) Dec 06 09:14:08 volumio volumio[740]: at Process.ChildProcess._handle.onexit (internal/child_process.js:288:5) Dec 06 09:14:08 volumio volumio[740]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 06 09:14:09 volumio sudo[22394]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-06 09:13 Dec 06 09:14:09 volumio sudo[22394]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="cc50ad4a2058d01de272214eb33827883bd2b7d8" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="502750e5d54ecf269d25125b622bfabc030fb553" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 12 Nov 2025 06:58:02 PM CET" VOLUMIO_VERSION="3.874" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4ae6504ed6f22e44c01a6e93b16badbd"