-- Logs begin at Thu 2019-02-14 19:12:00 KST, end at Thu 2024-11-21 14:28:53 KST. -- Nov 21 14:27:00 volumio volumio[817]: info: Getting Spotify volume Nov 21 14:27:00 volumio volumio[817]: (node:817) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:00 volumio volumio[817]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 21 14:27:00 volumio volumio[817]: (node:817) 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: 14) Nov 21 14:27:00 volumio volumio[817]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Nov 21 14:27:00 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Nov 21 14:27:00 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Nov 21 14:27:01 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:01 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:27:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42. Nov 21 14:27:01 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:27:01 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:27:01 volumio go-librespot[2097]: Librespot-go daemon starting... Nov 21 14:27:01 volumio go-librespot[2097]: time="2024-11-21T14:27:01+09:00" level=info msg="generated new device id: 9a501c5b810d815c5d28f3e37ca86cab33ce69ef" Nov 21 14:27:01 volumio go-librespot[2097]: time="2024-11-21T14:27:01+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:27:01 volumio go-librespot[2097]: time="2024-11-21T14:27:01+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:27:01 volumio go-librespot[2097]: time="2024-11-21T14:27:01+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:27:01 volumio go-librespot[2097]: time="2024-11-21T14:27:01+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:27:01 volumio go-librespot[2097]: time="2024-11-21T14:27:01+09:00" level=debug msg="zeroconf server listening on port 40495" Nov 21 14:27:01 volumio go-librespot[2097]: time="2024-11-21T14:27:01+09:00" level=debug msg="obtained new client token: AABBAHJdsqBF8S+tJeiJpw7c7HSEN1R4fXlwcfpRRk5rEG+R3SB3naBNX5pgVAOn+zIw+9/PiTJqRpeetNX9uu/HGE26K5UpdGeD2//6kpoRa4Hp6H0Idsut0D+d9JH+Ro3v43B73QP0H+PQt/CX/ch9eQQGXPSxS9Vl7YaeiOZLHquTb4aziZSf8aoxfCnwMbaEIrqzbViYDMUFTvCMIu1mCVau9GBEhqMZJkTGU8Y/FLWckLwhLoDTgBL7gQg=" Nov 21 14:27:02 volumio go-librespot[2097]: time="2024-11-21T14:27:02+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:27:02 volumio go-librespot[2097]: time="2024-11-21T14:27:02+09:00" level=debug msg="completed keyexchange" Nov 21 14:27:02 volumio go-librespot[2097]: time="2024-11-21T14:27:02+09:00" level=debug msg="completed challenge" Nov 21 14:27:02 volumio go-librespot[2097]: time="2024-11-21T14:27:02+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:27:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:27:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:27:04 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:04 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:27:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Nov 21 14:27:05 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:27:05 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:27:05 volumio go-librespot[2110]: Librespot-go daemon starting... Nov 21 14:27:05 volumio go-librespot[2110]: time="2024-11-21T14:27:05+09:00" level=info msg="generated new device id: eb9c889aaa758b39b2f5aebf42b0190f82b3515d" Nov 21 14:27:05 volumio go-librespot[2110]: time="2024-11-21T14:27:05+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:27:06 volumio go-librespot[2110]: time="2024-11-21T14:27:06+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:27:06 volumio go-librespot[2110]: time="2024-11-21T14:27:06+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:27:06 volumio go-librespot[2110]: time="2024-11-21T14:27:06+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:27:06 volumio go-librespot[2110]: time="2024-11-21T14:27:06+09:00" level=debug msg="zeroconf server listening on port 46535" Nov 21 14:27:06 volumio go-librespot[2110]: time="2024-11-21T14:27:06+09:00" level=debug msg="obtained new client token: AAAlY5qHpt2LntUKfeu1v78DcAsbjgXzzW9O1TzjMk5rDe9fe7FHAAXUW4sa7q5OH//0l6m77fHi7Fj/v0L/xZLSvhjvDYTTUPLVByhDNmcmYxUkOXmYpte2rnMDGDowXykmkAEckLmz4cSPLaXUaQTDCot3wTxbeQ48vYNdDd0lnqCz7kWCwmijRuKvKaT/xc3U7y4VrBvoOVWVqc3rOXfSYVbAG5KL2d91M342LyzYEelWdR50yIVpD/Eo" Nov 21 14:27:06 volumio go-librespot[2110]: time="2024-11-21T14:27:06+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:27:06 volumio go-librespot[2110]: time="2024-11-21T14:27:06+09:00" level=debug msg="completed keyexchange" Nov 21 14:27:06 volumio go-librespot[2110]: time="2024-11-21T14:27:06+09:00" level=debug msg="completed challenge" Nov 21 14:27:06 volumio go-librespot[2110]: time="2024-11-21T14:27:06+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:27:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:27:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:27:07 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:07 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:27:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Nov 21 14:27:10 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:27:10 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:27:10 volumio go-librespot[2132]: Librespot-go daemon starting... Nov 21 14:27:10 volumio go-librespot[2132]: time="2024-11-21T14:27:10+09:00" level=info msg="generated new device id: 93af7f43503704c9dd0fa289bfdc1d35984869f7" Nov 21 14:27:10 volumio go-librespot[2132]: time="2024-11-21T14:27:10+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:27:10 volumio go-librespot[2132]: time="2024-11-21T14:27:10+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:27:10 volumio go-librespot[2132]: time="2024-11-21T14:27:10+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:27:10 volumio go-librespot[2132]: time="2024-11-21T14:27:10+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:27:10 volumio go-librespot[2132]: time="2024-11-21T14:27:10+09:00" level=debug msg="zeroconf server listening on port 45255" Nov 21 14:27:10 volumio go-librespot[2132]: time="2024-11-21T14:27:10+09:00" level=debug msg="obtained new client token: AABkAjM0gaLJRABdLU/ehdsN1xqbTC7aSVEVl6NreQeBYFJvwBI+TKbtK6ZLINdzGhJSm9vPGL8PfNKZw/4BZSdZVUFv5dBCrnNsN6/cpS8SmEifqkBr4vLFiOFEiiBG/psXPikiW4ecflpHCbu5aJpiEL/vuMdR6qI7bSXLQqXUJNwKaG5yFzsaFlcrQkocnmxUIaXVLaeTx0oVQum9zcVA1OxJvDihahAkePbsIV7hRmccsFWx4W5jgxzuDQM=" Nov 21 14:27:10 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:10 volumio go-librespot[2132]: time="2024-11-21T14:27:10+09:00" level=debug msg="new websocket client" Nov 21 14:27:10 volumio volumio[817]: info: Connection to go-librespot Websocket established Nov 21 14:27:10 volumio go-librespot[2132]: time="2024-11-21T14:27:10+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:27:10 volumio go-librespot[2132]: time="2024-11-21T14:27:10+09:00" level=debug msg="completed keyexchange" Nov 21 14:27:11 volumio go-librespot[2132]: time="2024-11-21T14:27:11+09:00" level=debug msg="completed challenge" Nov 21 14:27:11 volumio go-librespot[2132]: time="2024-11-21T14:27:11+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:27:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:27:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:27:11 volumio volumio[817]: info: Connection to go-librespot Websocket closed Nov 21 14:27:13 volumio volumio[817]: info: Getting Spotify volume Nov 21 14:27:13 volumio volumio[817]: (node:817) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:13 volumio volumio[817]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 21 14:27:13 volumio volumio[817]: (node:817) 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: 15) Nov 21 14:27:13 volumio volumio[817]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Nov 21 14:27:13 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Nov 21 14:27:13 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Nov 21 14:27:14 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:14 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:27:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Nov 21 14:27:14 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:27:14 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:27:14 volumio go-librespot[2143]: Librespot-go daemon starting... Nov 21 14:27:14 volumio go-librespot[2143]: time="2024-11-21T14:27:14+09:00" level=info msg="generated new device id: 2afa43e6f7df8eda4f33889c4be5a0aa52d00750" Nov 21 14:27:14 volumio go-librespot[2143]: time="2024-11-21T14:27:14+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:27:14 volumio go-librespot[2143]: time="2024-11-21T14:27:14+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:27:14 volumio go-librespot[2143]: time="2024-11-21T14:27:14+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:27:14 volumio go-librespot[2143]: time="2024-11-21T14:27:14+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:27:14 volumio go-librespot[2143]: time="2024-11-21T14:27:14+09:00" level=debug msg="zeroconf server listening on port 40281" Nov 21 14:27:14 volumio go-librespot[2143]: time="2024-11-21T14:27:14+09:00" level=debug msg="obtained new client token: AADpVVx7RfmFTpril9/Vv1ntDgQI/9evcqlXQONdz8HO56oCq9ZQPqbhbzqD7kJ4b67o4hlrH+Zap/NrINf3oxeerdjAe5ivnIoVw4VW4bb9jCdCQw17Ume206iATpCoEKX9Oe9uWLaduf8UnDfvWcNiLUsmn3BcRC7T2R/FlYm/pb7CmTJZyGswZuCmuqGCOkG09zTPUYOC8/Xv7Q1AmjFWCth6bkOmXhR2vK6yBWJkMGy/jPNHqY9T2NqvlCQ=" Nov 21 14:27:14 volumio go-librespot[2143]: time="2024-11-21T14:27:14+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:27:14 volumio go-librespot[2143]: time="2024-11-21T14:27:14+09:00" level=debug msg="completed keyexchange" Nov 21 14:27:15 volumio go-librespot[2143]: time="2024-11-21T14:27:15+09:00" level=debug msg="completed challenge" Nov 21 14:27:15 volumio go-librespot[2143]: time="2024-11-21T14:27:15+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:27:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:27:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:27:17 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:17 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:27:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. Nov 21 14:27:18 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:27:18 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:27:18 volumio go-librespot[2165]: Librespot-go daemon starting... Nov 21 14:27:18 volumio go-librespot[2165]: time="2024-11-21T14:27:18+09:00" level=info msg="generated new device id: aceca3ba35be47c0e47b16aeb4eceaff79073eb5" Nov 21 14:27:18 volumio go-librespot[2165]: time="2024-11-21T14:27:18+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:27:18 volumio go-librespot[2165]: time="2024-11-21T14:27:18+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:27:18 volumio go-librespot[2165]: time="2024-11-21T14:27:18+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:27:18 volumio go-librespot[2165]: time="2024-11-21T14:27:18+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:27:18 volumio go-librespot[2165]: time="2024-11-21T14:27:18+09:00" level=debug msg="zeroconf server listening on port 42987" Nov 21 14:27:18 volumio go-librespot[2165]: time="2024-11-21T14:27:18+09:00" level=debug msg="obtained new client token: AAAtCnhYuLBl7ZvDh5usxyBjyYa7RBz7dUft1gcidRf9FHvFEm1Jyyz5KQzy6J3fNotmkklnbbBEUUQMFpxUBp7YtvQNY6lhMZ5RJDJ28I0wf2p2oNOrSC84FtxFuOrRDNbO+hXb6Ew1P0l3Mqr/F2+bY60ghVTWTQl4XzhQ7sX+XkqATTw69pUXaK3PylrQr8+af9v+2gW6XKRROvfDVAGY8CEHcCL4NZrkOv/Mo1dNeJh2FEye0QJIad6BnwI=" Nov 21 14:27:19 volumio go-librespot[2165]: time="2024-11-21T14:27:19+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:27:19 volumio go-librespot[2165]: time="2024-11-21T14:27:19+09:00" level=debug msg="completed keyexchange" Nov 21 14:27:19 volumio go-librespot[2165]: time="2024-11-21T14:27:19+09:00" level=debug msg="completed challenge" Nov 21 14:27:19 volumio go-librespot[2165]: time="2024-11-21T14:27:19+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:27:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:27:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:27:20 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:20 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:27:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. Nov 21 14:27:22 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:27:22 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:27:22 volumio go-librespot[2173]: Librespot-go daemon starting... Nov 21 14:27:22 volumio go-librespot[2173]: time="2024-11-21T14:27:22+09:00" level=info msg="generated new device id: 8da1463fe2c3b9c0339da5f537923b536f28b095" Nov 21 14:27:22 volumio go-librespot[2173]: time="2024-11-21T14:27:22+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:27:23 volumio go-librespot[2173]: time="2024-11-21T14:27:23+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:27:23 volumio go-librespot[2173]: time="2024-11-21T14:27:23+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:27:23 volumio go-librespot[2173]: time="2024-11-21T14:27:23+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:27:23 volumio go-librespot[2173]: time="2024-11-21T14:27:23+09:00" level=debug msg="zeroconf server listening on port 34503" Nov 21 14:27:23 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:23 volumio go-librespot[2173]: time="2024-11-21T14:27:23+09:00" level=debug msg="new websocket client" Nov 21 14:27:23 volumio volumio[817]: info: Connection to go-librespot Websocket established Nov 21 14:27:23 volumio go-librespot[2173]: time="2024-11-21T14:27:23+09:00" level=debug msg="obtained new client token: AABhXbyvpirAFMUkzzxv+cqcYHPx4cHbzhuXlO2cO/Qgu65/LCyS63qWZin15U3exTFSq120zVCb+H0vpjY1s4k54Kh90+Mcw3eZ4PSSngS1Zi+0Sb4NvpmzJzovBOHRMBapVAHukKCc8NyJlcW2l4tpfJS80NpzOadvnmUlK98Ep+RE2XryhpY2YUKUh4RLLqD3S18piXgt1CMASxLTh25zQJsn455gLUxNl8loY3Ao39+X7nyOM4X/IPTh" Nov 21 14:27:23 volumio go-librespot[2173]: time="2024-11-21T14:27:23+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:27:23 volumio go-librespot[2173]: time="2024-11-21T14:27:23+09:00" level=debug msg="completed keyexchange" Nov 21 14:27:23 volumio go-librespot[2173]: time="2024-11-21T14:27:23+09:00" level=debug msg="completed challenge" Nov 21 14:27:23 volumio go-librespot[2173]: time="2024-11-21T14:27:23+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:27:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:27:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:27:23 volumio volumio[817]: info: Connection to go-librespot Websocket closed Nov 21 14:27:26 volumio volumio[817]: info: Getting Spotify volume Nov 21 14:27:26 volumio volumio[817]: (node:817) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:26 volumio volumio[817]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 21 14:27:26 volumio volumio[817]: (node:817) 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: 16) Nov 21 14:27:26 volumio volumio[817]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Nov 21 14:27:26 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Nov 21 14:27:26 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Nov 21 14:27:26 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:26 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:27 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:27:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. Nov 21 14:27:27 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:27:27 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:27:27 volumio go-librespot[2185]: Librespot-go daemon starting... Nov 21 14:27:27 volumio go-librespot[2185]: time="2024-11-21T14:27:27+09:00" level=info msg="generated new device id: 1a99c720d38f9608b9a5689c2e018ac07882cc9a" Nov 21 14:27:27 volumio go-librespot[2185]: time="2024-11-21T14:27:27+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:27:27 volumio go-librespot[2185]: time="2024-11-21T14:27:27+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:27:27 volumio go-librespot[2185]: time="2024-11-21T14:27:27+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:27:27 volumio go-librespot[2185]: time="2024-11-21T14:27:27+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:27:27 volumio go-librespot[2185]: time="2024-11-21T14:27:27+09:00" level=debug msg="zeroconf server listening on port 33497" Nov 21 14:27:27 volumio go-librespot[2185]: time="2024-11-21T14:27:27+09:00" level=debug msg="obtained new client token: AAD4V4Pe6MysMCM7ApS8xwguXImPfifJjGJPE2Jm4/XXxEqLJn9t0zVi12I3Y/TZImZ5kSs+yGAwWXnR2QXILxejfZukz7Jlu9vu8Wp5FH4QXFhTuh5TzOhhBaK6CrCJxrGhM9H0DV5xTkSMpPII2btg4G6qJF6pjdmfFlOWgwLoxI8li2PkkOpXtjnNEyWwzBHpsP6ZpbIcEc/shTQM2+8XDP/a6pWYjd5jlgx8NN+oMJs8iC4Rg35ND79aCMA=" Nov 21 14:27:27 volumio go-librespot[2185]: time="2024-11-21T14:27:27+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:27:27 volumio go-librespot[2185]: time="2024-11-21T14:27:27+09:00" level=debug msg="completed keyexchange" Nov 21 14:27:28 volumio go-librespot[2185]: time="2024-11-21T14:27:28+09:00" level=debug msg="completed challenge" Nov 21 14:27:28 volumio go-librespot[2185]: time="2024-11-21T14:27:28+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:27:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:27:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:27:29 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:29 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:31 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:27:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49. Nov 21 14:27:31 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:27:31 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:27:31 volumio go-librespot[2207]: Librespot-go daemon starting... Nov 21 14:27:31 volumio go-librespot[2207]: time="2024-11-21T14:27:31+09:00" level=info msg="generated new device id: 991443a1ebfd1c6ed9483c957760120863b01820" Nov 21 14:27:31 volumio go-librespot[2207]: time="2024-11-21T14:27:31+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:27:31 volumio go-librespot[2207]: time="2024-11-21T14:27:31+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:27:31 volumio go-librespot[2207]: time="2024-11-21T14:27:31+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:27:31 volumio go-librespot[2207]: time="2024-11-21T14:27:31+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:27:31 volumio go-librespot[2207]: time="2024-11-21T14:27:31+09:00" level=debug msg="zeroconf server listening on port 41637" Nov 21 14:27:31 volumio go-librespot[2207]: time="2024-11-21T14:27:31+09:00" level=debug msg="obtained new client token: AAD38K+iGSNPEZohC58wad0XufGZZmTRoNRX5V4B+WNF0wcnZEK7L3iOO3/+cza3E48jfYQEVKM9cIWPPjguWo49xBL3ac8LhpkZbRL4ICLG5Izls4reFZJs/i03gHbUOYmZWVNjX8ADCjoDFWRE0ZF6wl5CZG4DYtLmN9IA82hmGe5tuq3tb6lVBLb2Wwfigp7wouISenp3zNo9f/x14N11zxqoDtgsRzzDCDmtC1U7z6G6OA+ByV4Jf2Ny4mc=" Nov 21 14:27:31 volumio go-librespot[2207]: time="2024-11-21T14:27:31+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:27:31 volumio go-librespot[2207]: time="2024-11-21T14:27:31+09:00" level=debug msg="completed keyexchange" Nov 21 14:27:32 volumio go-librespot[2207]: time="2024-11-21T14:27:32+09:00" level=debug msg="completed challenge" Nov 21 14:27:32 volumio go-librespot[2207]: time="2024-11-21T14:27:32+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:27:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:27:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:27:32 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:32 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:35 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:27:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. Nov 21 14:27:35 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:27:35 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:27:35 volumio go-librespot[2225]: Librespot-go daemon starting... Nov 21 14:27:35 volumio go-librespot[2225]: time="2024-11-21T14:27:35+09:00" level=info msg="generated new device id: 36bdc1fb4135e884c73e26c2d32df7cc1432aafc" Nov 21 14:27:35 volumio go-librespot[2225]: time="2024-11-21T14:27:35+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:27:35 volumio go-librespot[2225]: time="2024-11-21T14:27:35+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:27:35 volumio go-librespot[2225]: time="2024-11-21T14:27:35+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:27:35 volumio go-librespot[2225]: time="2024-11-21T14:27:35+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:27:35 volumio go-librespot[2225]: time="2024-11-21T14:27:35+09:00" level=debug msg="zeroconf server listening on port 37597" Nov 21 14:27:35 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:35 volumio go-librespot[2225]: time="2024-11-21T14:27:35+09:00" level=debug msg="new websocket client" Nov 21 14:27:35 volumio volumio[817]: info: Connection to go-librespot Websocket established Nov 21 14:27:36 volumio go-librespot[2225]: time="2024-11-21T14:27:36+09:00" level=debug msg="obtained new client token: AACB0DllJtZq7bY89ZVlGPlmZUhofeAX1PZ/8x9kzMGOx25s2nPpbGMUpgbxtqA/MKDUeyCehvP9X4rMCbYcB88pAclFXqXJJ96UyCtPfHVYhwz9zq0jCtDrA2s6vRwFtxEcUtZ0wa2r8m6UDi6f8jAMvVWmsn1exdUthxiiUNocwUgIpoo0oec2mcflsTufunHdZ1GcHzMg5XI8H0VC0YlvtqS0hJQVcuN89r89YidOpwRrlo0sxaJzT39BbDg=" Nov 21 14:27:36 volumio go-librespot[2225]: time="2024-11-21T14:27:36+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:27:36 volumio go-librespot[2225]: time="2024-11-21T14:27:36+09:00" level=debug msg="completed keyexchange" Nov 21 14:27:36 volumio go-librespot[2225]: time="2024-11-21T14:27:36+09:00" level=debug msg="completed challenge" Nov 21 14:27:36 volumio go-librespot[2225]: time="2024-11-21T14:27:36+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:27:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:27:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:27:36 volumio volumio[817]: info: Connection to go-librespot Websocket closed Nov 21 14:27:38 volumio volumio[817]: info: Getting Spotify volume Nov 21 14:27:38 volumio volumio[817]: (node:817) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:38 volumio volumio[817]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 21 14:27:38 volumio volumio[817]: (node:817) 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: 17) Nov 21 14:27:38 volumio volumio[817]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Nov 21 14:27:38 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Nov 21 14:27:38 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Nov 21 14:27:39 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:39 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:39 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:27:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. Nov 21 14:27:39 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:27:39 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:27:39 volumio go-librespot[2281]: Librespot-go daemon starting... Nov 21 14:27:39 volumio go-librespot[2281]: time="2024-11-21T14:27:39+09:00" level=info msg="generated new device id: 09c705b2a537b586bba0d4a88c0314c36fda5cee" Nov 21 14:27:39 volumio go-librespot[2281]: time="2024-11-21T14:27:39+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:27:40 volumio go-librespot[2281]: time="2024-11-21T14:27:40+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Nov 21 14:27:40 volumio go-librespot[2281]: time="2024-11-21T14:27:40+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Nov 21 14:27:40 volumio go-librespot[2281]: time="2024-11-21T14:27:40+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Nov 21 14:27:40 volumio go-librespot[2281]: time="2024-11-21T14:27:40+09:00" level=debug msg="zeroconf server listening on port 35711" Nov 21 14:27:40 volumio go-librespot[2281]: time="2024-11-21T14:27:40+09:00" level=debug msg="obtained new client token: AAAr/+aQTTNikcdR5eyqI4bwkFV4D2/8xh6cRJyWoJggyFI237/OJDzHD2advEnT77+sGvgvx9nhR2swxpuLaDzT37JQ2ujUEt5q13f5jarxLpJdedruB8szzOKdtRkj5xQvtYDEDDQcYDgu2KfHaPDkBn87fn2zIlTEkX2lfmDMWdFNS4oGptLB35lY52f4t/dTh17Z61ggRHsXe+/M/HRjkPmno0t5lJ0Rc3NkldCsD68uBfB3OMMMnktY" Nov 21 14:27:40 volumio go-librespot[2281]: time="2024-11-21T14:27:40+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:27:40 volumio go-librespot[2281]: time="2024-11-21T14:27:40+09:00" level=debug msg="completed keyexchange" Nov 21 14:27:40 volumio go-librespot[2281]: time="2024-11-21T14:27:40+09:00" level=debug msg="completed challenge" Nov 21 14:27:40 volumio go-librespot[2281]: time="2024-11-21T14:27:40+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:27:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:27:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:27:42 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:42 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:27:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52. Nov 21 14:27:44 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:27:44 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:27:44 volumio go-librespot[2294]: Librespot-go daemon starting... Nov 21 14:27:44 volumio go-librespot[2294]: time="2024-11-21T14:27:44+09:00" level=info msg="generated new device id: ac5fada21bd8dcc623a0339b22cb1f0a5f968b7c" Nov 21 14:27:44 volumio go-librespot[2294]: time="2024-11-21T14:27:44+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:27:44 volumio go-librespot[2294]: time="2024-11-21T14:27:44+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Nov 21 14:27:44 volumio go-librespot[2294]: time="2024-11-21T14:27:44+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Nov 21 14:27:44 volumio go-librespot[2294]: time="2024-11-21T14:27:44+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Nov 21 14:27:44 volumio go-librespot[2294]: time="2024-11-21T14:27:44+09:00" level=debug msg="zeroconf server listening on port 34847" Nov 21 14:27:44 volumio go-librespot[2294]: time="2024-11-21T14:27:44+09:00" level=debug msg="obtained new client token: AACHgOuzbYRIn8V52kwLb6yaGe5x32BkpkXu3J92mVvky7pjoA0TVnbS4p99gMzb6uZl0r02eLsEynZioycyCbJ1jd+F6/boG6HdUYQAKr1nsKAJTjFmTVPi82bVmJgT7NRwsNPWo0tKCaRgX80yplSSboJbSFK2KmoeDmxFk9wqz7qQV3XlCmZNAixaERvQO2B469pdHHo7laO2ptK0uFQJlOG+IOGB6QAlqMWm31T4cwWU7BV4HKp21HBZLIA=" Nov 21 14:27:44 volumio go-librespot[2294]: time="2024-11-21T14:27:44+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:27:44 volumio go-librespot[2294]: time="2024-11-21T14:27:44+09:00" level=debug msg="completed keyexchange" Nov 21 14:27:45 volumio go-librespot[2294]: time="2024-11-21T14:27:45+09:00" level=debug msg="completed challenge" Nov 21 14:27:45 volumio go-librespot[2294]: time="2024-11-21T14:27:45+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:27:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:27:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:27:45 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:45 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:27:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53. Nov 21 14:27:48 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:27:48 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:27:48 volumio go-librespot[2316]: Librespot-go daemon starting... Nov 21 14:27:48 volumio go-librespot[2316]: time="2024-11-21T14:27:48+09:00" level=info msg="generated new device id: ced9bd51a9cd04b032e4bbcfb7559e3f78d4f703" Nov 21 14:27:48 volumio go-librespot[2316]: time="2024-11-21T14:27:48+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:27:48 volumio go-librespot[2316]: time="2024-11-21T14:27:48+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Nov 21 14:27:48 volumio go-librespot[2316]: time="2024-11-21T14:27:48+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Nov 21 14:27:48 volumio go-librespot[2316]: time="2024-11-21T14:27:48+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Nov 21 14:27:48 volumio go-librespot[2316]: time="2024-11-21T14:27:48+09:00" level=debug msg="zeroconf server listening on port 44013" Nov 21 14:27:48 volumio go-librespot[2316]: time="2024-11-21T14:27:48+09:00" level=debug msg="obtained new client token: AABHBCSUwBK7uyKU+Qy6GUl+3y24MV2HqM1j76hqjuVadYd6jmPKxx08rKN6UyFOko0Vk32yLAzrQria/mkFZdrt/D2xg5ygr+NyczcDomDHXqG4icQEMGXOh7LwMFsFG9KJIYsVBYN8+vgAZ1wD+/XMt/Fzvt2jq1uclJc1IVaBwyu8EDG94Gy0cNXfE763z5W53NWDKywtejkCTBcXeQQiMLYhDgiYcgoGCftpKqEU6X98bwRRTOX7hK0qylg=" Nov 21 14:27:48 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:48 volumio go-librespot[2316]: time="2024-11-21T14:27:48+09:00" level=debug msg="new websocket client" Nov 21 14:27:48 volumio volumio[817]: info: Connection to go-librespot Websocket established Nov 21 14:27:48 volumio go-librespot[2316]: time="2024-11-21T14:27:48+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:27:48 volumio go-librespot[2316]: time="2024-11-21T14:27:48+09:00" level=debug msg="completed keyexchange" Nov 21 14:27:49 volumio go-librespot[2316]: time="2024-11-21T14:27:49+09:00" level=debug msg="completed challenge" Nov 21 14:27:49 volumio go-librespot[2316]: time="2024-11-21T14:27:49+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:27:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:27:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:27:49 volumio volumio[817]: info: Connection to go-librespot Websocket closed Nov 21 14:27:51 volumio volumio[817]: info: Getting Spotify volume Nov 21 14:27:51 volumio volumio[817]: (node:817) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:51 volumio volumio[817]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 21 14:27:51 volumio volumio[817]: (node:817) 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: 18) Nov 21 14:27:51 volumio volumio[817]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Nov 21 14:27:51 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Nov 21 14:27:51 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Nov 21 14:27:52 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:52 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:27:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54. Nov 21 14:27:52 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:27:52 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:27:52 volumio go-librespot[2324]: Librespot-go daemon starting... Nov 21 14:27:52 volumio go-librespot[2324]: time="2024-11-21T14:27:52+09:00" level=info msg="generated new device id: 76d9bfe0b1f4fc7ea9944bf126d67d186804afca" Nov 21 14:27:52 volumio go-librespot[2324]: time="2024-11-21T14:27:52+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:27:52 volumio go-librespot[2324]: time="2024-11-21T14:27:52+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Nov 21 14:27:52 volumio go-librespot[2324]: time="2024-11-21T14:27:52+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Nov 21 14:27:52 volumio go-librespot[2324]: time="2024-11-21T14:27:52+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Nov 21 14:27:52 volumio go-librespot[2324]: time="2024-11-21T14:27:52+09:00" level=debug msg="zeroconf server listening on port 41883" Nov 21 14:27:52 volumio go-librespot[2324]: time="2024-11-21T14:27:52+09:00" level=debug msg="obtained new client token: AAAg6BhGVEaRzLpB4HlpZArs3vVYEJXQADIoCq2eS0conPn50qZqnApzhkqgPGNl3Y2FYgBgp5cDsJ0nD0oZnJms0m1If8MLAmsJHia7TmC9+IBVMwSSa2s10c0Q57JNwskSjuyizdU3idFxZ2uYpilX0ixMpoSuIlzh6AMwTNiwYqWk13JALOeZEhg4LBG/SRF8jamXEpMzI/4wmykb7jurD+9ATYWiuoLneL22v9t68FP0MahMZK7lZhN3i0U=" Nov 21 14:27:53 volumio go-librespot[2324]: time="2024-11-21T14:27:53+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:27:53 volumio go-librespot[2324]: time="2024-11-21T14:27:53+09:00" level=debug msg="completed keyexchange" Nov 21 14:27:53 volumio go-librespot[2324]: time="2024-11-21T14:27:53+09:00" level=debug msg="completed challenge" Nov 21 14:27:53 volumio go-librespot[2324]: time="2024-11-21T14:27:53+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:27:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:27:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:27:55 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:55 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:27:56 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:27:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55. Nov 21 14:27:56 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:27:56 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:27:56 volumio go-librespot[2335]: Librespot-go daemon starting... Nov 21 14:27:56 volumio go-librespot[2335]: time="2024-11-21T14:27:56+09:00" level=info msg="generated new device id: 580d6f43f6140c04e0a5fe6b4998a20b6e5faa49" Nov 21 14:27:56 volumio go-librespot[2335]: time="2024-11-21T14:27:56+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:27:57 volumio go-librespot[2335]: time="2024-11-21T14:27:57+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:27:57 volumio go-librespot[2335]: time="2024-11-21T14:27:57+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:27:57 volumio go-librespot[2335]: time="2024-11-21T14:27:57+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:27:57 volumio go-librespot[2335]: time="2024-11-21T14:27:57+09:00" level=debug msg="zeroconf server listening on port 40205" Nov 21 14:27:57 volumio go-librespot[2335]: time="2024-11-21T14:27:57+09:00" level=debug msg="obtained new client token: AAAeTuMK8fqC1HfyrCYnHvirwSUl4U5sM8/Z18bwup0YWrxUXwAZMMd8zO8YTf/A2tNqJVKPXqwzBWmMf85Zc7WqNeC7bqbztBsxkrrs5o+DRzD6Gg+JQbCVpymz4cBkk+fd01koVtHeeFLeFBRLoGG/ene4qZVppk1GJceAMmWddk7uqLpS3waW+NA32uopDTn6DRTgVjM+b6pXUwYgE4g5jnfT/jhXvypzfzRiNa5yt/iJ/XEcLPD442cJ" Nov 21 14:27:57 volumio go-librespot[2335]: time="2024-11-21T14:27:57+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:27:57 volumio go-librespot[2335]: time="2024-11-21T14:27:57+09:00" level=debug msg="completed keyexchange" Nov 21 14:27:57 volumio go-librespot[2335]: time="2024-11-21T14:27:57+09:00" level=debug msg="completed challenge" Nov 21 14:27:57 volumio go-librespot[2335]: time="2024-11-21T14:27:57+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:27:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:27:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:27:57 volumio kernel: hwmon hwmon1: Undervoltage detected! Nov 21 14:27:58 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:27:58 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:28:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:28:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56. Nov 21 14:28:01 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:28:01 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:28:01 volumio go-librespot[2358]: Librespot-go daemon starting... Nov 21 14:28:01 volumio go-librespot[2358]: time="2024-11-21T14:28:01+09:00" level=info msg="generated new device id: 07f861d639d7e98df8e67f8c1a8e13ef1a84c151" Nov 21 14:28:01 volumio go-librespot[2358]: time="2024-11-21T14:28:01+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:28:01 volumio go-librespot[2358]: time="2024-11-21T14:28:01+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:28:01 volumio go-librespot[2358]: time="2024-11-21T14:28:01+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:28:01 volumio go-librespot[2358]: time="2024-11-21T14:28:01+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:28:01 volumio go-librespot[2358]: time="2024-11-21T14:28:01+09:00" level=debug msg="zeroconf server listening on port 40889" Nov 21 14:28:01 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:28:01 volumio go-librespot[2358]: time="2024-11-21T14:28:01+09:00" level=debug msg="new websocket client" Nov 21 14:28:01 volumio volumio[817]: info: Connection to go-librespot Websocket established Nov 21 14:28:01 volumio go-librespot[2358]: time="2024-11-21T14:28:01+09:00" level=debug msg="obtained new client token: AAB2WueItmlNMOUbXcxqu2dQs22dnytu1YRkNMP+6/9aaXlmoLpIMtqN+Py+iKYJ/XbIQWJlPR8Zc6x1siHqqT4JgaAywObvuoH6gQMkPPeHuPqvvB6NZ0k+adb7PCDKeTjZ4MdM3UeW0OBaHAAbE0mt7WIpWfu9oBMOmlumxaxJ4hSobCOOIjeFFeKSXRv9JMdJMDdxRfenRKSQaCTdhWUkIw3V5Xtml3LfxICK5pj7zGWREvHkYSmR9YQHjKs=" Nov 21 14:28:01 volumio go-librespot[2358]: time="2024-11-21T14:28:01+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:28:01 volumio go-librespot[2358]: time="2024-11-21T14:28:01+09:00" level=debug msg="completed keyexchange" Nov 21 14:28:02 volumio go-librespot[2358]: time="2024-11-21T14:28:02+09:00" level=debug msg="completed challenge" Nov 21 14:28:02 volumio go-librespot[2358]: time="2024-11-21T14:28:02+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:28:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:28:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:28:02 volumio volumio[817]: info: Connection to go-librespot Websocket closed Nov 21 14:28:04 volumio kernel: hwmon hwmon1: Voltage normalised Nov 21 14:28:04 volumio volumio[817]: info: Getting Spotify volume Nov 21 14:28:04 volumio volumio[817]: (node:817) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:28:04 volumio volumio[817]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 21 14:28:04 volumio volumio[817]: (node:817) 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: 19) Nov 21 14:28:04 volumio volumio[817]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Nov 21 14:28:04 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Nov 21 14:28:04 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Nov 21 14:28:05 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:28:05 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:28:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:28:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57. Nov 21 14:28:05 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:28:05 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:28:05 volumio go-librespot[2371]: Librespot-go daemon starting... Nov 21 14:28:05 volumio go-librespot[2371]: time="2024-11-21T14:28:05+09:00" level=info msg="generated new device id: c42c22c39644f4e35e8b3de477648924433f2250" Nov 21 14:28:05 volumio go-librespot[2371]: time="2024-11-21T14:28:05+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:28:05 volumio go-librespot[2371]: time="2024-11-21T14:28:05+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:28:05 volumio go-librespot[2371]: time="2024-11-21T14:28:05+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:28:05 volumio go-librespot[2371]: time="2024-11-21T14:28:05+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:28:05 volumio go-librespot[2371]: time="2024-11-21T14:28:05+09:00" level=debug msg="zeroconf server listening on port 45915" Nov 21 14:28:05 volumio go-librespot[2371]: time="2024-11-21T14:28:05+09:00" level=debug msg="obtained new client token: AAC5wb+fhEcdHuQ5Z/7SnW6VdwnrXVt2Edz3jIYhfc1BvU/uvkEkxPKxFYV1qC85rtqNPMdRiuxv2jl6/WMz7kFKoCz8ZeTLTwPmj8USC6oC5eEVSSUXuvKfxRj226zxWALU/PkFowUUlFus8xCGkgPGZIapSMC4KY0GAAgWj9lNpWWzjDve2G6NSso7tW/EfWipfjPgbNpXivqBo23LdA952jab06Wi+XK/DAp2b0/xbggVjPLv8g/J9y7YCTw=" Nov 21 14:28:05 volumio go-librespot[2371]: time="2024-11-21T14:28:05+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:28:05 volumio go-librespot[2371]: time="2024-11-21T14:28:05+09:00" level=debug msg="completed keyexchange" Nov 21 14:28:06 volumio go-librespot[2371]: time="2024-11-21T14:28:06+09:00" level=debug msg="completed challenge" Nov 21 14:28:06 volumio go-librespot[2371]: time="2024-11-21T14:28:06+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:28:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:28:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:28:08 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:28:08 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:28:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:28:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 58. Nov 21 14:28:09 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:28:09 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:28:09 volumio go-librespot[2394]: Librespot-go daemon starting... Nov 21 14:28:09 volumio go-librespot[2394]: time="2024-11-21T14:28:09+09:00" level=info msg="generated new device id: 695c9b9fa1e2c2d4c02c87832ed6dcafbe149f8e" Nov 21 14:28:09 volumio go-librespot[2394]: time="2024-11-21T14:28:09+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:28:09 volumio go-librespot[2394]: time="2024-11-21T14:28:09+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:28:09 volumio go-librespot[2394]: time="2024-11-21T14:28:09+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:28:09 volumio go-librespot[2394]: time="2024-11-21T14:28:09+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:28:09 volumio go-librespot[2394]: time="2024-11-21T14:28:09+09:00" level=debug msg="zeroconf server listening on port 44019" Nov 21 14:28:09 volumio go-librespot[2394]: time="2024-11-21T14:28:09+09:00" level=debug msg="obtained new client token: AABOW0U+Vedzmv9YivTMT4GOQjhVs4XPObE7OCOYfTquhEhH5XpK52DqlY0hfDKCiAGZq3UhVmgCOaF+1FVU5NnEEaacS5GK0P9+512nyjcbWCEcQpyWANiJEUPkkqn1Ny1xdVLWHtkM5XsXjnbXm6qOQIGdPgbhIu4mDKKFZcuTprZYa8wdowAeBQUcH2V6uEbE+xo2a+2qDuhl3jd4Ln+A+2dD6gaUeWrdrAR4lKaRnJO+8o3LTe1i0Oq+y/I=" Nov 21 14:28:10 volumio go-librespot[2394]: time="2024-11-21T14:28:10+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:28:10 volumio go-librespot[2394]: time="2024-11-21T14:28:10+09:00" level=debug msg="completed keyexchange" Nov 21 14:28:10 volumio go-librespot[2394]: time="2024-11-21T14:28:10+09:00" level=debug msg="completed challenge" Nov 21 14:28:10 volumio go-librespot[2394]: time="2024-11-21T14:28:10+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:28:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:28:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:28:11 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:28:11 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:28:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:28:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59. Nov 21 14:28:13 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:28:13 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:28:13 volumio go-librespot[2405]: Librespot-go daemon starting... Nov 21 14:28:13 volumio go-librespot[2405]: time="2024-11-21T14:28:13+09:00" level=info msg="generated new device id: 0de5fe5e12358942ce6f2ba123b2667ca74fcbb7" Nov 21 14:28:13 volumio go-librespot[2405]: time="2024-11-21T14:28:13+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:28:14 volumio go-librespot[2405]: time="2024-11-21T14:28:14+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:28:14 volumio go-librespot[2405]: time="2024-11-21T14:28:14+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:28:14 volumio go-librespot[2405]: time="2024-11-21T14:28:14+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:28:14 volumio go-librespot[2405]: time="2024-11-21T14:28:14+09:00" level=debug msg="zeroconf server listening on port 35745" Nov 21 14:28:14 volumio go-librespot[2405]: time="2024-11-21T14:28:14+09:00" level=debug msg="obtained new client token: AABdSF0rO8LVUQ5z0rSfU64QXdHFGQ/vF4Ax6dZIS+nRgws/p/zQ19FpzNF2FKR74oCAIVA0X1dfT8frGASJj03dxG32+LJlJpn1F3//K0oRVY/gvvo8ESJBxB2KPrnb56tx09WNPesSmBCQVMjsZj/w32TRW5zSMvgGJc8kBVdRHSnxw4krVAdbpK1FUGEO29IvuIMKN7unDKOcB0NOE0ImoOU658TirFxreF6luu3OeERwmCH/btMnBlfR" Nov 21 14:28:14 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:28:14 volumio go-librespot[2405]: time="2024-11-21T14:28:14+09:00" level=debug msg="new websocket client" Nov 21 14:28:14 volumio volumio[817]: info: Connection to go-librespot Websocket established Nov 21 14:28:14 volumio go-librespot[2405]: time="2024-11-21T14:28:14+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:28:14 volumio go-librespot[2405]: time="2024-11-21T14:28:14+09:00" level=debug msg="completed keyexchange" Nov 21 14:28:14 volumio go-librespot[2405]: time="2024-11-21T14:28:14+09:00" level=debug msg="completed challenge" Nov 21 14:28:14 volumio go-librespot[2405]: time="2024-11-21T14:28:14+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:28:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:28:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:28:14 volumio volumio[817]: info: Connection to go-librespot Websocket closed Nov 21 14:28:17 volumio volumio[817]: info: Getting Spotify volume Nov 21 14:28:17 volumio volumio[817]: (node:817) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:28:17 volumio volumio[817]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 21 14:28:17 volumio volumio[817]: (node:817) 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: 20) Nov 21 14:28:17 volumio volumio[817]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Nov 21 14:28:17 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Nov 21 14:28:17 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Nov 21 14:28:17 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:28:17 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:28:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:28:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 60. Nov 21 14:28:18 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:28:18 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:28:18 volumio go-librespot[2427]: Librespot-go daemon starting... Nov 21 14:28:18 volumio go-librespot[2427]: time="2024-11-21T14:28:18+09:00" level=info msg="generated new device id: 55f364c62e55793f4b0ac93364a2508c5281b5f6" Nov 21 14:28:18 volumio go-librespot[2427]: time="2024-11-21T14:28:18+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:28:18 volumio go-librespot[2427]: time="2024-11-21T14:28:18+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Nov 21 14:28:18 volumio go-librespot[2427]: time="2024-11-21T14:28:18+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Nov 21 14:28:18 volumio go-librespot[2427]: time="2024-11-21T14:28:18+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Nov 21 14:28:18 volumio go-librespot[2427]: time="2024-11-21T14:28:18+09:00" level=debug msg="zeroconf server listening on port 38431" Nov 21 14:28:18 volumio go-librespot[2427]: time="2024-11-21T14:28:18+09:00" level=debug msg="obtained new client token: AABs4V9SvdKv07fwJpOl91GusjTfw0OzafHt0XTNSGce+T8D0ueMV2xzG4TRwpsuCnoNVjhisnsm9xM9a+Q8YY53D245+eHyhRJaVMuwvPAKkYMekg83gNTH216dmA9PbQt3pD29RyNPittkJqK8Cx9Vb2HDhgFvrIxfOjr/v2HhNntMmg+PmneDnoeGwT/6YuBibIMTUJxl7XIfj0yNwT92blDyq4dvB/Dhg+t6LmhK3z/bt1q2/pkgq21+WSw=" Nov 21 14:28:18 volumio go-librespot[2427]: time="2024-11-21T14:28:18+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:28:18 volumio go-librespot[2427]: time="2024-11-21T14:28:18+09:00" level=debug msg="completed keyexchange" Nov 21 14:28:19 volumio go-librespot[2427]: time="2024-11-21T14:28:19+09:00" level=debug msg="completed challenge" Nov 21 14:28:19 volumio go-librespot[2427]: time="2024-11-21T14:28:19+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:28:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:28:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:28:20 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:28:20 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:28:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:28:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 61. Nov 21 14:28:22 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:28:22 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:28:22 volumio go-librespot[2435]: Librespot-go daemon starting... Nov 21 14:28:22 volumio go-librespot[2435]: time="2024-11-21T14:28:22+09:00" level=info msg="generated new device id: 8956571f829737ae9c5698246f7926e9b4ebcb3d" Nov 21 14:28:22 volumio go-librespot[2435]: time="2024-11-21T14:28:22+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:28:22 volumio go-librespot[2435]: time="2024-11-21T14:28:22+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:28:22 volumio go-librespot[2435]: time="2024-11-21T14:28:22+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:28:22 volumio go-librespot[2435]: time="2024-11-21T14:28:22+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:28:22 volumio go-librespot[2435]: time="2024-11-21T14:28:22+09:00" level=debug msg="zeroconf server listening on port 39271" Nov 21 14:28:22 volumio go-librespot[2435]: time="2024-11-21T14:28:22+09:00" level=debug msg="obtained new client token: AABGaqPcWUBmyPpoUgsBzC3Qnrs9eqIR8I0rM0jEGiaV5Db1A5IQiqLTbGMzXXHBKvTWP4wysgGpoZbURRr7+2vPF4T/kKbU3gIULmcbINoscPQO4Mc3/xEDnNquD8ANyo0G6mipUTktXvoANowF44l6DEUcjoRVtLY1drnwNSKemGQpgwiyRYhoYdpouHhMHZOtTS8cmyr3hTT7pSIGOyZIE4ZqkHm4kVT9hpe61cNLzpYLis/cGZNqeZ4aKFA=" Nov 21 14:28:22 volumio go-librespot[2435]: time="2024-11-21T14:28:22+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:28:22 volumio go-librespot[2435]: time="2024-11-21T14:28:22+09:00" level=debug msg="completed keyexchange" Nov 21 14:28:23 volumio go-librespot[2435]: time="2024-11-21T14:28:23+09:00" level=debug msg="completed challenge" Nov 21 14:28:23 volumio go-librespot[2435]: time="2024-11-21T14:28:23+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:28:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:28:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:28:23 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:28:23 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:28:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:28:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 62. Nov 21 14:28:26 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:28:26 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:28:26 volumio go-librespot[2448]: Librespot-go daemon starting... Nov 21 14:28:26 volumio go-librespot[2448]: time="2024-11-21T14:28:26+09:00" level=info msg="generated new device id: f6fc3745a5e2b3a020a04e36562567cfc8266ff4" Nov 21 14:28:26 volumio go-librespot[2448]: time="2024-11-21T14:28:26+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:28:26 volumio go-librespot[2448]: time="2024-11-21T14:28:26+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:28:26 volumio go-librespot[2448]: time="2024-11-21T14:28:26+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:28:26 volumio go-librespot[2448]: time="2024-11-21T14:28:26+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:28:26 volumio go-librespot[2448]: time="2024-11-21T14:28:26+09:00" level=debug msg="zeroconf server listening on port 45755" Nov 21 14:28:26 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:28:26 volumio go-librespot[2448]: time="2024-11-21T14:28:26+09:00" level=debug msg="new websocket client" Nov 21 14:28:26 volumio volumio[817]: info: Connection to go-librespot Websocket established Nov 21 14:28:26 volumio go-librespot[2448]: time="2024-11-21T14:28:26+09:00" level=debug msg="obtained new client token: AABPLiQezmIaIn5BqNnvQeM2PHzZ7OrinTt7sPDuQimP/pz2lKiaE9fxL1UtBdXH5ctDUQwIXsvrYavOePSkv4IbqvxsKptjTWBkhiJQeQ2ZSf6A0FZvFqCGE0cyQTpVXWJ/krPIBWqCCAHthBUudIQtWYtEThe11KiU1QOLd/oT3QwnDYVZ5+i05aK7f9S1fuL82ru45IsaVUfTG3pdCwyVDrpiFLxWpEFbDWdJrbtKXaaGn0B7VlyhRtx2u+w=" Nov 21 14:28:27 volumio go-librespot[2448]: time="2024-11-21T14:28:27+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:28:27 volumio go-librespot[2448]: time="2024-11-21T14:28:27+09:00" level=debug msg="completed keyexchange" Nov 21 14:28:27 volumio go-librespot[2448]: time="2024-11-21T14:28:27+09:00" level=debug msg="completed challenge" Nov 21 14:28:27 volumio go-librespot[2448]: time="2024-11-21T14:28:27+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:28:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:28:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:28:27 volumio volumio[817]: info: Connection to go-librespot Websocket closed Nov 21 14:28:29 volumio volumio[817]: info: Getting Spotify volume Nov 21 14:28:29 volumio volumio[817]: (node:817) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:28:29 volumio volumio[817]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 21 14:28:29 volumio volumio[817]: (node:817) 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: 21) Nov 21 14:28:29 volumio volumio[817]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Nov 21 14:28:29 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Nov 21 14:28:29 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Nov 21 14:28:30 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:28:30 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:28:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:28:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 63. Nov 21 14:28:30 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:28:30 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:28:30 volumio go-librespot[2470]: Librespot-go daemon starting... Nov 21 14:28:30 volumio go-librespot[2470]: time="2024-11-21T14:28:30+09:00" level=info msg="generated new device id: d261c07b2a2fb9985966915e4ee68f712b9a3af5" Nov 21 14:28:30 volumio go-librespot[2470]: time="2024-11-21T14:28:30+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:28:31 volumio go-librespot[2470]: time="2024-11-21T14:28:31+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Nov 21 14:28:31 volumio go-librespot[2470]: time="2024-11-21T14:28:31+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Nov 21 14:28:31 volumio go-librespot[2470]: time="2024-11-21T14:28:31+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Nov 21 14:28:31 volumio go-librespot[2470]: time="2024-11-21T14:28:31+09:00" level=debug msg="zeroconf server listening on port 45581" Nov 21 14:28:31 volumio go-librespot[2470]: time="2024-11-21T14:28:31+09:00" level=debug msg="obtained new client token: AABcWd8CH7+hH0RHByrkQUECRE6u2YTj2+9FnDJboeRyTkMm9U3xSIOKNan4IGsGrnv6SbvOWAoBOcUTGN9f3CJyMkpMz8/5K5V/wVQk323Pd8RolaQZYgNJQZGMowjUTSfe2T3vJBVRxwsYCRQIp+RMUZye7y2jLfLOoAvR2UNumeLXG1wb2Jezyee9/1IOwPvsntDqxYk6gKrLn4qJczHiJZa23AwxMrHcObT1DLD/qP5G/26kphSD/NpL" Nov 21 14:28:31 volumio go-librespot[2470]: time="2024-11-21T14:28:31+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:28:31 volumio go-librespot[2470]: time="2024-11-21T14:28:31+09:00" level=debug msg="completed keyexchange" Nov 21 14:28:31 volumio go-librespot[2470]: time="2024-11-21T14:28:31+09:00" level=debug msg="completed challenge" Nov 21 14:28:31 volumio go-librespot[2470]: time="2024-11-21T14:28:31+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:28:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:28:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:28:33 volumio sudo[2479]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 21 14:28:33 volumio sudo[2482]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 21 14:28:33 volumio sudo[2479]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 21 14:28:33 volumio sudo[2482]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 21 14:28:33 volumio sudo[2479]: pam_unix(sudo:session): session closed for user root Nov 21 14:28:33 volumio sudo[2482]: pam_unix(sudo:session): session closed for user root Nov 21 14:28:33 volumio volumio[817]: verbose: New Socket.io Connection to 192.168.0.4 from 192.168.0.38 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Safari/537.36 Edg/131.0.0.0 Engine version: 3 Transport: polling Total Clients: 5 Nov 21 14:28:33 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 21 14:28:33 volumio volumio[817]: info: CoreCommandRouter::volumioGetVisibleSources Nov 21 14:28:33 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 21 14:28:33 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Nov 21 14:28:33 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Nov 21 14:28:33 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 21 14:28:33 volumio volumio[817]: info: CoreCommandRouter::volumioGetQueue Nov 21 14:28:33 volumio volumio[817]: info: CoreStateMachine::getQueue Nov 21 14:28:33 volumio volumio[817]: info: CorePlayQueue::getQueue Nov 21 14:28:33 volumio volumio[817]: info: Listing playlists Nov 21 14:28:33 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 21 14:28:33 volumio volumio[817]: info: Received Get System Info Nov 21 14:28:33 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 21 14:28:33 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 21 14:28:33 volumio volumio[817]: info: Discovery: Getting this device information Nov 21 14:28:33 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Nov 21 14:28:33 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Nov 21 14:28:33 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 21 14:28:33 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Nov 21 14:28:33 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Nov 21 14:28:33 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Nov 21 14:28:33 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 21 14:28:33 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Nov 21 14:28:33 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:28:33 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:28:34 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Nov 21 14:28:35 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 21 14:28:35 volumio volumio[817]: info: Received Get System Info Nov 21 14:28:35 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 21 14:28:35 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 21 14:28:35 volumio volumio[817]: info: Discovery: Getting this device information Nov 21 14:28:35 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Nov 21 14:28:35 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Nov 21 14:28:35 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 21 14:28:35 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:28:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 64. Nov 21 14:28:35 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:28:35 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:28:35 volumio go-librespot[2487]: Librespot-go daemon starting... Nov 21 14:28:35 volumio go-librespot[2487]: time="2024-11-21T14:28:35+09:00" level=info msg="generated new device id: 09c417915b00c556a4f59e18de90d884ddc58ee8" Nov 21 14:28:35 volumio go-librespot[2487]: time="2024-11-21T14:28:35+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:28:35 volumio go-librespot[2487]: time="2024-11-21T14:28:35+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:28:35 volumio go-librespot[2487]: time="2024-11-21T14:28:35+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:28:35 volumio go-librespot[2487]: time="2024-11-21T14:28:35+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:28:35 volumio go-librespot[2487]: time="2024-11-21T14:28:35+09:00" level=debug msg="zeroconf server listening on port 45855" Nov 21 14:28:35 volumio go-librespot[2487]: time="2024-11-21T14:28:35+09:00" level=debug msg="obtained new client token: AABJISBA1dWiNvzWtnfkv03t24wfF5LkuecHD/EfnVjixyf6FeJjFiDH+sPCzd6v3mymG5JuAk2D7+AU/3bMDvMwhOzm9TB5Fjh67RoELbqIMsHiqOjvdgzfYqD8sVamScjJ+2k6r7vN/CMVvwJ0HjTvY6eYR3UFcjHZ8p4Iygx33tc4snPayeo0Uoztr0VFt7oKxwEbV0YV9CloDQRJdS4ZMX4Vi0Mz8LdMaV+Vv8Dvyy9Z5NbDz3K5++y1nks=" Nov 21 14:28:35 volumio go-librespot[2487]: time="2024-11-21T14:28:35+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:28:35 volumio go-librespot[2487]: time="2024-11-21T14:28:35+09:00" level=debug msg="completed keyexchange" Nov 21 14:28:36 volumio go-librespot[2487]: time="2024-11-21T14:28:36+09:00" level=debug msg="completed challenge" Nov 21 14:28:36 volumio go-librespot[2487]: time="2024-11-21T14:28:36+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:28:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:28:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:28:36 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Nov 21 14:28:36 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Nov 21 14:28:36 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:28:36 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:28:36 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 21 14:28:36 volumio volumio[817]: info: Received Get System Info Nov 21 14:28:36 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 21 14:28:36 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 21 14:28:36 volumio volumio[817]: info: Discovery: Getting this device information Nov 21 14:28:36 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Nov 21 14:28:36 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Nov 21 14:28:36 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 21 14:28:37 volumio volumio[817]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 21 14:28:37 volumio volumio[817]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 21 14:28:37 volumio volumio[817]: info: Retrieving Cloud Streaming UI Nov 21 14:28:37 volumio volumio[817]: info: Getting Tidal Cloud Configuration Nov 21 14:28:37 volumio volumio[817]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 21 14:28:37 volumio volumio[817]: info: Getting Qobuz Cloud Configuration Nov 21 14:28:37 volumio volumio[817]: info: Asking plugin for UI Config Nov 21 14:28:37 volumio volumio[817]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 21 14:28:37 volumio volumio[817]: info: Getting Spotify Cloud Configuration Nov 21 14:28:37 volumio volumio[817]: info: Asking plugin for UI Config Nov 21 14:28:37 volumio volumio[817]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 21 14:28:37 volumio volumio[817]: info: Saving Spotify Acccount Nov 21 14:28:37 volumio volumio[817]: info: Got Tidal Cloud Configuration Nov 21 14:28:37 volumio volumio[817]: info: Got it Nov 21 14:28:37 volumio volumio[817]: info: Got it Nov 21 14:28:37 volumio volumio[817]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Nov 21 14:28:37 volumio volumio[817]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 21 14:28:37 volumio volumio[817]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Nov 21 14:28:37 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 21 14:28:37 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Nov 21 14:28:37 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 21 14:28:37 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 21 14:28:37 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 21 14:28:37 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 21 14:28:37 volumio volumio[817]: info: CoreCommandRouter::volumioGetBrowseSources Nov 21 14:28:37 volumio volumio[817]: info: CoreCommandRouter::volumioGetBrowseSources Nov 21 14:28:37 volumio volumio[817]: info: CoreCommandRouter::volumioGetBrowseSources Nov 21 14:28:37 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 21 14:28:37 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Nov 21 14:28:39 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:28:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 65. Nov 21 14:28:39 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:28:39 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:28:39 volumio go-librespot[2551]: Librespot-go daemon starting... Nov 21 14:28:39 volumio go-librespot[2551]: time="2024-11-21T14:28:39+09:00" level=info msg="generated new device id: 59f3e8c0e4bd215e8f0665851d23e9f519fda334" Nov 21 14:28:39 volumio go-librespot[2551]: time="2024-11-21T14:28:39+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:28:39 volumio go-librespot[2551]: time="2024-11-21T14:28:39+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Nov 21 14:28:39 volumio go-librespot[2551]: time="2024-11-21T14:28:39+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Nov 21 14:28:39 volumio go-librespot[2551]: time="2024-11-21T14:28:39+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Nov 21 14:28:39 volumio go-librespot[2551]: time="2024-11-21T14:28:39+09:00" level=debug msg="zeroconf server listening on port 45423" Nov 21 14:28:39 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:28:39 volumio go-librespot[2551]: time="2024-11-21T14:28:39+09:00" level=debug msg="new websocket client" Nov 21 14:28:39 volumio volumio[817]: info: Connection to go-librespot Websocket established Nov 21 14:28:39 volumio go-librespot[2551]: time="2024-11-21T14:28:39+09:00" level=debug msg="obtained new client token: AABrzXx6T/5Kjadsok9wX29lDNIgxwzME+t5YDIu6hJQIi7vKRhHVwGN16pAjVHFTjWr34PYu86vrHW12emJ+s3Fn5Pm7j3CiQTlVMQRApDLWi4G8MLi3JOOUkbrQoY1Dlt4Ncf6DX5KAMCliM+JaWVmDUOr+uZ+CSilbiwaDNcMmyp2qHDQj41Vg6fEqFdqKcbonqVOlLg+Y88XCFvlglUZ/xSHhiwkDm3urfii2+RYYJ2RJCvLh0fz8GZZCTI=" Nov 21 14:28:39 volumio go-librespot[2551]: time="2024-11-21T14:28:39+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:28:39 volumio go-librespot[2551]: time="2024-11-21T14:28:39+09:00" level=debug msg="completed keyexchange" Nov 21 14:28:40 volumio go-librespot[2551]: time="2024-11-21T14:28:40+09:00" level=debug msg="completed challenge" Nov 21 14:28:40 volumio go-librespot[2551]: time="2024-11-21T14:28:40+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:28:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:28:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:28:40 volumio volumio[817]: info: Connection to go-librespot Websocket closed Nov 21 14:28:41 volumio volumio[817]: info: Disabling MyMusic plugin upnp_browser Nov 21 14:28:41 volumio volumio[817]: info: CoreCommandRouter::volumioRemoveToBrowseSources미디어 서버 Nov 21 14:28:41 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 21 14:28:41 volumio volumio[817]: Cannot find translation for source YouTube2 Nov 21 14:28:41 volumio volumio[817]: Cannot find translation for source YouTube Music Nov 21 14:28:41 volumio volumio[817]: Cannot find translation for source Mother Earth Radio Nov 21 14:28:41 volumio volumio[817]: info: Disabling plugin upnp_browser Nov 21 14:28:41 volumio volumio[817]: info: Done. Nov 21 14:28:41 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 21 14:28:42 volumio volumio[817]: info: Getting Spotify volume Nov 21 14:28:42 volumio volumio[817]: (node:817) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:28:42 volumio volumio[817]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 21 14:28:42 volumio volumio[817]: (node:817) 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: 22) Nov 21 14:28:42 volumio volumio[817]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Nov 21 14:28:42 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Nov 21 14:28:42 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Nov 21 14:28:43 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Nov 21 14:28:43 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:28:43 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:28:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:28:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 66. Nov 21 14:28:43 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:28:43 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:28:43 volumio go-librespot[2564]: Librespot-go daemon starting... Nov 21 14:28:43 volumio go-librespot[2564]: time="2024-11-21T14:28:43+09:00" level=info msg="generated new device id: 7c5f8af41f925ce45157704b54f535f1a9f6c698" Nov 21 14:28:43 volumio go-librespot[2564]: time="2024-11-21T14:28:43+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:28:43 volumio go-librespot[2564]: time="2024-11-21T14:28:43+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:28:43 volumio go-librespot[2564]: time="2024-11-21T14:28:43+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:28:43 volumio go-librespot[2564]: time="2024-11-21T14:28:43+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:28:43 volumio go-librespot[2564]: time="2024-11-21T14:28:43+09:00" level=debug msg="zeroconf server listening on port 35613" Nov 21 14:28:43 volumio go-librespot[2564]: time="2024-11-21T14:28:43+09:00" level=debug msg="obtained new client token: AAC5mLxto8payTSlmm1xLWr+fanTnHHNY2jcNRSMs9FhTp1DY2OEXGfVeEcLV3eHh6FHz5gI76UbRTeUS6IxDBTCureLCINolnSjPdYECf66R8bdyui0QiEtbIe/TmgaproI84DiTCt59EYKcYONKV+N0mOvB2gvWdF+LAQC1AkAkvvjcyNGfG2QH/xYso243WkIEcHPi8BwcQfpgNQR7jPl3HsNMQSvH6dASjW8WcNvNqfYDa3VoHSAYGn84SQ=" Nov 21 14:28:44 volumio go-librespot[2564]: time="2024-11-21T14:28:44+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070 (error: dial tcp 104.199.241.202:4070: connect: connection refused), retrying with a different AP" Nov 21 14:28:44 volumio go-librespot[2564]: time="2024-11-21T14:28:44+09:00" level=info msg="connected to ap-gae2.spotify.com:443" Nov 21 14:28:44 volumio go-librespot[2564]: time="2024-11-21T14:28:44+09:00" level=debug msg="completed keyexchange" Nov 21 14:28:45 volumio go-librespot[2564]: time="2024-11-21T14:28:45+09:00" level=debug msg="completed challenge" Nov 21 14:28:45 volumio go-librespot[2564]: time="2024-11-21T14:28:45+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:28:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:28:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:28:45 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 21 14:28:46 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:28:46 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:28:47 volumio volumio[817]: info: Enabling MyMusic plugin upnp_browser Nov 21 14:28:47 volumio volumio[817]: info: Enabling plugin upnp_browser Nov 21 14:28:47 volumio volumio[817]: info: Loading plugin "upnp_browser"... Nov 21 14:28:47 volumio volumio[817]: info: PLUGIN START: upnp_browser Nov 21 14:28:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 21 14:28:47 volumio volumio[817]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 21 14:28:47 volumio volumio[817]: info: [1732166927050] CoreMusicLibrary::Adding element 미디어 서버 Nov 21 14:28:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 21 14:28:47 volumio volumio[817]: Cannot find translation for source YouTube2 Nov 21 14:28:47 volumio volumio[817]: Cannot find translation for source YouTube Music Nov 21 14:28:47 volumio volumio[817]: Cannot find translation for source Mother Earth Radio Nov 21 14:28:47 volumio volumio[817]: info: Done. Nov 21 14:28:47 volumio volumio[817]: info: Disabling MyMusic plugin airplay_emulation Nov 21 14:28:47 volumio volumio[817]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesShairport-Sync Nov 21 14:28:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 21 14:28:47 volumio volumio[817]: Cannot find translation for source YouTube2 Nov 21 14:28:47 volumio volumio[817]: Cannot find translation for source YouTube Music Nov 21 14:28:47 volumio volumio[817]: Cannot find translation for source Mother Earth Radio Nov 21 14:28:47 volumio volumio[817]: info: Disabling plugin airplay_emulation Nov 21 14:28:47 volumio volumio[817]: info: Done. Nov 21 14:28:47 volumio sudo[2588]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop shairport-sync Nov 21 14:28:47 volumio sudo[2588]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 21 14:28:47 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 21 14:28:47 volumio systemd[1]: shairport-sync.service: Succeeded. Nov 21 14:28:47 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 21 14:28:47 volumio sudo[2588]: pam_unix(sudo:session): session closed for user root Nov 21 14:28:47 volumio volumio[817]: info: Shairport-Sync Stopped Nov 21 14:28:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:28:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 67. Nov 21 14:28:48 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:28:48 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:28:48 volumio go-librespot[2590]: Librespot-go daemon starting... Nov 21 14:28:48 volumio go-librespot[2590]: time="2024-11-21T14:28:48+09:00" level=info msg="generated new device id: e04eaead80b659d57676efc29178a525d54c8881" Nov 21 14:28:48 volumio go-librespot[2590]: time="2024-11-21T14:28:48+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:28:48 volumio go-librespot[2590]: time="2024-11-21T14:28:48+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:28:48 volumio go-librespot[2590]: time="2024-11-21T14:28:48+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:28:48 volumio go-librespot[2590]: time="2024-11-21T14:28:48+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:28:48 volumio go-librespot[2590]: time="2024-11-21T14:28:48+09:00" level=debug msg="zeroconf server listening on port 41993" Nov 21 14:28:48 volumio go-librespot[2590]: time="2024-11-21T14:28:48+09:00" level=debug msg="obtained new client token: AAA9I4nGMrwGgYvkoWKxFGdkJ57FX8W/mC6pmrB3hjAzAzp08+g5zm3J7MnqLUWiRLlm9Wmd+Bmv1S6SLNluKI85V7kQR8KUCF/VKrqoxtdYcHupe8dbnas4sLnVJe2NZT3GJsuc+w50XrBviHQlrGE/jCvVLEgnkoa/PAv5x7+KeVUMy+An4jySDPswo9g4aBljw93FgXpQ4O47S7vdDd2p+HzMYKSlQawfbZh++1S95KLp6hAtmXI6GqK7oPM=" Nov 21 14:28:49 volumio volumio[817]: info: Enabling MyMusic plugin airplay_emulation Nov 21 14:28:49 volumio volumio[817]: info: Enabling plugin airplay_emulation Nov 21 14:28:49 volumio volumio[817]: info: Loading plugin "airplay_emulation"... Nov 21 14:28:49 volumio volumio[817]: info: Starting Shairport Sync Nov 21 14:28:49 volumio volumio[817]: info: PLUGIN START: airplay_emulation Nov 21 14:28:49 volumio go-librespot[2590]: time="2024-11-21T14:28:49+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:28:49 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 21 14:28:49 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 21 14:28:49 volumio go-librespot[2590]: time="2024-11-21T14:28:49+09:00" level=debug msg="completed keyexchange" Nov 21 14:28:49 volumio volumio[817]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 21 14:28:49 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 21 14:28:49 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 21 14:28:49 volumio volumio[817]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 21 14:28:49 volumio volumio[817]: info: Done. Nov 21 14:28:49 volumio volumio[817]: info: Starting Shairport Sync Nov 21 14:28:49 volumio volumio[817]: info: Starting Shairport Sync Nov 21 14:28:49 volumio sudo[2605]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 21 14:28:49 volumio sudo[2605]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 21 14:28:49 volumio sudo[2608]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 21 14:28:49 volumio sudo[2608]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 21 14:28:49 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 21 14:28:49 volumio sudo[2605]: pam_unix(sudo:session): session closed for user root Nov 21 14:28:49 volumio volumio[817]: info: Shairport-Sync Started Nov 21 14:28:49 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 21 14:28:49 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Nov 21 14:28:49 volumio systemd[1]: shairport-sync.service: Succeeded. Nov 21 14:28:49 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 21 14:28:49 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 21 14:28:49 volumio sudo[2608]: pam_unix(sudo:session): session closed for user root Nov 21 14:28:49 volumio volumio[817]: info: Shairport-Sync Started Nov 21 14:28:49 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:28:49 volumio go-librespot[2590]: time="2024-11-21T14:28:49+09:00" level=debug msg="new websocket client" Nov 21 14:28:49 volumio volumio[817]: info: Connection to go-librespot Websocket established Nov 21 14:28:49 volumio go-librespot[2590]: time="2024-11-21T14:28:49+09:00" level=debug msg="completed challenge" Nov 21 14:28:49 volumio go-librespot[2590]: time="2024-11-21T14:28:49+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 14:28:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 14:28:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 14:28:49 volumio volumio[817]: info: Connection to go-librespot Websocket closed Nov 21 14:28:49 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 21 14:28:50 volumio volumio[817]: info: Disabling MyMusic plugin upnp Nov 21 14:28:51 volumio sudo[2615]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Nov 21 14:28:51 volumio sudo[2615]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 21 14:28:51 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Nov 21 14:28:51 volumio volumio[817]: error: Upnp client error: Error: This socket has been ended by the other party Nov 21 14:28:51 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 21 14:28:51 volumio volumio[817]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Nov 21 14:28:51 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Nov 21 14:28:51 volumio volumio[817]: info: Received Get System Version Nov 21 14:28:51 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 21 14:28:51 volumio volumio[817]: info: Received Get System Info Nov 21 14:28:51 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 21 14:28:51 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 21 14:28:51 volumio volumio[817]: info: Discovery: Getting this device information Nov 21 14:28:51 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Nov 21 14:28:51 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Nov 21 14:28:51 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 21 14:28:52 volumio volumio[817]: info: Getting Spotify volume Nov 21 14:28:52 volumio volumio[817]: (node:817) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:28:52 volumio volumio[817]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 21 14:28:52 volumio volumio[817]: (node:817) 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: 23) Nov 21 14:28:52 volumio volumio[817]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Nov 21 14:28:52 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Nov 21 14:28:52 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Nov 21 14:28:52 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Nov 21 14:28:52 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 14:28:52 volumio volumio[817]: info: Enabling MyMusic plugin upnp Nov 21 14:28:52 volumio volumio[817]: info: Enabling plugin upnp Nov 21 14:28:52 volumio volumio[817]: info: Loading plugin "upnp"... Nov 21 14:28:52 volumio volumio[817]: info: [1732166932740] Starting Upmpd Daemon Nov 21 14:28:52 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 21 14:28:52 volumio volumio[817]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 21 14:28:52 volumio volumio[817]: Error: listen EADDRINUSE: address already in use :::6599 Nov 21 14:28:52 volumio volumio[817]: at Server.setupListenHandle [as _listen2] (net.js:1318:16) Nov 21 14:28:52 volumio volumio[817]: at listenInCluster (net.js:1366:12) Nov 21 14:28:52 volumio volumio[817]: at Server.listen (net.js:1452:7) Nov 21 14:28:52 volumio volumio[817]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Nov 21 14:28:52 volumio volumio[817]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Nov 21 14:28:52 volumio volumio[817]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Nov 21 14:28:52 volumio volumio[817]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Nov 21 14:28:52 volumio volumio[817]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Nov 21 14:28:52 volumio volumio[817]: code: 'EADDRINUSE', Nov 21 14:28:52 volumio volumio[817]: errno: -98, Nov 21 14:28:52 volumio volumio[817]: syscall: 'listen', Nov 21 14:28:52 volumio volumio[817]: address: '::', Nov 21 14:28:52 volumio volumio[817]: port: 6599 Nov 21 14:28:52 volumio volumio[817]: } Nov 21 14:28:52 volumio volumio[817]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 21 14:28:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 14:28:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 68. Nov 21 14:28:52 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 14:28:52 volumio systemd[1]: Started go-librespot Daemon. Nov 21 14:28:52 volumio go-librespot[2624]: Librespot-go daemon starting... Nov 21 14:28:52 volumio go-librespot[2624]: time="2024-11-21T14:28:52+09:00" level=info msg="generated new device id: e6850e4d09a366441759fe9a369a45c12813d6a1" Nov 21 14:28:52 volumio go-librespot[2624]: time="2024-11-21T14:28:52+09:00" level=debug msg="stored credentials found for 31cfgj6ozcovh3gr5a4ax4w2kvhe" Nov 21 14:28:53 volumio go-librespot[2624]: time="2024-11-21T14:28:53+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 14:28:53 volumio go-librespot[2624]: time="2024-11-21T14:28:53+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 21 14:28:53 volumio go-librespot[2624]: time="2024-11-21T14:28:53+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 21 14:28:53 volumio go-librespot[2624]: time="2024-11-21T14:28:53+09:00" level=debug msg="zeroconf server listening on port 34305" Nov 21 14:28:53 volumio go-librespot[2624]: time="2024-11-21T14:28:53+09:00" level=debug msg="obtained new client token: AACl63WkSXW1BcwP2j4LW1Pwkobzo9W63Bj5yGFBQvxcmmiWlJvG6+JofUDcK6Be9XdMmYMMKh9fx+YesGYZ0vQQCbt66q3GVi20BWozS2c3gvpwpjLhcHmK64QKE8Xwj2POZW7bGPhF508g+5LYxKwoZWlk/GSOaf2wDoBt4hQsKGZegPZdkUOd8snL4wnXV2BdvCZZLQM8hd+3aTJ6JADPWzvTwfdPbthG92Wj1LJBozgKKmyOGkDZLOqs" Nov 21 14:28:53 volumio go-librespot[2624]: time="2024-11-21T14:28:53+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 21 14:28:53 volumio go-librespot[2624]: time="2024-11-21T14:28:53+09:00" level=debug msg="completed keyexchange" Nov 21 14:28:53 volumio sudo[2638]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-21 14:27 Nov 21 14:28:53 volumio sudo[2638]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"