-- Logs begin at Wed 2024-08-28 01:49:01 CDT, end at Wed 2024-08-28 03:45:35 CDT. -- Aug 28 03:44:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:44:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4635. Aug 28 03:44:00 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:44:00 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:44:00 volumio go-librespot[24878]: Librespot-go daemon starting... Aug 28 03:44:00 volumio volumio[4187]: info: CorePlayQueue::getTrack 30 Aug 28 03:44:00 volumio volumio[4187]: info: CorePlayQueue::getTrack 31 Aug 28 03:44:00 volumio volumio[4187]: info: Prefetching next song Aug 28 03:44:00 volumio go-librespot[24878]: time="2024-08-28T03:44:00-05:00" level=info msg="generated new device id: 429e6469d1ee647149bdd8ff900a5f69b0b14f97" Aug 28 03:44:00 volumio go-librespot[24878]: time="2024-08-28T03:44:00-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:44:00 volumio go-librespot[24878]: time="2024-08-28T03:44:00-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 03:44:00 volumio go-librespot[24878]: time="2024-08-28T03:44:00-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 03:44:00 volumio go-librespot[24878]: time="2024-08-28T03:44:00-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 03:44:00 volumio go-librespot[24878]: time="2024-08-28T03:44:00-05:00" level=debug msg="zeroconf server listening on port 43213" Aug 28 03:44:00 volumio go-librespot[24878]: time="2024-08-28T03:44:00-05:00" level=debug msg="obtained new client token: AAC25qYolE2lXf/fanR1FMENRZiRDCUUMAQBq4ihDbgX1PWyiqjmDzrwoeyEmCS7/lCWCSTKf4YFeUo71pJ59jchc01mHxWjt2V2P8iWymmPukXEAnrqe1aQiQzEYxvKgcd3cmYQojgHAm95CSfGvS+VTIFGxbqAoQREqmo+zGswm1hsjy2i1Kas2p3hNrY984kP662Kw3Do14TwLW8XxmJukVVzydq4DW5NHcavnUJf8aT7sYcTbeL/ew==" Aug 28 03:44:00 volumio go-librespot[24878]: time="2024-08-28T03:44:00-05:00" level=debug msg="completed keyexchange" Aug 28 03:44:01 volumio volumio[4187]: verbose: ControllerMpd::sendMpdCommand addid "https://rr3---sn-q4fl6nsr.googlevideo.com/videoplayback?expire=1724856240&ei=UOPOZpuxL-_sir4PxtOF-AU&ip=99.11.117.23&id=o-AIr4CGB5j5k9RwZNThD2fgpGRFwxGy6gP92XBX4gkhTA&itag=774&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&mh=HG&mm=31%2C26&mn=sn-q4fl6nsr%2Csn-5ualdnls&ms=au%2Conr&mv=m&mvi=3&pl=18&ctier=A&pfa=5&gcr=us&initcwndbps=991250&hightc=yes&siu=1&bui=AQmm2eyMOOFScENHUyF_cmpj2y1LGpQVA5_MnSGTRqyU8m4hmf_QHBIUSTXCyyE3InrslLDDDA&spc=Mv1m9rMqtMFNxG550rS1y4vMS8LvZimYq12Ay6GF8XJbtWo38xllpkfqaedFuI0&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=WrvCT2SGOl_xI7Tum-ar-xEQ&rqh=1&gir=yes&clen=6144978&dur=179.421&lmt=1714628206824502&mt=1724834450&fvip=5&keepalive=yes&c=WEB_REMIX&sefc=1&txp=2318224&n=Ri4Ot8iyz0CIrg&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cctier%2Cpfa%2Cgcr%2Chightc%2Csiu%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=mh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Cinitcwndbps&lsig=AGtxev0wRgIhAP0ZHvlfgV2OqxIR3ZIY1HTXYylwf6WDc0ZR5PuiahgKAiEArw9m3zAL5c385X_Xu0ZDkjTB56zLz8dEgkbb8X-zHYY%3D&sig=AJfQdSswRQIgMQUjHyLrwSDV2cewyghwnlnwL_zxtYPn1xdtuP2uADMCIQD3qmmp9e8x12WpkNZCW59qoiXze1IX60o9QN6cy9gCRg%3D%3D&cver=1.20211213.00.00&t.YouTube" Aug 28 03:44:01 volumio volumio[4187]: info: Aug 28 03:44:01 volumio volumio[4187]: ---------------------------- MPD announces system playlist update Aug 28 03:44:01 volumio volumio[4187]: info: Ignoring MPD Status Update Aug 28 03:44:01 volumio volumio[4187]: info: sendMpdCommand addid "https://rr3---sn-q4fl6nsr.googlevideo.com/videoplayback?expire=1724856240&ei=UOPOZpuxL-_sir4PxtOF-AU&ip=99.11.117.23&id=o-AIr4CGB5j5k9RwZNThD2fgpGRFwxGy6gP92XBX4gkhTA&itag=774&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&mh=HG&mm=31%2C26&mn=sn-q4fl6nsr%2Csn-5ualdnls&ms=au%2Conr&mv=m&mvi=3&pl=18&ctier=A&pfa=5&gcr=us&initcwndbps=991250&hightc=yes&siu=1&bui=AQmm2eyMOOFScENHUyF_cmpj2y1LGpQVA5_MnSGTRqyU8m4hmf_QHBIUSTXCyyE3InrslLDDDA&spc=Mv1m9rMqtMFNxG550rS1y4vMS8LvZimYq12Ay6GF8XJbtWo38xllpkfqaedFuI0&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=WrvCT2SGOl_xI7Tum-ar-xEQ&rqh=1&gir=yes&clen=6144978&dur=179.421&lmt=1714628206824502&mt=1724834450&fvip=5&keepalive=yes&c=WEB_REMIX&sefc=1&txp=2318224&n=Ri4Ot8iyz0CIrg&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cctier%2Cpfa%2Cgcr%2Chightc%2Csiu%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=mh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Cinitcwndbps&lsig=AGtxev0wRgIhAP0ZHvlfgV2OqxIR3ZIY1HTXYylwf6WDc0ZR5PuiahgKAiEArw9m3zAL5c385X_Xu0ZDkjTB56zLz8dEgkbb8X-zHYY%3D&sig=AJfQdSswRQIgMQUjHyLrwSDV2cewyghwnlnwL_zxtYPn1xdtuP2uADMCIQD3qmmp9e8x12WpkNZCW59qoiXze1IX60o9QN6cy9gCRg%3D%3D&cver=1.20211213.00.00&t.YouTube" took 1 milliseconds Aug 28 03:44:01 volumio volumio[4187]: verbose: MPD COMMAND [object Object] Aug 28 03:44:01 volumio volumio[4187]: verbose: MPD COMMAND [object Object] Aug 28 03:44:01 volumio volumio[4187]: info: Aug 28 03:44:01 volumio volumio[4187]: ---------------------------- MPD announces system playlist update Aug 28 03:44:01 volumio volumio[4187]: info: Ignoring MPD Status Update Aug 28 03:44:01 volumio volumio[4187]: info: ------------------------------ 1ms Aug 28 03:44:01 volumio volumio[4187]: info: [ytmusic-play] Prefetched and added track to MPD queue: Ocean (Bonus Track) (feat. Eden Nash) Aug 28 03:44:01 volumio volumio[4187]: verbose: ControllerMpd::sendMpdCommand consume 1 Aug 28 03:44:01 volumio volumio[4187]: info: ------------------------------ 1ms Aug 28 03:44:01 volumio volumio[4187]: info: sendMpdCommand consume 1 took 1 milliseconds Aug 28 03:44:01 volumio go-librespot[24878]: time="2024-08-28T03:44:01-05:00" level=debug msg="completed challenge" Aug 28 03:44:01 volumio go-librespot[24878]: time="2024-08-28T03:44:01-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:44:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:44:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:44:01 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:01 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:44:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4636. Aug 28 03:44:04 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:44:04 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:04 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:04 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:44:04 volumio go-librespot[24886]: Librespot-go daemon starting... Aug 28 03:44:04 volumio go-librespot[24886]: time="2024-08-28T03:44:04-05:00" level=info msg="generated new device id: b5457634719dbaef7b59971158d0708de471d37e" Aug 28 03:44:04 volumio go-librespot[24886]: time="2024-08-28T03:44:04-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:44:04 volumio go-librespot[24886]: time="2024-08-28T03:44:04-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 03:44:04 volumio go-librespot[24886]: time="2024-08-28T03:44:04-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 03:44:04 volumio go-librespot[24886]: time="2024-08-28T03:44:04-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 03:44:04 volumio go-librespot[24886]: time="2024-08-28T03:44:04-05:00" level=debug msg="zeroconf server listening on port 37909" Aug 28 03:44:04 volumio go-librespot[24886]: time="2024-08-28T03:44:04-05:00" level=debug msg="obtained new client token: AACcipDo3jW+6v1ygS3ByhOMnMQtQFo5MBrwoIw0PboQSbDxYeqqRcxNYZxbOnbDgFOen63lguxXp3fFQVtN/WB7A1I+BT/ZXkSLS2+yqubw8lAl+2iqpDl3PohMhSEyVl4XVTRJ5BGaN37FR66VqiSAOuGgSzkbvG3o+MLybXXxsAaKJ840a5yGmbLGAI69HOkOTI7hFkD2DwC2NAyADSQhHYHbds6hNymM9fFoPi9TB9K6dL/fT4ALhg==" Aug 28 03:44:04 volumio go-librespot[24886]: time="2024-08-28T03:44:04-05:00" level=debug msg="completed keyexchange" Aug 28 03:44:05 volumio volumio[4187]: info: CoreStateMachine::startPlaybackTimer Aug 28 03:44:05 volumio volumio[4187]: info: CorePlayQueue::getTrack 31 Aug 28 03:44:05 volumio go-librespot[24886]: time="2024-08-28T03:44:05-05:00" level=debug msg="completed challenge" Aug 28 03:44:05 volumio go-librespot[24886]: time="2024-08-28T03:44:05-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:44:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:44:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:44:05 volumio volumio[4187]: info: CoreStateMachine::pushState Aug 28 03:44:05 volumio volumio[4187]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 28 03:44:05 volumio volumio[4187]: info: CoreCommandRouter::volumioPushState Aug 28 03:44:05 volumio volumio[4187]: info: CorePlayQueue::getTrack 31 Aug 28 03:44:05 volumio volumio[4187]: info: ControllerMpd::getState Aug 28 03:44:05 volumio volumio[4187]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:44:05 volumio volumio[4187]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Aug 28 03:44:05 volumio volumio[4187]: info: sendMpdCommand status took 3 milliseconds Aug 28 03:44:05 volumio volumio[4187]: verbose: ControllerMpd::parseState Aug 28 03:44:05 volumio volumio[4187]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 28 03:44:05 volumio volumio[4187]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 28 03:44:05 volumio volumio[4187]: verbose: ControllerMpd::parseTrackInfo Aug 28 03:44:05 volumio volumio[4187]: info: ControllerMpd::pushState Aug 28 03:44:05 volumio volumio[4187]: info: CoreCommandRouter::servicePushState Aug 28 03:44:05 volumio volumio[4187]: info: CorePlayQueue::getTrack 31 Aug 28 03:44:05 volumio volumio[4187]: verbose: STATE SERVICE {"status":"play","position":0,"seek":186155,"duration":208,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Money Game","artist":"Ren","album":"Money Game","uri":"https://rr2---sn-q4fzen7y.googlevideo.com/videoplayback?expire=1724856033&ei=geLOZuCOA76GybgP38CX2A0&ip=99.11.117.23&id=o-ALW2QkH778_1g2kRTMctheJz4IbLHsigH2z1DhqLChCr&itag=774&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&mh=31&mm=31%2C29&mn=sn-q4fzen7y%2Csn-q4fl6nsk&ms=au%2Crdu&mv=m&mvi=2&pl=18&ctier=A&pfa=5&gcr=us&initcwndbps=942500&hightc=yes&siu=1&bui=AQmm2ew9pg0FopWHl0A1EYI7cHxwNtTj_PsBCmAJ5emKzyW7W49CTS3NQXSiwUvTi-mZ_awNJw&spc=Mv1m9n33y9gSGlJYoDVj7x8WOmCsz51ONQzYV1DLjkgstnbNvzG5btf8hv0frcg&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=lZlPoqrR2DiB81R3eki7IwIQ&rqh=1&gir=yes&clen=7386178&dur=208.101&lmt=1714673238889147&mt=1724833970&fvip=3&keepalive=yes&c=WEB_REMIX&sefc=1&txp=2318224&n=TCJVI2_P9GiBiQ&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cctier%2Cpfa%2Cgcr%2Chightc%2Csiu%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=mh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Cinitcwndbps&lsig=AGtxev0wRAIgWWRa5VPSbPyHCqpx_SsyNY4cYmcoPiX56NCRSXQwq5sCIEtlziRG44-xAVugEpDNgHozrxbKcIfqRdEMGfjGZ2XS&sig=AJfQdSswRQIhAIuxtHPdgzSInjkU_oN_gx01jbSGYSNsvT7QlqCRT-zkAiA9kI9JC0Su-ALrCGW7MgJC5e5xSrO_0PgD8BIm6SCKXA%3D%3D&cver=1.20211213.00.00&t.YouTube","trackType":"YouTube"} Aug 28 03:44:05 volumio volumio[4187]: verbose: CURRENT POSITION 31 Aug 28 03:44:05 volumio volumio[4187]: info: CoreStateMachine::syncState stateService play Aug 28 03:44:05 volumio volumio[4187]: info: CoreStateMachine::syncState currentStatus play Aug 28 03:44:05 volumio volumio[4187]: info: Received an update from plugin. extracting info from payload Aug 28 03:44:05 volumio volumio[4187]: info: CoreStateMachine::pushState Aug 28 03:44:05 volumio volumio[4187]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 28 03:44:05 volumio volumio[4187]: info: CoreCommandRouter::volumioPushState Aug 28 03:44:05 volumio volumio[4187]: info: CoreStateMachine::pushState Aug 28 03:44:05 volumio volumio[4187]: info: CoreCommandRouter::volumioPushState Aug 28 03:44:05 volumio volumio[4187]: info: [LastFM] Current track has sufficient metadata: title (Ocean (Bonus Track) (feat. Eden Nash)) and artist (Ren) passed on explicitly Aug 28 03:44:05 volumio volumio[4187]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Aug 28 03:44:05 volumio volumio[4187]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Aug 28 03:44:05 volumio volumio[4187]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Ocean (Bonus Track) (feat. Eden Nash)","url":"https://www.last.fm/music/Ren/_/Ocean+(Bonus+Track)+(feat.+Eden+Nash)","duration":"0","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"135","playcount":"396","artist":{"name":"Ren","mbid":"dd43c3fc-8079-4815-b240-a2aa75feaeff","url":"https://www.last.fm/music/Ren"},"userplaycount":"1","userloved":"0","toptags":""}} Aug 28 03:44:07 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:07 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:44:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4637. Aug 28 03:44:08 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:44:08 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:44:08 volumio go-librespot[24895]: Librespot-go daemon starting... Aug 28 03:44:08 volumio go-librespot[24895]: time="2024-08-28T03:44:08-05:00" level=info msg="generated new device id: a838432ba672d080971f52bfef763c1d61364194" Aug 28 03:44:08 volumio go-librespot[24895]: time="2024-08-28T03:44:08-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:44:08 volumio go-librespot[24895]: time="2024-08-28T03:44:08-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 03:44:08 volumio go-librespot[24895]: time="2024-08-28T03:44:08-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 03:44:08 volumio go-librespot[24895]: time="2024-08-28T03:44:08-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 03:44:08 volumio go-librespot[24895]: time="2024-08-28T03:44:08-05:00" level=debug msg="zeroconf server listening on port 37717" Aug 28 03:44:08 volumio go-librespot[24895]: time="2024-08-28T03:44:08-05:00" level=debug msg="obtained new client token: AABfrTRpfs5gqxUvOqznqx7mTS1DKBVDfEPiV8Hcrik0vD3svl337jj2bMjna0nKYnsXxBuq1hyzKxriLKveP8v4RJIwGWH2YdLyzkSmlHydbT/UTaB+khNl4SgaYwzeDWOLfdH1PJ2C26ghoOFxrREmX0UP9dIdq7SrFdYEQzRJKx6/vpMuL4XYfh3v7hvdqnM5DvaKuAYVCyDnCJqxufywiXbvCxCqTH0P+A/qHur6rOABMrTNhOgq0Q==" Aug 28 03:44:08 volumio go-librespot[24895]: time="2024-08-28T03:44:08-05:00" level=debug msg="completed keyexchange" Aug 28 03:44:09 volumio go-librespot[24895]: time="2024-08-28T03:44:09-05:00" level=debug msg="completed challenge" Aug 28 03:44:09 volumio go-librespot[24895]: time="2024-08-28T03:44:09-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:44:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:44:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:44:10 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:10 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:44:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4638. Aug 28 03:44:12 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:44:12 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:44:12 volumio go-librespot[24903]: Librespot-go daemon starting... Aug 28 03:44:12 volumio go-librespot[24903]: time="2024-08-28T03:44:12-05:00" level=info msg="generated new device id: 1437c252b64fc722ff5909d3bcca1c8b719eacf8" Aug 28 03:44:12 volumio go-librespot[24903]: time="2024-08-28T03:44:12-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:44:12 volumio go-librespot[24903]: time="2024-08-28T03:44:12-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 03:44:12 volumio go-librespot[24903]: time="2024-08-28T03:44:12-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 03:44:12 volumio go-librespot[24903]: time="2024-08-28T03:44:12-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 03:44:12 volumio go-librespot[24903]: time="2024-08-28T03:44:12-05:00" level=debug msg="zeroconf server listening on port 45053" Aug 28 03:44:12 volumio go-librespot[24903]: time="2024-08-28T03:44:12-05:00" level=debug msg="obtained new client token: AAB1Xa5xLwuUNNWIm/wqX0EvLEnQDbpbhzctQEg6NPj1m/OkNNIhH5s0sGjLNu031EAkG0vlXFPY6JxG8MrdP6rpgtr+0gLZWQba6NfvKvmMTQPIZUG6mSfNzei6TACdokrKjZfnfCmCv/wvA1hsbkgH8bW0AVIi9Eyu9jNtEzr7Y2ugBqrUBh3fIXjvHedQWNHSwB3WO/mFnxy7dyKwdLsYZbMhciVZodH+hVGpCRp913F/irW/d6RrAA==" Aug 28 03:44:12 volumio go-librespot[24903]: time="2024-08-28T03:44:12-05:00" level=debug msg="completed keyexchange" Aug 28 03:44:13 volumio go-librespot[24903]: time="2024-08-28T03:44:13-05:00" level=debug msg="completed challenge" Aug 28 03:44:13 volumio go-librespot[24903]: time="2024-08-28T03:44:13-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:44:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:44:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:44:13 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:13 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:44:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4639. Aug 28 03:44:16 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:44:16 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:44:16 volumio go-librespot[24911]: Librespot-go daemon starting... Aug 28 03:44:16 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:16 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:16 volumio go-librespot[24911]: time="2024-08-28T03:44:16-05:00" level=info msg="generated new device id: eeadbf6b31ea035460ff4bef8d1c56bc62b4069b" Aug 28 03:44:16 volumio go-librespot[24911]: time="2024-08-28T03:44:16-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:44:16 volumio go-librespot[24911]: time="2024-08-28T03:44:16-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 03:44:16 volumio go-librespot[24911]: time="2024-08-28T03:44:16-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 03:44:16 volumio go-librespot[24911]: time="2024-08-28T03:44:16-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 03:44:16 volumio go-librespot[24911]: time="2024-08-28T03:44:16-05:00" level=debug msg="zeroconf server listening on port 37005" Aug 28 03:44:16 volumio go-librespot[24911]: time="2024-08-28T03:44:16-05:00" level=debug msg="obtained new client token: AACIMmiEH2oZZsM+auPcbBc/9bsCYvphQzt15WqXNTQ1OdAzMiBpQrn42av3rd8fi3DJIlmp2Zi3OOnibe0QOKJS1XMyuD4OdWQSFB0vUdj2MbpmYX+M1eg2oIjJT6dgrnVI23Yx469+CH5oi4Suq1OUbWJjV61W43oNCOLxT6sC50hV2u6qtZe71HRGVodPjo9oImjPs2vydV4nJJmjPiQQ18B8sWs0Jo/qdA907R2COJHSisVaHvReHg==" Aug 28 03:44:16 volumio go-librespot[24911]: time="2024-08-28T03:44:16-05:00" level=debug msg="completed keyexchange" Aug 28 03:44:17 volumio go-librespot[24911]: time="2024-08-28T03:44:17-05:00" level=debug msg="completed challenge" Aug 28 03:44:17 volumio go-librespot[24911]: time="2024-08-28T03:44:17-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:44:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:44:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:44:19 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:19 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:44:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4640. Aug 28 03:44:20 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:44:20 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:44:20 volumio go-librespot[24919]: Librespot-go daemon starting... Aug 28 03:44:20 volumio go-librespot[24919]: time="2024-08-28T03:44:20-05:00" level=info msg="generated new device id: 911b8a676647ab5a6b6b81ec001a076768113379" Aug 28 03:44:20 volumio go-librespot[24919]: time="2024-08-28T03:44:20-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:44:20 volumio go-librespot[24919]: time="2024-08-28T03:44:20-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 03:44:20 volumio go-librespot[24919]: time="2024-08-28T03:44:20-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 03:44:20 volumio go-librespot[24919]: time="2024-08-28T03:44:20-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 03:44:20 volumio go-librespot[24919]: time="2024-08-28T03:44:20-05:00" level=debug msg="zeroconf server listening on port 32985" Aug 28 03:44:20 volumio go-librespot[24919]: time="2024-08-28T03:44:20-05:00" level=debug msg="obtained new client token: AAC87Dw7MXatxySxwK+BJa7Cj3ED71oDmihg9wDzL0gwnKA/L7sfZ2Tlk402eu4cWC8wrlhvHzJk39DoCrtvowKsBlGMpUvIOCL2hnaQUIFvc6UJ28zZ+sN9k3LdFupynXBNGKGxdDVZopN+GEWhMk7NG0dNZYqIqqLeel5XwtK616Mv6EkdURN2NJlXbO13zg+n94ogVahVNzsNLpxJZssGfkNB2KNO3o93XFn376WjaVoSCboEFo3KwA==" Aug 28 03:44:20 volumio go-librespot[24919]: time="2024-08-28T03:44:20-05:00" level=debug msg="completed keyexchange" Aug 28 03:44:21 volumio go-librespot[24919]: time="2024-08-28T03:44:21-05:00" level=debug msg="completed challenge" Aug 28 03:44:21 volumio go-librespot[24919]: time="2024-08-28T03:44:21-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:44:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:44:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:44:22 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:22 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:44:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4641. Aug 28 03:44:24 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:44:24 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:44:24 volumio go-librespot[24929]: Librespot-go daemon starting... Aug 28 03:44:24 volumio go-librespot[24929]: time="2024-08-28T03:44:24-05:00" level=info msg="generated new device id: 7c75da5d53c03ae50f18ef461a11622caff9e8d6" Aug 28 03:44:24 volumio go-librespot[24929]: time="2024-08-28T03:44:24-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:44:24 volumio go-librespot[24929]: time="2024-08-28T03:44:24-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 03:44:24 volumio go-librespot[24929]: time="2024-08-28T03:44:24-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 03:44:24 volumio go-librespot[24929]: time="2024-08-28T03:44:24-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 03:44:24 volumio go-librespot[24929]: time="2024-08-28T03:44:24-05:00" level=debug msg="zeroconf server listening on port 33301" Aug 28 03:44:24 volumio go-librespot[24929]: time="2024-08-28T03:44:24-05:00" level=debug msg="obtained new client token: AADpClN0CL4+4sfvNp3kylH+jz6xCifT7kVypRuqXUWGJM4PARb8AUjC3Vz5sRlxFdnszRBQlj9J03DCz2yANczVX2S3zEE9EZ/PecduUmIv2/MEgNp4rdHbzVoHEu5Rw6k6LS5oqBh0Rz5382lyXh5apVni2R1FG4pYT6A0rUQrQzcCPwk8vbQ+uanKlbf888LthBZkZJUfc6/4LKPHApquZUR+q+cYo0Zmd2Df3joBwyheLe4qK5mNnQ==" Aug 28 03:44:24 volumio go-librespot[24929]: time="2024-08-28T03:44:24-05:00" level=debug msg="completed keyexchange" Aug 28 03:44:25 volumio go-librespot[24929]: time="2024-08-28T03:44:25-05:00" level=debug msg="completed challenge" Aug 28 03:44:25 volumio go-librespot[24929]: time="2024-08-28T03:44:25-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:44:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:44:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:44:25 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:25 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:27 volumio volumio[4187]: info: Aug 28 03:44:27 volumio volumio[4187]: ---------------------------- MPD announces system playlist update Aug 28 03:44:27 volumio volumio[4187]: info: Ignoring MPD Status Update Aug 28 03:44:27 volumio volumio[4187]: info: Aug 28 03:44:27 volumio volumio[4187]: ---------------------------- MPD announces state update: player Aug 28 03:44:27 volumio volumio[4187]: info: ControllerMpd::getState Aug 28 03:44:27 volumio volumio[4187]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:44:27 volumio volumio[4187]: info: ------------------------------ 1ms Aug 28 03:44:27 volumio volumio[4187]: info: sendMpdCommand status took 1 milliseconds Aug 28 03:44:27 volumio volumio[4187]: verbose: ControllerMpd::parseState Aug 28 03:44:27 volumio volumio[4187]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 28 03:44:27 volumio volumio[4187]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 28 03:44:27 volumio volumio[4187]: verbose: ControllerMpd::parseTrackInfo Aug 28 03:44:27 volumio volumio[4187]: info: ControllerMpd::pushState Aug 28 03:44:27 volumio volumio[4187]: info: CoreCommandRouter::servicePushState Aug 28 03:44:27 volumio volumio[4187]: info: CorePlayQueue::getTrack 31 Aug 28 03:44:27 volumio volumio[4187]: verbose: STATE SERVICE {"status":"play","position":0,"seek":74,"duration":179,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Ocean (Bonus Track) (feat. Eden Nash)","artist":"Ren","album":"Demos (Do Not Share), Vol 1","uri":"https://rr3---sn-q4fl6nsr.googlevideo.com/videoplayback?expire=1724856240&ei=UOPOZpuxL-_sir4PxtOF-AU&ip=99.11.117.23&id=o-AIr4CGB5j5k9RwZNThD2fgpGRFwxGy6gP92XBX4gkhTA&itag=774&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&mh=HG&mm=31%2C26&mn=sn-q4fl6nsr%2Csn-5ualdnls&ms=au%2Conr&mv=m&mvi=3&pl=18&ctier=A&pfa=5&gcr=us&initcwndbps=991250&hightc=yes&siu=1&bui=AQmm2eyMOOFScENHUyF_cmpj2y1LGpQVA5_MnSGTRqyU8m4hmf_QHBIUSTXCyyE3InrslLDDDA&spc=Mv1m9rMqtMFNxG550rS1y4vMS8LvZimYq12Ay6GF8XJbtWo38xllpkfqaedFuI0&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=WrvCT2SGOl_xI7Tum-ar-xEQ&rqh=1&gir=yes&clen=6144978&dur=179.421&lmt=1714628206824502&mt=1724834450&fvip=5&keepalive=yes&c=WEB_REMIX&sefc=1&txp=2318224&n=Ri4Ot8iyz0CIrg&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cctier%2Cpfa%2Cgcr%2Chightc%2Csiu%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=mh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Cinitcwndbps&lsig=AGtxev0wRgIhAP0ZHvlfgV2OqxIR3ZIY1HTXYylwf6WDc0ZR5PuiahgKAiEArw9m3zAL5c385X_Xu0ZDkjTB56zLz8dEgkbb8X-zHYY%3D&sig=AJfQdSswRQIgMQUjHyLrwSDV2cewyghwnlnwL_zxtYPn1xdtuP2uADMCIQD3qmmp9e8x12WpkNZCW59qoiXze1IX60o9QN6cy9gCRg%3D%3D&cver=1.20211213.00.00&t.YouTube","trackType":"YouTube"} Aug 28 03:44:27 volumio volumio[4187]: verbose: CURRENT POSITION 31 Aug 28 03:44:27 volumio volumio[4187]: info: CoreStateMachine::syncState stateService play Aug 28 03:44:27 volumio volumio[4187]: info: CoreStateMachine::syncState currentStatus play Aug 28 03:44:27 volumio volumio[4187]: info: Received an update from plugin. extracting info from payload Aug 28 03:44:27 volumio volumio[4187]: info: CoreStateMachine::pushState Aug 28 03:44:27 volumio volumio[4187]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 28 03:44:27 volumio volumio[4187]: info: CoreCommandRouter::volumioPushState Aug 28 03:44:27 volumio volumio[4187]: info: CoreStateMachine::pushState Aug 28 03:44:27 volumio volumio[4187]: info: CoreCommandRouter::volumioPushState Aug 28 03:44:27 volumio volumio[4187]: info: ------------------------------ 6ms Aug 28 03:44:27 volumio volumio[4187]: info: [LastFM] updating timer, previous duration is obsolete; adding -21750 milliseconds. Aug 28 03:44:27 volumio volumio[4187]: Currently remaining: 156000 Aug 28 03:44:27 volumio volumio[4187]: -------------------------------------------------// Adding -21750 milliseconds to a total of 134250. Aug 28 03:44:27 volumio volumio[4187]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Aug 28 03:44:27 volumio volumio[4187]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Aug 28 03:44:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:44:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4642. Aug 28 03:44:28 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:44:28 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:44:28 volumio go-librespot[24976]: Librespot-go daemon starting... Aug 28 03:44:28 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:28 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:28 volumio go-librespot[24976]: time="2024-08-28T03:44:28-05:00" level=info msg="generated new device id: f2bb01b9af887936245a356905fc072649dbe749" Aug 28 03:44:28 volumio go-librespot[24976]: time="2024-08-28T03:44:28-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:44:28 volumio go-librespot[24976]: time="2024-08-28T03:44:28-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 03:44:28 volumio go-librespot[24976]: time="2024-08-28T03:44:28-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 03:44:28 volumio go-librespot[24976]: time="2024-08-28T03:44:28-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 03:44:28 volumio go-librespot[24976]: time="2024-08-28T03:44:28-05:00" level=debug msg="zeroconf server listening on port 46621" Aug 28 03:44:28 volumio go-librespot[24976]: time="2024-08-28T03:44:28-05:00" level=debug msg="obtained new client token: AADjOuC1+s6v+4+2q/NrsyJ/sjhG4cCvsZK3a2+XtEGtxbB2pAspddVg3Mx5ouSSUVN43PQtPuZhVa/v9lvTFJuSojL4ng97s259Lw6xWiR3UeDRMlpFIH9U4YKt60R12J+wnm72hpafcIaQj4qFvjPPvvEjlYBpiy8Yao0dYIac9XVVsln/RE3fBHfPHaaFjTa9BCtYPY0R6V3fAKTI5PEreGRVNmt51lsP8m+vT86ydy+LM5jekdTHvw==" Aug 28 03:44:28 volumio go-librespot[24976]: time="2024-08-28T03:44:28-05:00" level=debug msg="completed keyexchange" Aug 28 03:44:29 volumio go-librespot[24976]: time="2024-08-28T03:44:29-05:00" level=debug msg="completed challenge" Aug 28 03:44:29 volumio go-librespot[24976]: time="2024-08-28T03:44:29-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:44:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:44:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:44:31 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:31 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:44:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4643. Aug 28 03:44:32 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:44:32 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:44:32 volumio go-librespot[24984]: Librespot-go daemon starting... Aug 28 03:44:32 volumio go-librespot[24984]: time="2024-08-28T03:44:32-05:00" level=info msg="generated new device id: c4de5c4fd58add004c4f19837ef99b2cade8863c" Aug 28 03:44:32 volumio go-librespot[24984]: time="2024-08-28T03:44:32-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:44:32 volumio go-librespot[24984]: time="2024-08-28T03:44:32-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 03:44:32 volumio go-librespot[24984]: time="2024-08-28T03:44:32-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 03:44:32 volumio go-librespot[24984]: time="2024-08-28T03:44:32-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 03:44:32 volumio go-librespot[24984]: time="2024-08-28T03:44:32-05:00" level=debug msg="zeroconf server listening on port 35841" Aug 28 03:44:32 volumio go-librespot[24984]: time="2024-08-28T03:44:32-05:00" level=debug msg="obtained new client token: AAA9Ae0yG2rCbiTh3G7R466S3fn9o1ck66bxoQoVOW5SD4yAceTjYeKggvB+7OvZwp2syX/aOy1eQ3iiTeJ0PmxO0m+AtZo2lGcwKjz6b2YlwcFuDdiHNZYRenFnuZ4bsqO7IBNNArZ0xnmmcoZf3k+Oz08sJI6+ELTA9ZIhdxegMMgN9CEYd7lg9T1TaaRhYUjzajQLab7/ad5CMnpUO+OUt+Dgs9Vomne3E0swY7DcygHefUuW639bAQ==" Aug 28 03:44:32 volumio go-librespot[24984]: time="2024-08-28T03:44:32-05:00" level=debug msg="completed keyexchange" Aug 28 03:44:33 volumio go-librespot[24984]: time="2024-08-28T03:44:33-05:00" level=debug msg="completed challenge" Aug 28 03:44:33 volumio go-librespot[24984]: time="2024-08-28T03:44:33-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:44:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:44:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:44:34 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:34 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:44:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4644. Aug 28 03:44:36 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:44:36 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:44:36 volumio go-librespot[24993]: Librespot-go daemon starting... Aug 28 03:44:36 volumio go-librespot[24993]: time="2024-08-28T03:44:36-05:00" level=info msg="generated new device id: 5d2dd1d658537ac77516cbc6233aa3dc52994dc8" Aug 28 03:44:36 volumio go-librespot[24993]: time="2024-08-28T03:44:36-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:44:36 volumio go-librespot[24993]: time="2024-08-28T03:44:36-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 28 03:44:36 volumio go-librespot[24993]: time="2024-08-28T03:44:36-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 28 03:44:36 volumio go-librespot[24993]: time="2024-08-28T03:44:36-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 28 03:44:36 volumio go-librespot[24993]: time="2024-08-28T03:44:36-05:00" level=debug msg="zeroconf server listening on port 44277" Aug 28 03:44:36 volumio go-librespot[24993]: time="2024-08-28T03:44:36-05:00" level=debug msg="obtained new client token: AAD8j7UvGWOgjFBmu7LTYi2Lmu7uaq4PJEfI615+M3HXJkf6zf1671zyrDAibbMcW9Kcxr1w46uYvEg8FHfGzi6/XMFiOwuwlVvI6f7s2H0fCn7uWFA147wzki0LUyaLJBArJMuKZepg1+ww2xm9VzBxyoG/fXwG4aPXOkpsDBhX2WpC/JmRcsR1K1kyPI+mdxt9gFIQwd6IKZUsnWmLah+dy0ELKQ9WAeGkuyrO2kjntF8S70xhds+RCg==" Aug 28 03:44:36 volumio go-librespot[24993]: time="2024-08-28T03:44:36-05:00" level=debug msg="completed keyexchange" Aug 28 03:44:37 volumio go-librespot[24993]: time="2024-08-28T03:44:37-05:00" level=debug msg="completed challenge" Aug 28 03:44:37 volumio go-librespot[24993]: time="2024-08-28T03:44:37-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:44:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:44:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:44:37 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:37 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:44:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4645. Aug 28 03:44:40 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:44:40 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:44:40 volumio go-librespot[25001]: Librespot-go daemon starting... Aug 28 03:44:40 volumio go-librespot[25001]: time="2024-08-28T03:44:40-05:00" level=info msg="generated new device id: cb5bc2c52478c7450bc2c168ab8250f8408843c8" Aug 28 03:44:40 volumio go-librespot[25001]: time="2024-08-28T03:44:40-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:44:40 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:40 volumio go-librespot[25001]: time="2024-08-28T03:44:40-05:00" level=debug msg="new websocket client" Aug 28 03:44:40 volumio volumio[4187]: info: Connection to go-librespot Websocket established Aug 28 03:44:40 volumio go-librespot[25001]: time="2024-08-28T03:44:40-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 03:44:40 volumio go-librespot[25001]: time="2024-08-28T03:44:40-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 03:44:40 volumio go-librespot[25001]: time="2024-08-28T03:44:40-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 03:44:40 volumio go-librespot[25001]: time="2024-08-28T03:44:40-05:00" level=debug msg="zeroconf server listening on port 43299" Aug 28 03:44:40 volumio go-librespot[25001]: time="2024-08-28T03:44:40-05:00" level=debug msg="obtained new client token: AAAD0GLyvUQPHD9OmhdxB+NOUW9XVb5GlL5vUVfrJNpvt7ZzgKiuSo4V32rONwZFfc0F20y0E7/9n7pC12oLdAQYKnoSsI/WUdGUZTZ4stpkms2DOkKaGw1A8TfhTCo8y2iBwBp0OGnoopTuf2OTxhPndYoTs2WYCIH0Yczn+F0RKqsghHLfdkwjxc2mPWxeGsQBNECzfSO7gOTv7gVu5jnv5PCM4zDuqtuHLpf/GI7DiPOl0RisZajltg==" Aug 28 03:44:40 volumio go-librespot[25001]: time="2024-08-28T03:44:40-05:00" level=debug msg="completed keyexchange" Aug 28 03:44:41 volumio go-librespot[25001]: time="2024-08-28T03:44:41-05:00" level=debug msg="completed challenge" Aug 28 03:44:41 volumio go-librespot[25001]: time="2024-08-28T03:44:41-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:44:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:44:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:44:41 volumio volumio[4187]: info: Connection to go-librespot Websocket closed Aug 28 03:44:43 volumio volumio[4187]: info: Getting Spotify volume Aug 28 03:44:43 volumio volumio[4187]: (node:4187) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:43 volumio volumio[4187]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Aug 28 03:44:43 volumio volumio[4187]: (node:4187) 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: 243) Aug 28 03:44:43 volumio volumio[4187]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Aug 28 03:44:43 volumio volumio[4187]: info: CoreCommandRouter::volumioGetState Aug 28 03:44:43 volumio volumio[4187]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Aug 28 03:44:44 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:44 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:44:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4646. Aug 28 03:44:44 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:44:44 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:44:44 volumio go-librespot[25010]: Librespot-go daemon starting... Aug 28 03:44:44 volumio go-librespot[25010]: time="2024-08-28T03:44:44-05:00" level=info msg="generated new device id: 9e3df6609fb234bcb37252878d7ccaf2131d786b" Aug 28 03:44:44 volumio go-librespot[25010]: time="2024-08-28T03:44:44-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:44:44 volumio go-librespot[25010]: time="2024-08-28T03:44:44-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 28 03:44:44 volumio go-librespot[25010]: time="2024-08-28T03:44:44-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 28 03:44:44 volumio go-librespot[25010]: time="2024-08-28T03:44:44-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 28 03:44:44 volumio go-librespot[25010]: time="2024-08-28T03:44:44-05:00" level=debug msg="zeroconf server listening on port 43291" Aug 28 03:44:44 volumio go-librespot[25010]: time="2024-08-28T03:44:44-05:00" level=debug msg="obtained new client token: AAC9gqR0tsuDDhJYBuFcpIWm1tg84EiDPmoTQr8jROJ4oF6j0x8+mIBzmEWhYC/AJRbXmDt9pCMd0ALyegX11cYA2CVuWhKNLYZBJGm3pu2a0ek3ci6iqX08jmzrcJzh0T40lDwo7tNpJ6qEZo9QN8oee6FQRPKEs6VngRvreqgECot3O5GzFC51dyUUTNS+u2J93Hlwbc3OzvYUCOHUadg9N7+3piPOxhLqcrIYf5bZg+ce8gHEKmmIxQ==" Aug 28 03:44:44 volumio go-librespot[25010]: time="2024-08-28T03:44:44-05:00" level=debug msg="completed keyexchange" Aug 28 03:44:45 volumio go-librespot[25010]: time="2024-08-28T03:44:45-05:00" level=debug msg="completed challenge" Aug 28 03:44:45 volumio go-librespot[25010]: time="2024-08-28T03:44:45-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:44:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:44:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:44:47 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:47 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:44:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4647. Aug 28 03:44:48 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:44:48 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:44:48 volumio go-librespot[25019]: Librespot-go daemon starting... Aug 28 03:44:48 volumio go-librespot[25019]: time="2024-08-28T03:44:48-05:00" level=info msg="generated new device id: 30f15d790829f932dfb5fd9e9fa8ac8bd6e67ce4" Aug 28 03:44:48 volumio go-librespot[25019]: time="2024-08-28T03:44:48-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:44:48 volumio go-librespot[25019]: time="2024-08-28T03:44:48-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 28 03:44:48 volumio go-librespot[25019]: time="2024-08-28T03:44:48-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 28 03:44:48 volumio go-librespot[25019]: time="2024-08-28T03:44:48-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 28 03:44:48 volumio go-librespot[25019]: time="2024-08-28T03:44:48-05:00" level=debug msg="zeroconf server listening on port 39379" Aug 28 03:44:48 volumio go-librespot[25019]: time="2024-08-28T03:44:48-05:00" level=debug msg="obtained new client token: AADzO7z3+4KAjDVxWi/0ZVDZPhdZ+2Jyk+tqCVK1WEqUWhPbjAK/ahAml6PXQjeGNCkmLNUXiSQHrk2WTmvOFwg4OObHhVJrCkSk59Uwtv12A4ebh0VdsSKt/zGv0eF1N2GWCUw7nIUiyCaWSf7BZ15Cmj2Vz6GOX46d1WdE/czrRxhD3WTl+VFbiTSEATQFkYzY3c4Q9trij4xKUklWnvtBbGKKi1j92YHXp9C8Pd1y+mSMLOKTulU4GA==" Aug 28 03:44:48 volumio go-librespot[25019]: time="2024-08-28T03:44:48-05:00" level=debug msg="completed keyexchange" Aug 28 03:44:49 volumio go-librespot[25019]: time="2024-08-28T03:44:49-05:00" level=debug msg="completed challenge" Aug 28 03:44:49 volumio go-librespot[25019]: time="2024-08-28T03:44:49-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:44:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:44:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:44:50 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:50 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:44:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4648. Aug 28 03:44:52 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:44:52 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:44:52 volumio go-librespot[25027]: Librespot-go daemon starting... Aug 28 03:44:52 volumio go-librespot[25027]: time="2024-08-28T03:44:52-05:00" level=info msg="generated new device id: 6c706de8d5254eb4361843ab50c53cb5f51fbe28" Aug 28 03:44:52 volumio go-librespot[25027]: time="2024-08-28T03:44:52-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:44:52 volumio go-librespot[25027]: time="2024-08-28T03:44:52-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 03:44:52 volumio go-librespot[25027]: time="2024-08-28T03:44:52-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 03:44:52 volumio go-librespot[25027]: time="2024-08-28T03:44:52-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 03:44:52 volumio go-librespot[25027]: time="2024-08-28T03:44:52-05:00" level=debug msg="zeroconf server listening on port 45601" Aug 28 03:44:52 volumio go-librespot[25027]: time="2024-08-28T03:44:52-05:00" level=debug msg="obtained new client token: AADXqB+GvRh3SdxNh89J6K8+uIQrSP9cOrGTBy93K1kllubmcoNWJlgr7cdJcObpbRvmRwEEJ7KhGsrcNZ1DRcS5FBsjh7S+ZJw5i42Lu2Y9wWot1D9d4VqsDNI8c1UqiqIiWuUsWmzkGDxGxPfnhdUqrqdTfb9+waI9oLJWEagQqHGQalqDYDH5qjz6QZpKAhLqB9ivYP0Zk89a5696Bn7w9KATyI3JSWv+sG1uxq6ozSyvKxkpNsuF4g==" Aug 28 03:44:52 volumio go-librespot[25027]: time="2024-08-28T03:44:52-05:00" level=debug msg="completed keyexchange" Aug 28 03:44:53 volumio go-librespot[25027]: time="2024-08-28T03:44:53-05:00" level=debug msg="completed challenge" Aug 28 03:44:53 volumio go-librespot[25027]: time="2024-08-28T03:44:53-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:44:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:44:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:44:53 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:53 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:56 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:56 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:44:56 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:44:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4649. Aug 28 03:44:56 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:44:56 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:44:56 volumio go-librespot[25035]: Librespot-go daemon starting... Aug 28 03:44:56 volumio go-librespot[25035]: time="2024-08-28T03:44:56-05:00" level=info msg="generated new device id: 6c901049ba53df5d2134f512b7b00e1e134df07a" Aug 28 03:44:56 volumio go-librespot[25035]: time="2024-08-28T03:44:56-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:44:56 volumio go-librespot[25035]: time="2024-08-28T03:44:56-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 03:44:56 volumio go-librespot[25035]: time="2024-08-28T03:44:56-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 03:44:56 volumio go-librespot[25035]: time="2024-08-28T03:44:56-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 03:44:56 volumio go-librespot[25035]: time="2024-08-28T03:44:56-05:00" level=debug msg="zeroconf server listening on port 46501" Aug 28 03:44:56 volumio go-librespot[25035]: time="2024-08-28T03:44:56-05:00" level=debug msg="obtained new client token: AAD+zE/D49IpF/J3guVI5i6/WEC+9debnM0t9z8JI7i6S87StieZRMK9/7nWzCfsqo0CyQhvjLhxWP4ZN2eT4ym/0KaR/hUt56swn/bLoUk4HnJkWDHXL6i3jKFvOA/2a/xwJkKC7VrxuDu/lWzjinIN8vQA7xIoQv5fhPRq6eHcAu2OyyfFhH6avdYjtI6sH3njgn1aW5XPgr+/hgS0k9DThzPA9QgMf2en39tATGg3zB5XPh5+5BM4dg==" Aug 28 03:44:56 volumio go-librespot[25035]: time="2024-08-28T03:44:56-05:00" level=debug msg="completed keyexchange" Aug 28 03:44:57 volumio go-librespot[25035]: time="2024-08-28T03:44:57-05:00" level=debug msg="completed challenge" Aug 28 03:44:57 volumio go-librespot[25035]: time="2024-08-28T03:44:57-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:44:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:44:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:44:59 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:44:59 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:45:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:45:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4650. Aug 28 03:45:00 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:45:00 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:45:00 volumio go-librespot[25043]: Librespot-go daemon starting... Aug 28 03:45:00 volumio go-librespot[25043]: time="2024-08-28T03:45:00-05:00" level=info msg="generated new device id: 91f7478f037a7886833213b8d7b9170939987a72" Aug 28 03:45:00 volumio go-librespot[25043]: time="2024-08-28T03:45:00-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:45:00 volumio go-librespot[25043]: time="2024-08-28T03:45:00-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 03:45:00 volumio go-librespot[25043]: time="2024-08-28T03:45:00-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 03:45:00 volumio go-librespot[25043]: time="2024-08-28T03:45:00-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 03:45:00 volumio go-librespot[25043]: time="2024-08-28T03:45:00-05:00" level=debug msg="zeroconf server listening on port 45181" Aug 28 03:45:00 volumio go-librespot[25043]: time="2024-08-28T03:45:00-05:00" level=debug msg="obtained new client token: AAAuF+tWt9ipsqXttnFQ3pQOWZiaXISlB+3DhtR2uApEDnfK3PD94bEm4lfzLn6a32Qts/FyQf1PwXMIqf45Rk4Lnk8yvrxXNBtMDOXbBs0OcqZE5Uplvo9oQ3pdB20Lyl11Vmtay7lLdcF6nfkwT5Q1AHlPWISCNrm12hoDoCW7e0mq6FjmYvWwHi34i2qhy2U4O4Do8zwZvMCgOsoko8vyv5QfWkpfBIN2oKztPk7Jo975ozYnvrPYVA==" Aug 28 03:45:00 volumio go-librespot[25043]: time="2024-08-28T03:45:00-05:00" level=debug msg="completed keyexchange" Aug 28 03:45:01 volumio go-librespot[25043]: time="2024-08-28T03:45:01-05:00" level=debug msg="completed challenge" Aug 28 03:45:01 volumio go-librespot[25043]: time="2024-08-28T03:45:01-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:45:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:45:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:45:02 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:45:02 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:45:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:45:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4651. Aug 28 03:45:04 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:45:04 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:45:04 volumio go-librespot[25052]: Librespot-go daemon starting... Aug 28 03:45:04 volumio go-librespot[25052]: time="2024-08-28T03:45:04-05:00" level=info msg="generated new device id: 4992bc3e3aeb3aaa2bae488b9a15f2c4ff2b9c77" Aug 28 03:45:04 volumio go-librespot[25052]: time="2024-08-28T03:45:04-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:45:04 volumio go-librespot[25052]: time="2024-08-28T03:45:04-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 28 03:45:04 volumio go-librespot[25052]: time="2024-08-28T03:45:04-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 28 03:45:04 volumio go-librespot[25052]: time="2024-08-28T03:45:04-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 28 03:45:04 volumio go-librespot[25052]: time="2024-08-28T03:45:04-05:00" level=debug msg="zeroconf server listening on port 38239" Aug 28 03:45:04 volumio go-librespot[25052]: time="2024-08-28T03:45:04-05:00" level=debug msg="obtained new client token: AAA7/ylGJiYOn+V2Rzxec5/0T6BlqFu2uFokVIJrEwbXImd5UJLa+LApTH6qLiieorsLljAneInbr43F2aCFVXqYLJXFi6Cs+MbR6H0kWELQ9vYUmQ+UWkJTQPL11r1qdCMUlMnXwnICMAG3qoMGaAIpqSqTPonzW3SuA8AfBAjsl58Zx6QIpWkdGCt29oLYZhVwKqw5+PhfX8mj4I15n7Qd0IyiTmqE0waAsCxrcmQiqWoSH8ImV0Evdg==" Aug 28 03:45:04 volumio go-librespot[25052]: time="2024-08-28T03:45:04-05:00" level=debug msg="completed keyexchange" Aug 28 03:45:05 volumio go-librespot[25052]: time="2024-08-28T03:45:05-05:00" level=debug msg="completed challenge" Aug 28 03:45:05 volumio go-librespot[25052]: time="2024-08-28T03:45:05-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:45:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:45:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:45:05 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:45:05 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:45:08 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:45:08 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:45:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:45:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4652. Aug 28 03:45:08 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:45:08 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:45:08 volumio go-librespot[25061]: Librespot-go daemon starting... Aug 28 03:45:08 volumio go-librespot[25061]: time="2024-08-28T03:45:08-05:00" level=info msg="generated new device id: 69ab8a7b6734dba5de03c7c4fd56f7008a96908d" Aug 28 03:45:08 volumio go-librespot[25061]: time="2024-08-28T03:45:08-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:45:08 volumio go-librespot[25061]: time="2024-08-28T03:45:08-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 03:45:08 volumio go-librespot[25061]: time="2024-08-28T03:45:08-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 03:45:08 volumio go-librespot[25061]: time="2024-08-28T03:45:08-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 03:45:08 volumio go-librespot[25061]: time="2024-08-28T03:45:08-05:00" level=debug msg="zeroconf server listening on port 40855" Aug 28 03:45:08 volumio go-librespot[25061]: time="2024-08-28T03:45:08-05:00" level=debug msg="obtained new client token: AABFzF0coyQqv0AIQUVc0MKq4a3fwQ9i11TEOOHwlIS5PyNPj1VHhQXUSMO5aXdzTqrPOGzH0o+HITXgYQIHoIyczrpkWsPrFATqKcyTwz8VeRKIdKvRRyEdgplvnNoa/MjE1eU6950jMDfrkJpWfYn4DRHG1PHw5kan7D0zdnYFNBsd0Ldvh1JyFrayDYwws5p4Ra60kcV1R3uG8mOvCtXEHttYt1Abr1nIQo4eCdP4P0NIWN+NJ/tqxA==" Aug 28 03:45:08 volumio go-librespot[25061]: time="2024-08-28T03:45:08-05:00" level=debug msg="completed keyexchange" Aug 28 03:45:09 volumio go-librespot[25061]: time="2024-08-28T03:45:09-05:00" level=debug msg="completed challenge" Aug 28 03:45:09 volumio go-librespot[25061]: time="2024-08-28T03:45:09-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:45:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:45:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:45:11 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:45:11 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:45:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:45:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4653. Aug 28 03:45:12 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:45:12 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:45:12 volumio go-librespot[25069]: Librespot-go daemon starting... Aug 28 03:45:12 volumio go-librespot[25069]: time="2024-08-28T03:45:12-05:00" level=info msg="generated new device id: b8ef28ba743f82ddd6a20b45b7dbc72fd18de069" Aug 28 03:45:12 volumio go-librespot[25069]: time="2024-08-28T03:45:12-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:45:12 volumio go-librespot[25069]: time="2024-08-28T03:45:12-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 28 03:45:12 volumio go-librespot[25069]: time="2024-08-28T03:45:12-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 28 03:45:12 volumio go-librespot[25069]: time="2024-08-28T03:45:12-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 28 03:45:12 volumio go-librespot[25069]: time="2024-08-28T03:45:12-05:00" level=debug msg="zeroconf server listening on port 33819" Aug 28 03:45:12 volumio go-librespot[25069]: time="2024-08-28T03:45:12-05:00" level=debug msg="obtained new client token: AAAwA0ipdaUihzhyrtVLx40j90rLiJx1/rCW5OaW4sSImi8HSDxBjYj6ll4ZTd92uE72wmnexysl3jNI07zWU/3OPN/yCyKEKjejVeJjgXkoTn5kmonWTPhurFW3+/0XmGOk4Hk73cPmM79Halb4oXRTxGrwMm1vMPQJ6gniHrVX2sABqMVQ3J2kOJVOh4o5TJcdw5MMiJ0ugm9S12W9lAgkHIs2J1LBjJi0uOhnQt98W+Vy3jSYIzvygg==" Aug 28 03:45:12 volumio go-librespot[25069]: time="2024-08-28T03:45:12-05:00" level=debug msg="completed keyexchange" Aug 28 03:45:13 volumio go-librespot[25069]: time="2024-08-28T03:45:13-05:00" level=debug msg="completed challenge" Aug 28 03:45:13 volumio go-librespot[25069]: time="2024-08-28T03:45:13-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:45:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:45:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:45:14 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:45:14 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:45:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:45:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4654. Aug 28 03:45:16 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:45:16 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:45:16 volumio go-librespot[25077]: Librespot-go daemon starting... Aug 28 03:45:16 volumio go-librespot[25077]: time="2024-08-28T03:45:16-05:00" level=info msg="generated new device id: 24829c45fec1d3e479af00e4a0c501443c13e843" Aug 28 03:45:16 volumio go-librespot[25077]: time="2024-08-28T03:45:16-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:45:16 volumio go-librespot[25077]: time="2024-08-28T03:45:16-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 03:45:16 volumio go-librespot[25077]: time="2024-08-28T03:45:16-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 03:45:16 volumio go-librespot[25077]: time="2024-08-28T03:45:16-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 03:45:16 volumio go-librespot[25077]: time="2024-08-28T03:45:16-05:00" level=debug msg="zeroconf server listening on port 37419" Aug 28 03:45:16 volumio go-librespot[25077]: time="2024-08-28T03:45:16-05:00" level=debug msg="obtained new client token: AADxhgCOcnz6j0ygm5u0emnO5RgbrNGXkv8YH/zpLGQL2Uc9rDs/JPOPy5NxCtwJr022shUU8SFtSJxzNsJF5R9b0swShumig/f8SzGNyHNPo1+e48rwyTuMBKC1lxMw9YNQLwmAf81KsGLwh2Q0etgZYADlaPv91XfGXzpH3FBW+XcFnROTmZ5qH9a6caeKyqKCfuSn17OHPoyB6WXFCHVfMwRJmRgjWLi+DtM8IBo0M+yuj70BADp5pQ==" Aug 28 03:45:16 volumio go-librespot[25077]: time="2024-08-28T03:45:16-05:00" level=debug msg="completed keyexchange" Aug 28 03:45:17 volumio go-librespot[25077]: time="2024-08-28T03:45:17-05:00" level=debug msg="completed challenge" Aug 28 03:45:17 volumio go-librespot[25077]: time="2024-08-28T03:45:17-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:45:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:45:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:45:17 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:45:17 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:45:20 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:45:20 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:45:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:45:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4655. Aug 28 03:45:20 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:45:20 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:45:20 volumio go-librespot[25085]: Librespot-go daemon starting... Aug 28 03:45:20 volumio go-librespot[25085]: time="2024-08-28T03:45:20-05:00" level=info msg="generated new device id: 486397eb8728984f4de78a90b4247989100c82e3" Aug 28 03:45:20 volumio go-librespot[25085]: time="2024-08-28T03:45:20-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:45:20 volumio go-librespot[25085]: time="2024-08-28T03:45:20-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 03:45:20 volumio go-librespot[25085]: time="2024-08-28T03:45:20-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 03:45:20 volumio go-librespot[25085]: time="2024-08-28T03:45:20-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 03:45:20 volumio go-librespot[25085]: time="2024-08-28T03:45:20-05:00" level=debug msg="zeroconf server listening on port 38827" Aug 28 03:45:20 volumio go-librespot[25085]: time="2024-08-28T03:45:20-05:00" level=debug msg="obtained new client token: AADH6Ay2i4hRxS6qi7U5R6pP9VTbu8c9FHpwiy6Qv47L9E0Q7gG9LAV2hUf8/RtVK//jsuLBC/8TAC9jfvxXJI9O9wsGYlBVTeTXbUD2bfJTq6SnSQPAnRyyAx/yB1w1ZX0Rq32I1mNUhzE/izsyZEXng22R24lZcWna2rtP5jOZW7JIVZzPlTEFzSxMjFw9ZUH2p93n1MeFNQ5oVDGFTGfhZXOLu9/yDUWWLNAhJRYCTE6huEhuFxh/wA==" Aug 28 03:45:20 volumio go-librespot[25085]: time="2024-08-28T03:45:20-05:00" level=debug msg="completed keyexchange" Aug 28 03:45:21 volumio go-librespot[25085]: time="2024-08-28T03:45:21-05:00" level=debug msg="completed challenge" Aug 28 03:45:21 volumio go-librespot[25085]: time="2024-08-28T03:45:21-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:45:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:45:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:45:23 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:45:23 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:45:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:45:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4656. Aug 28 03:45:24 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:45:24 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:45:24 volumio go-librespot[25093]: Librespot-go daemon starting... Aug 28 03:45:24 volumio go-librespot[25093]: time="2024-08-28T03:45:24-05:00" level=info msg="generated new device id: c91fa24b2a5b26629730f11c48e57134db85dbf4" Aug 28 03:45:24 volumio go-librespot[25093]: time="2024-08-28T03:45:24-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:45:24 volumio go-librespot[25093]: time="2024-08-28T03:45:24-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 03:45:24 volumio go-librespot[25093]: time="2024-08-28T03:45:24-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 03:45:24 volumio go-librespot[25093]: time="2024-08-28T03:45:24-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 03:45:24 volumio go-librespot[25093]: time="2024-08-28T03:45:24-05:00" level=debug msg="zeroconf server listening on port 41443" Aug 28 03:45:24 volumio go-librespot[25093]: time="2024-08-28T03:45:24-05:00" level=debug msg="obtained new client token: AABjmkOKKtk9H9avujHVaV0R9O0wZQ4ak6XX9grW8Y/KBa4i9MTo24etErLlAOV5V9ECvzKc4/GoO59aiEA24QkqLB74nscG4Vs2xXhLoNKFJzH8EVEKeXKgikVwuDh32wheMBokCtapTGqenbdVPo+ruix6tCGi+uLpXS9TsDqqPJiAGaj3ctlZQvCq7t3CkQOczPuJsYSvtSkkoSI7L8AA4rycHa845dy05HVf4RzTJ4401/O4Hy8M1w==" Aug 28 03:45:24 volumio go-librespot[25093]: time="2024-08-28T03:45:24-05:00" level=debug msg="completed keyexchange" Aug 28 03:45:25 volumio go-librespot[25093]: time="2024-08-28T03:45:25-05:00" level=debug msg="completed challenge" Aug 28 03:45:25 volumio go-librespot[25093]: time="2024-08-28T03:45:25-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:45:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:45:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:45:26 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:45:26 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:45:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:45:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4657. Aug 28 03:45:28 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:45:28 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:45:28 volumio go-librespot[25140]: Librespot-go daemon starting... Aug 28 03:45:28 volumio go-librespot[25140]: time="2024-08-28T03:45:28-05:00" level=info msg="generated new device id: 96b428fa6c1eb0dd8987045b1adba9149fbdc3fc" Aug 28 03:45:28 volumio go-librespot[25140]: time="2024-08-28T03:45:28-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:45:28 volumio go-librespot[25140]: time="2024-08-28T03:45:28-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 28 03:45:28 volumio go-librespot[25140]: time="2024-08-28T03:45:28-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 28 03:45:28 volumio go-librespot[25140]: time="2024-08-28T03:45:28-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 28 03:45:28 volumio go-librespot[25140]: time="2024-08-28T03:45:28-05:00" level=debug msg="zeroconf server listening on port 43479" Aug 28 03:45:28 volumio go-librespot[25140]: time="2024-08-28T03:45:28-05:00" level=debug msg="obtained new client token: AAD84rvc9WVfke3AyAOw4Y6YlgFb6QZR8PbVbi22LuDt+Zul3oOTrjOVyI3rhYemPhr2b2UBm8S1SjmwLP58fY8VlPjhBhlYc9wUMyizeFXRX+LT3N4GL3P3Si1UMkU+M70BfPr8gq2IMBp/qbXX+XUrNrIB3WsE3TyRlYjS3Eo7RMDLfxqMSqG8btLbvgaYj0sVNQJuARvF/d8BDYlPgimHilPrth5h5/FIgZ7rcRDMXqd5u7SjGsEjOA==" Aug 28 03:45:28 volumio go-librespot[25140]: time="2024-08-28T03:45:28-05:00" level=debug msg="completed keyexchange" Aug 28 03:45:29 volumio go-librespot[25140]: time="2024-08-28T03:45:29-05:00" level=debug msg="completed challenge" Aug 28 03:45:29 volumio go-librespot[25140]: time="2024-08-28T03:45:29-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:45:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:45:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:45:29 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:45:29 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:45:32 volumio volumio[4187]: info: Initializing connection to go-librespot Websocket Aug 28 03:45:32 volumio volumio[4187]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 03:45:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 28 03:45:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4658. Aug 28 03:45:32 volumio systemd[1]: Stopped go-librespot Daemon. Aug 28 03:45:32 volumio systemd[1]: Started go-librespot Daemon. Aug 28 03:45:32 volumio go-librespot[25148]: Librespot-go daemon starting... Aug 28 03:45:32 volumio go-librespot[25148]: time="2024-08-28T03:45:32-05:00" level=info msg="generated new device id: 4e3a8064a675d3b3c2d484a3402ba4c47523c5cb" Aug 28 03:45:32 volumio go-librespot[25148]: time="2024-08-28T03:45:32-05:00" level=debug msg="stored credentials found for its2gud" Aug 28 03:45:32 volumio go-librespot[25148]: time="2024-08-28T03:45:32-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 03:45:32 volumio go-librespot[25148]: time="2024-08-28T03:45:32-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 03:45:32 volumio go-librespot[25148]: time="2024-08-28T03:45:32-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 03:45:32 volumio go-librespot[25148]: time="2024-08-28T03:45:32-05:00" level=debug msg="zeroconf server listening on port 34087" Aug 28 03:45:32 volumio go-librespot[25148]: time="2024-08-28T03:45:32-05:00" level=debug msg="obtained new client token: AAAELHEyXPmwHc7q+pzGaEH8qJquLcIRv/yzvCIuTusBwYn15THHDlQwF40nAz1OVZt81Ltd8NdmD1K1qGsEO+5tRNm1YnbAgjrHdEdFaS+Nv1NvKd7pHzDuSXCT1RdACOUGXXMu/eXlcEoQ5SLpApfQWqhpoIVl+2iL08oEnbOwBOHhQyTLxjH0Lj9oZIoZk1B+bQ6R1CRK3UjIlUW7RBvQ6uLCvVzcTKWCHiceV2zXh8Sz0WQXr1Jmqg==" Aug 28 03:45:32 volumio go-librespot[25148]: time="2024-08-28T03:45:32-05:00" level=debug msg="completed keyexchange" Aug 28 03:45:33 volumio go-librespot[25148]: time="2024-08-28T03:45:33-05:00" level=debug msg="completed challenge" Aug 28 03:45:33 volumio go-librespot[25148]: time="2024-08-28T03:45:33-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 28 03:45:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 03:45:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 03:45:35 volumio volumio[4187]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 28 03:45:35 volumio volumio[4187]: Error: read ETIMEDOUT Aug 28 03:45:35 volumio volumio[4187]: at TCP.onStreamRead (internal/stream_base_commons.js:209:20) { Aug 28 03:45:35 volumio volumio[4187]: errno: -110, Aug 28 03:45:35 volumio volumio[4187]: code: 'ETIMEDOUT', Aug 28 03:45:35 volumio volumio[4187]: syscall: 'read' Aug 28 03:45:35 volumio volumio[4187]: } Aug 28 03:45:35 volumio volumio[4187]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 28 03:45:35 volumio sudo[25165]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-28 03:44 Aug 28 03:45:35 volumio sudo[25165]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"