-- Logs begin at Fri 2024-03-29 22:38:51 CST, end at Wed 2024-05-08 07:11:23 CST. -- May 08 07:10:00 minidsp-shd volumio[689]: info: Getting Spotify volume May 08 07:10:00 minidsp-shd volumio[689]: (node:689) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:00 minidsp-shd volumio[689]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 08 07:10:00 minidsp-shd volumio[689]: (node:689) 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: 30) May 08 07:10:00 minidsp-shd volumio[689]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 May 08 07:10:00 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioGetState May 08 07:10:00 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:00 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 08 07:10:02 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:10:02 minidsp-shd volumio[689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:02 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 08 07:10:02 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. May 08 07:10:02 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 08 07:10:02 minidsp-shd systemd[1]: Started go-librespot Daemon. May 08 07:10:02 minidsp-shd go-librespot[2192]: Librespot-go daemon starting... May 08 07:10:02 minidsp-shd go-librespot[2192]: time="2024-05-08T07:10:02+08:00" level=info msg="generated new device id: 69358588c105128fa086ad7f0baff93c26f180e8" May 08 07:10:02 minidsp-shd go-librespot[2192]: time="2024-05-08T07:10:02+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j" May 08 07:10:03 minidsp-shd go-librespot[2192]: time="2024-05-08T07:10:03+08:00" level=debug msg="obtained new client token: AACpj2mNHf7W6KZaZqsS809m54gNE6Fl+clr0zYM6GQ2ntAYIKUiYdGOhxb4a91t/Eq1juQg6bXYA2D7gv4uXl3YVp1wM0wABKvtpDHjzHv+hA7Ems6B9EGwkQxgykVPOUc6G0Z18OeHlYnuWs8bAGaQBenEpJpILOqt01V2YNIAThgJVVj4awSHU80yUuZoNjx3+QsI8544r2IQ4O6mKNdYq55xTIwM3N6OsO+XHEcUBe1PNClKhAKepq1FfMPA" May 08 07:10:03 minidsp-shd go-librespot[2192]: time="2024-05-08T07:10:03+08: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]" May 08 07:10:03 minidsp-shd go-librespot[2192]: time="2024-05-08T07:10:03+08:00" level=debug msg="completed keyexchange" May 08 07:10:04 minidsp-shd go-librespot[2192]: time="2024-05-08T07:10:04+08:00" level=debug msg="completed challenge" May 08 07:10:04 minidsp-shd go-librespot[2192]: time="2024-05-08T07:10:04+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 08 07:10:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 08 07:10:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 08 07:10:05 minidsp-shd volumio[689]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 08 07:10:05 minidsp-shd volumio[689]: info: CURURI: albums://Lang%20Lang/Liszt%20-%20My%20Piano%20Hero May 08 07:10:05 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:10:05 minidsp-shd volumio[689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:05 minidsp-shd volumio[689]: info: Preload queue cleared May 08 07:10:05 minidsp-shd volumio[689]: info: Preloading song: music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Romance O pourquoi donc in E Minor, S. 169.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Preloading song: music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/La campanella in G-Sharp Minor from Grandes études de Paganini, S. 141 3.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Preloading song: music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Consolation No. 3 in D-Flat Major, S. 172.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Preloading song: music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Grand Galop chromatique in E-Flat Major, S. 219.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Preloading song: music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Liebestraum No. 3 in A-Flat Major, S. 541 3.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Preloading song: music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Hungarian Rhapsody No. 6 in D-Flat Major, S. 244 6.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Preloading song: music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Trois études de concert in D-Flat Major, S. 144 3 Un sospiro.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Preloading song: music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Rakoczy March from Hungarian Rhapsody No. 15 in A Minor, S. 244 15.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Preloading song: music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Ave Maria, S. 558.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Preloading song: music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Piano Concerto No. 1 in E-Flat Major, S. 124 I. Allegro maestoso.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Preloading song: music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Piano Concerto No. 1 in E-Flat Major, S. 124 II. Quasi adagio - Allegretto vivace - Allegro animato.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Preloading song: music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Piano Concerto No. 1 in E-Flat Major, S. 124 III. Allegro marziale animato.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Exploding uri music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Romance O pourquoi donc in E Minor, S. 169.flac in service mpd May 08 07:10:05 minidsp-shd volumio[689]: info: ALBUMART /albumart?cacheid=918&web=Lang%20Lang/Liszt%20-%20My%20Piano%20Hero/extralarge&path=%2Fmnt%2FNAS%2F%E4%B9%90%E6%9B%B2%2F%E5%8F%A4%E5%85%B8%2F%E3%80%8A%E6%88%91%E7%9A%84%E9%92%A2%E7%90%B4%E8%8B%B1%E9%9B%84%EF%BC%81%E6%9D%8E%E6%96%AF%E7%89%B9%E9%92%A2%E7%90%B4%E4%BD%9C%E5%93%81%E9%9B%86%20(LISZT%20-%20MY%20PIANO%20HERO%20!)%E3%80%8B%20-%20%E9%83%8E%E6%9C%97%2FRomance%20O%20pourquoi%20donc%20in%20E%20Minor%2C%20S.%20169.flac&metadata=false May 08 07:10:05 minidsp-shd volumio[689]: info: URI /mnt/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Romance O pourquoi donc in E Minor, S. 169.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Exploding uri music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/La campanella in G-Sharp Minor from Grandes études de Paganini, S. 141 3.flac in service mpd May 08 07:10:05 minidsp-shd volumio[689]: info: ALBUMART /albumart?cacheid=918&web=Lang%20Lang/Liszt%20-%20My%20Piano%20Hero/extralarge&path=%2Fmnt%2FNAS%2F%E4%B9%90%E6%9B%B2%2F%E5%8F%A4%E5%85%B8%2F%E3%80%8A%E6%88%91%E7%9A%84%E9%92%A2%E7%90%B4%E8%8B%B1%E9%9B%84%EF%BC%81%E6%9D%8E%E6%96%AF%E7%89%B9%E9%92%A2%E7%90%B4%E4%BD%9C%E5%93%81%E9%9B%86%20(LISZT%20-%20MY%20PIANO%20HERO%20!)%E3%80%8B%20-%20%E9%83%8E%E6%9C%97%2FLa%20campanella%20in%20G-Sharp%20Minor%20from%20Grandes%20%C3%A9tudes%20de%20Paganini%2C%20S.%20141%20%203.flac&metadata=false May 08 07:10:05 minidsp-shd volumio[689]: info: URI /mnt/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/La campanella in G-Sharp Minor from Grandes études de Paganini, S. 141 3.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Exploding uri music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Consolation No. 3 in D-Flat Major, S. 172.flac in service mpd May 08 07:10:05 minidsp-shd volumio[689]: info: ALBUMART /albumart?cacheid=918&web=Lang%20Lang/Liszt%20-%20My%20Piano%20Hero/extralarge&path=%2Fmnt%2FNAS%2F%E4%B9%90%E6%9B%B2%2F%E5%8F%A4%E5%85%B8%2F%E3%80%8A%E6%88%91%E7%9A%84%E9%92%A2%E7%90%B4%E8%8B%B1%E9%9B%84%EF%BC%81%E6%9D%8E%E6%96%AF%E7%89%B9%E9%92%A2%E7%90%B4%E4%BD%9C%E5%93%81%E9%9B%86%20(LISZT%20-%20MY%20PIANO%20HERO%20!)%E3%80%8B%20-%20%E9%83%8E%E6%9C%97%2FConsolation%20No.%203%20in%20D-Flat%20Major%2C%20S.%20172.flac&metadata=false May 08 07:10:05 minidsp-shd volumio[689]: info: URI /mnt/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Consolation No. 3 in D-Flat Major, S. 172.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Exploding uri music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Grand Galop chromatique in E-Flat Major, S. 219.flac in service mpd May 08 07:10:05 minidsp-shd volumio[689]: info: ALBUMART /albumart?cacheid=918&web=Lang%20Lang/Liszt%20-%20My%20Piano%20Hero/extralarge&path=%2Fmnt%2FNAS%2F%E4%B9%90%E6%9B%B2%2F%E5%8F%A4%E5%85%B8%2F%E3%80%8A%E6%88%91%E7%9A%84%E9%92%A2%E7%90%B4%E8%8B%B1%E9%9B%84%EF%BC%81%E6%9D%8E%E6%96%AF%E7%89%B9%E9%92%A2%E7%90%B4%E4%BD%9C%E5%93%81%E9%9B%86%20(LISZT%20-%20MY%20PIANO%20HERO%20!)%E3%80%8B%20-%20%E9%83%8E%E6%9C%97%2FGrand%20Galop%20chromatique%20in%20E-Flat%20Major%2C%20S.%20219.flac&metadata=false May 08 07:10:05 minidsp-shd volumio[689]: info: URI /mnt/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Grand Galop chromatique in E-Flat Major, S. 219.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Exploding uri music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Liebestraum No. 3 in A-Flat Major, S. 541 3.flac in service mpd May 08 07:10:05 minidsp-shd volumio[689]: info: ALBUMART /albumart?cacheid=918&web=Lang%20Lang/Liszt%20-%20My%20Piano%20Hero/extralarge&path=%2Fmnt%2FNAS%2F%E4%B9%90%E6%9B%B2%2F%E5%8F%A4%E5%85%B8%2F%E3%80%8A%E6%88%91%E7%9A%84%E9%92%A2%E7%90%B4%E8%8B%B1%E9%9B%84%EF%BC%81%E6%9D%8E%E6%96%AF%E7%89%B9%E9%92%A2%E7%90%B4%E4%BD%9C%E5%93%81%E9%9B%86%20(LISZT%20-%20MY%20PIANO%20HERO%20!)%E3%80%8B%20-%20%E9%83%8E%E6%9C%97%2FLiebestraum%20No.%203%20in%20A-Flat%20Major%2C%20S.%20541%20%203.flac&metadata=false May 08 07:10:05 minidsp-shd volumio[689]: info: URI /mnt/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Liebestraum No. 3 in A-Flat Major, S. 541 3.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Exploding uri music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Hungarian Rhapsody No. 6 in D-Flat Major, S. 244 6.flac in service mpd May 08 07:10:05 minidsp-shd volumio[689]: info: ALBUMART /albumart?cacheid=918&web=Lang%20Lang/Liszt%20-%20My%20Piano%20Hero/extralarge&path=%2Fmnt%2FNAS%2F%E4%B9%90%E6%9B%B2%2F%E5%8F%A4%E5%85%B8%2F%E3%80%8A%E6%88%91%E7%9A%84%E9%92%A2%E7%90%B4%E8%8B%B1%E9%9B%84%EF%BC%81%E6%9D%8E%E6%96%AF%E7%89%B9%E9%92%A2%E7%90%B4%E4%BD%9C%E5%93%81%E9%9B%86%20(LISZT%20-%20MY%20PIANO%20HERO%20!)%E3%80%8B%20-%20%E9%83%8E%E6%9C%97%2FHungarian%20Rhapsody%20No.%206%20in%20D-Flat%20Major%2C%20S.%20244%20%206.flac&metadata=false May 08 07:10:05 minidsp-shd volumio[689]: info: URI /mnt/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Hungarian Rhapsody No. 6 in D-Flat Major, S. 244 6.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Exploding uri music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Trois études de concert in D-Flat Major, S. 144 3 Un sospiro.flac in service mpd May 08 07:10:05 minidsp-shd volumio[689]: info: ALBUMART /albumart?cacheid=918&web=Lang%20Lang/Liszt%20-%20My%20Piano%20Hero/extralarge&path=%2Fmnt%2FNAS%2F%E4%B9%90%E6%9B%B2%2F%E5%8F%A4%E5%85%B8%2F%E3%80%8A%E6%88%91%E7%9A%84%E9%92%A2%E7%90%B4%E8%8B%B1%E9%9B%84%EF%BC%81%E6%9D%8E%E6%96%AF%E7%89%B9%E9%92%A2%E7%90%B4%E4%BD%9C%E5%93%81%E9%9B%86%20(LISZT%20-%20MY%20PIANO%20HERO%20!)%E3%80%8B%20-%20%E9%83%8E%E6%9C%97%2FTrois%20%C3%A9tudes%20de%20concert%20in%20D-Flat%20Major%2C%20S.%20144%20%203%20Un%20sospiro.flac&metadata=false May 08 07:10:05 minidsp-shd volumio[689]: info: URI /mnt/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Trois études de concert in D-Flat Major, S. 144 3 Un sospiro.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Exploding uri music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Rakoczy March from Hungarian Rhapsody No. 15 in A Minor, S. 244 15.flac in service mpd May 08 07:10:05 minidsp-shd volumio[689]: info: ALBUMART /albumart?cacheid=918&web=Lang%20Lang/Liszt%20-%20My%20Piano%20Hero/extralarge&path=%2Fmnt%2FNAS%2F%E4%B9%90%E6%9B%B2%2F%E5%8F%A4%E5%85%B8%2F%E3%80%8A%E6%88%91%E7%9A%84%E9%92%A2%E7%90%B4%E8%8B%B1%E9%9B%84%EF%BC%81%E6%9D%8E%E6%96%AF%E7%89%B9%E9%92%A2%E7%90%B4%E4%BD%9C%E5%93%81%E9%9B%86%20(LISZT%20-%20MY%20PIANO%20HERO%20!)%E3%80%8B%20-%20%E9%83%8E%E6%9C%97%2FRakoczy%20March%20from%20Hungarian%20Rhapsody%20No.%2015%20in%20A%20Minor%2C%20S.%20244%20%2015.flac&metadata=false May 08 07:10:05 minidsp-shd volumio[689]: info: URI /mnt/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Rakoczy March from Hungarian Rhapsody No. 15 in A Minor, S. 244 15.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Exploding uri music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Ave Maria, S. 558.flac in service mpd May 08 07:10:05 minidsp-shd volumio[689]: info: ALBUMART /albumart?cacheid=918&web=Lang%20Lang/Liszt%20-%20My%20Piano%20Hero/extralarge&path=%2Fmnt%2FNAS%2F%E4%B9%90%E6%9B%B2%2F%E5%8F%A4%E5%85%B8%2F%E3%80%8A%E6%88%91%E7%9A%84%E9%92%A2%E7%90%B4%E8%8B%B1%E9%9B%84%EF%BC%81%E6%9D%8E%E6%96%AF%E7%89%B9%E9%92%A2%E7%90%B4%E4%BD%9C%E5%93%81%E9%9B%86%20(LISZT%20-%20MY%20PIANO%20HERO%20!)%E3%80%8B%20-%20%E9%83%8E%E6%9C%97%2FAve%20Maria%2C%20S.%20558.flac&metadata=false May 08 07:10:05 minidsp-shd volumio[689]: info: URI /mnt/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Ave Maria, S. 558.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Exploding uri music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Piano Concerto No. 1 in E-Flat Major, S. 124 I. Allegro maestoso.flac in service mpd May 08 07:10:05 minidsp-shd volumio[689]: info: ALBUMART /albumart?cacheid=918&web=Lang%20Lang/Liszt%20-%20My%20Piano%20Hero/extralarge&path=%2Fmnt%2FNAS%2F%E4%B9%90%E6%9B%B2%2F%E5%8F%A4%E5%85%B8%2F%E3%80%8A%E6%88%91%E7%9A%84%E9%92%A2%E7%90%B4%E8%8B%B1%E9%9B%84%EF%BC%81%E6%9D%8E%E6%96%AF%E7%89%B9%E9%92%A2%E7%90%B4%E4%BD%9C%E5%93%81%E9%9B%86%20(LISZT%20-%20MY%20PIANO%20HERO%20!)%E3%80%8B%20-%20%E9%83%8E%E6%9C%97%2FPiano%20Concerto%20No.%201%20in%20E-Flat%20Major%2C%20S.%20124%20I.%20Allegro%20maestoso.flac&metadata=false May 08 07:10:05 minidsp-shd volumio[689]: info: URI /mnt/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Piano Concerto No. 1 in E-Flat Major, S. 124 I. Allegro maestoso.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Exploding uri music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Piano Concerto No. 1 in E-Flat Major, S. 124 II. Quasi adagio - Allegretto vivace - Allegro animato.flac in service mpd May 08 07:10:05 minidsp-shd volumio[689]: info: ALBUMART /albumart?cacheid=918&web=Lang%20Lang/Liszt%20-%20My%20Piano%20Hero/extralarge&path=%2Fmnt%2FNAS%2F%E4%B9%90%E6%9B%B2%2F%E5%8F%A4%E5%85%B8%2F%E3%80%8A%E6%88%91%E7%9A%84%E9%92%A2%E7%90%B4%E8%8B%B1%E9%9B%84%EF%BC%81%E6%9D%8E%E6%96%AF%E7%89%B9%E9%92%A2%E7%90%B4%E4%BD%9C%E5%93%81%E9%9B%86%20(LISZT%20-%20MY%20PIANO%20HERO%20!)%E3%80%8B%20-%20%E9%83%8E%E6%9C%97%2FPiano%20Concerto%20No.%201%20in%20E-Flat%20Major%2C%20S.%20124%20II.%20Quasi%20adagio%20-%20Allegretto%20vivace%20-%20Allegro%20animato.flac&metadata=false May 08 07:10:05 minidsp-shd volumio[689]: info: URI /mnt/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Piano Concerto No. 1 in E-Flat Major, S. 124 II. Quasi adagio - Allegretto vivace - Allegro animato.flac May 08 07:10:05 minidsp-shd volumio[689]: info: Exploding uri music-library/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Piano Concerto No. 1 in E-Flat Major, S. 124 III. Allegro marziale animato.flac in service mpd May 08 07:10:05 minidsp-shd volumio[689]: info: ALBUMART /albumart?cacheid=918&web=Lang%20Lang/Liszt%20-%20My%20Piano%20Hero/extralarge&path=%2Fmnt%2FNAS%2F%E4%B9%90%E6%9B%B2%2F%E5%8F%A4%E5%85%B8%2F%E3%80%8A%E6%88%91%E7%9A%84%E9%92%A2%E7%90%B4%E8%8B%B1%E9%9B%84%EF%BC%81%E6%9D%8E%E6%96%AF%E7%89%B9%E9%92%A2%E7%90%B4%E4%BD%9C%E5%93%81%E9%9B%86%20(LISZT%20-%20MY%20PIANO%20HERO%20!)%E3%80%8B%20-%20%E9%83%8E%E6%9C%97%2FPiano%20Concerto%20No.%201%20in%20E-Flat%20Major%2C%20S.%20124%20III.%20Allegro%20marziale%20animato.flac&metadata=false May 08 07:10:05 minidsp-shd volumio[689]: info: URI /mnt/NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Piano Concerto No. 1 in E-Flat Major, S. 124 III. Allegro marziale animato.flac May 08 07:10:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 08 07:10:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. May 08 07:10:07 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 08 07:10:07 minidsp-shd systemd[1]: Started go-librespot Daemon. May 08 07:10:07 minidsp-shd go-librespot[2203]: Librespot-go daemon starting... May 08 07:10:07 minidsp-shd go-librespot[2203]: time="2024-05-08T07:10:07+08:00" level=info msg="generated new device id: 515783524cc13fb292d563f312d0c5a5b5f521ea" May 08 07:10:07 minidsp-shd go-librespot[2203]: time="2024-05-08T07:10:07+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j" May 08 07:10:07 minidsp-shd volumio[689]: info: Preload queue cleared May 08 07:10:07 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioReplaceandPlayItems May 08 07:10:07 minidsp-shd volumio[689]: info: CoreStateMachine::ClearQueue May 08 07:10:07 minidsp-shd volumio[689]: info: CoreStateMachine::stop May 08 07:10:07 minidsp-shd volumio[689]: info: CoreStateMachine::setConsumeUpdateService undefined May 08 07:10:07 minidsp-shd volumio[689]: info: CorePlayQueue::clearPlayQueue May 08 07:10:07 minidsp-shd volumio[689]: info: CorePlayQueue::saveQueue May 08 07:10:07 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushQueue May 08 07:10:07 minidsp-shd volumio[689]: info: CoreStateMachine::addQueueItems May 08 07:10:07 minidsp-shd volumio[689]: info: CorePlayQueue::addQueueItems May 08 07:10:07 minidsp-shd volumio[689]: info: Preload queue cleared May 08 07:10:07 minidsp-shd volumio[689]: info: Adding Item to queue: albums://Lang%20Lang/Liszt%20-%20My%20Piano%20Hero May 08 07:10:07 minidsp-shd volumio[689]: info: Exploding uri albums://Lang%20Lang/Liszt%20-%20My%20Piano%20Hero in service mpd May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushQueue May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::saveQueue May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::updateTrackBlock May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrackBlock May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPlay May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::play index 0 May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::setConsumeUpdateService undefined May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::stop May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::setConsumeUpdateService undefined May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::play index undefined May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::setConsumeUpdateService undefined May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::startPlaybackTimer May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::clearAddPlayTracks NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Romance O pourquoi donc in E Minor, S. 169.flac May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::sendMpdCommand stop May 08 07:10:08 minidsp-shd volumio[689]: info: sendMpdCommand stop took 5 milliseconds May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::sendMpdCommand clear May 08 07:10:08 minidsp-shd volumio[689]: info: sendMpdCommand clear took 5 milliseconds May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::sendMpdCommand add "NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Romance O pourquoi donc in E Minor, S. 169.flac" May 08 07:10:08 minidsp-shd volumio[689]: info: May 08 07:10:08 minidsp-shd volumio[689]: ---------------------------- MPD announces system playlist update May 08 07:10:08 minidsp-shd volumio[689]: info: Ignoring MPD Status Update May 08 07:10:08 minidsp-shd volumio[689]: info: May 08 07:10:08 minidsp-shd volumio[689]: ---------------------------- MPD announces system playlist update May 08 07:10:08 minidsp-shd volumio[689]: info: Ignoring MPD Status Update May 08 07:10:08 minidsp-shd volumio[689]: info: May 08 07:10:08 minidsp-shd volumio[689]: ---------------------------- MPD announces system playlist update May 08 07:10:08 minidsp-shd volumio[689]: info: Ignoring MPD Status Update May 08 07:10:08 minidsp-shd volumio[689]: info: May 08 07:10:08 minidsp-shd volumio[689]: ---------------------------- MPD announces system playlist update May 08 07:10:08 minidsp-shd volumio[689]: info: Ignoring MPD Status Update May 08 07:10:08 minidsp-shd volumio[689]: info: sendMpdCommand add "NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Romance O pourquoi donc in E Minor, S. 169.flac" took 32 milliseconds May 08 07:10:08 minidsp-shd volumio[689]: info: ------------------------------ 23ms May 08 07:10:08 minidsp-shd volumio[689]: info: ------------------------------ 17ms May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::sendMpdCommand play May 08 07:10:08 minidsp-shd volumio[689]: info: May 08 07:10:08 minidsp-shd volumio[689]: ---------------------------- MPD announces system playlist update May 08 07:10:08 minidsp-shd volumio[689]: info: Ignoring MPD Status Update May 08 07:10:08 minidsp-shd volumio[689]: info: May 08 07:10:08 minidsp-shd volumio[689]: ---------------------------- MPD announces system playlist update May 08 07:10:08 minidsp-shd volumio[689]: info: Ignoring MPD Status Update May 08 07:10:08 minidsp-shd volumio[689]: error: Upnp client error: Error: This socket has been ended by the other party May 08 07:10:08 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:10:08 minidsp-shd volumio[689]: info: ------------------------------ 43ms May 08 07:10:08 minidsp-shd volumio[689]: info: ------------------------------ 42ms May 08 07:10:08 minidsp-shd volumio[689]: info: sendMpdCommand play took 31 milliseconds May 08 07:10:08 minidsp-shd volumio[689]: info: ------------------------------ 29ms May 08 07:10:08 minidsp-shd volumio[689]: info: ------------------------------ 26ms May 08 07:10:08 minidsp-shd go-librespot[2203]: time="2024-05-08T07:10:08+08:00" level=debug msg="new websocket client" May 08 07:10:08 minidsp-shd volumio[689]: info: Connection to go-librespot Websocket established May 08 07:10:08 minidsp-shd volumio[689]: info: May 08 07:10:08 minidsp-shd volumio[689]: ---------------------------- MPD announces state update: player May 08 07:10:08 minidsp-shd volumio[689]: info: ControllerMpd::getState May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::sendMpdCommand status May 08 07:10:08 minidsp-shd volumio[689]: info: May 08 07:10:08 minidsp-shd volumio[689]: ---------------------------- MPD announces state update: player May 08 07:10:08 minidsp-shd volumio[689]: info: ControllerMpd::getState May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::sendMpdCommand status May 08 07:10:08 minidsp-shd volumio[689]: info: May 08 07:10:08 minidsp-shd volumio[689]: ---------------------------- MPD announces state update: player May 08 07:10:08 minidsp-shd volumio[689]: info: ControllerMpd::getState May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::sendMpdCommand status May 08 07:10:08 minidsp-shd volumio[689]: info: May 08 07:10:08 minidsp-shd volumio[689]: ---------------------------- MPD announces state update: player May 08 07:10:08 minidsp-shd volumio[689]: info: sendMpdCommand status took 45 milliseconds May 08 07:10:08 minidsp-shd volumio[689]: info: ControllerMpd::getState May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::sendMpdCommand status May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::parseState May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 07:10:08 minidsp-shd volumio[689]: info: sendMpdCommand status took 53 milliseconds May 08 07:10:08 minidsp-shd volumio[689]: info: sendMpdCommand status took 47 milliseconds May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::parseState May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::parseState May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 07:10:08 minidsp-shd volumio[689]: info: May 08 07:10:08 minidsp-shd volumio[689]: ---------------------------- MPD announces state update: player May 08 07:10:08 minidsp-shd volumio[689]: info: ControllerMpd::getState May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::sendMpdCommand status May 08 07:10:08 minidsp-shd volumio[689]: info: May 08 07:10:08 minidsp-shd volumio[689]: ---------------------------- MPD announces state update: player May 08 07:10:08 minidsp-shd volumio[689]: info: ControllerMpd::getState May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::sendMpdCommand status May 08 07:10:08 minidsp-shd volumio[689]: info: sendMpdCommand status took 58 milliseconds May 08 07:10:08 minidsp-shd volumio[689]: info: sendMpdCommand playlistinfo took 55 milliseconds May 08 07:10:08 minidsp-shd volumio[689]: info: sendMpdCommand playlistinfo took 41 milliseconds May 08 07:10:08 minidsp-shd volumio[689]: info: sendMpdCommand playlistinfo took 38 milliseconds May 08 07:10:08 minidsp-shd volumio[689]: info: sendMpdCommand status took 29 milliseconds May 08 07:10:08 minidsp-shd volumio[689]: info: sendMpdCommand status took 22 milliseconds May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::parseState May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::parseTrackInfo May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::parseTrackInfo May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::parseTrackInfo May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::parseState May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::parseState May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 07:10:08 minidsp-shd volumio[689]: info: ControllerMpd::pushState May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::servicePushState May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:08 minidsp-shd volumio[689]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":185,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Romance \"O pourquoi donc\" in E Minor, S. 169","artist":"Lang Lang","album":"Liszt - My Piano Hero","uri":"NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Romance O pourquoi donc in E Minor, S. 169.flac","trackType":"flac"} May 08 07:10:08 minidsp-shd volumio[689]: verbose: CURRENT POSITION 0 May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::syncState stateService play May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::syncState currentStatus stop May 08 07:10:08 minidsp-shd volumio[689]: info: ControllerMpd::pushState May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::servicePushState May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:08 minidsp-shd volumio[689]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":185,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Romance \"O pourquoi donc\" in E Minor, S. 169","artist":"Lang Lang","album":"Liszt - My Piano Hero","uri":"NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Romance O pourquoi donc in E Minor, S. 169.flac","trackType":"flac"} May 08 07:10:08 minidsp-shd volumio[689]: verbose: CURRENT POSITION 0 May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::syncState stateService play May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::syncState currentStatus play May 08 07:10:08 minidsp-shd volumio[689]: info: Received an update from plugin. extracting info from payload May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::pushState May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushState May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output update for this device May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::pushState May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushState May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output update for this device May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output May 08 07:10:08 minidsp-shd volumio[689]: info: ControllerMpd::pushState May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::servicePushState May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:08 minidsp-shd volumio[689]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":185,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Romance \"O pourquoi donc\" in E Minor, S. 169","artist":"Lang Lang","album":"Liszt - My Piano Hero","uri":"NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Romance O pourquoi donc in E Minor, S. 169.flac","trackType":"flac"} May 08 07:10:08 minidsp-shd volumio[689]: verbose: CURRENT POSITION 0 May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::syncState stateService play May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::syncState currentStatus play May 08 07:10:08 minidsp-shd volumio[689]: info: Received an update from plugin. extracting info from payload May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::pushState May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushState May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output update for this device May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::pushState May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushState May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output update for this device May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output May 08 07:10:08 minidsp-shd volumio[689]: info: ------------------------------ 359ms May 08 07:10:08 minidsp-shd volumio[689]: info: ------------------------------ 379ms May 08 07:10:08 minidsp-shd volumio[689]: info: ------------------------------ 373ms May 08 07:10:08 minidsp-shd volumio[689]: info: sendMpdCommand playlistinfo took 268 milliseconds May 08 07:10:08 minidsp-shd volumio[689]: info: sendMpdCommand playlistinfo took 256 milliseconds May 08 07:10:08 minidsp-shd volumio[689]: info: sendMpdCommand playlistinfo took 255 milliseconds May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::parseTrackInfo May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::parseTrackInfo May 08 07:10:08 minidsp-shd volumio[689]: verbose: ControllerMpd::parseTrackInfo May 08 07:10:08 minidsp-shd volumio[689]: info: ControllerMpd::pushState May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::servicePushState May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:08 minidsp-shd volumio[689]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":185,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Romance \"O pourquoi donc\" in E Minor, S. 169","artist":"Lang Lang","album":"Liszt - My Piano Hero","uri":"NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Romance O pourquoi donc in E Minor, S. 169.flac","trackType":"flac"} May 08 07:10:08 minidsp-shd volumio[689]: verbose: CURRENT POSITION 0 May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::syncState stateService play May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::syncState currentStatus play May 08 07:10:08 minidsp-shd volumio[689]: info: Received an update from plugin. extracting info from payload May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::pushState May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushState May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output update for this device May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::pushState May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushState May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output update for this device May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output May 08 07:10:08 minidsp-shd volumio[689]: info: ControllerMpd::pushState May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::servicePushState May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:08 minidsp-shd volumio[689]: verbose: STATE SERVICE {"status":"play","position":0,"seek":225,"duration":185,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1035 Kbps","isStreaming":false,"title":"Romance \"O pourquoi donc\" in E Minor, S. 169","artist":"Lang Lang","album":"Liszt - My Piano Hero","uri":"NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Romance O pourquoi donc in E Minor, S. 169.flac","trackType":"flac"} May 08 07:10:08 minidsp-shd volumio[689]: verbose: CURRENT POSITION 0 May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::syncState stateService play May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::syncState currentStatus play May 08 07:10:08 minidsp-shd volumio[689]: info: Received an update from plugin. extracting info from payload May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::pushState May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushState May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output update for this device May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::pushState May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushState May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output update for this device May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output May 08 07:10:08 minidsp-shd volumio[689]: info: ControllerMpd::pushState May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::servicePushState May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:08 minidsp-shd volumio[689]: verbose: STATE SERVICE {"status":"play","position":0,"seek":866,"duration":185,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1734 Kbps","isStreaming":false,"title":"Romance \"O pourquoi donc\" in E Minor, S. 169","artist":"Lang Lang","album":"Liszt - My Piano Hero","uri":"NAS/乐曲/古典/《我的钢琴英雄！李斯特钢琴作品集 (LISZT - MY PIANO HERO !)》 - 郎朗/Romance O pourquoi donc in E Minor, S. 169.flac","trackType":"flac"} May 08 07:10:08 minidsp-shd volumio[689]: verbose: CURRENT POSITION 0 May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::syncState stateService play May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::syncState currentStatus play May 08 07:10:08 minidsp-shd volumio[689]: info: Received an update from plugin. extracting info from payload May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::pushState May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushState May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output update for this device May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output May 08 07:10:08 minidsp-shd volumio[689]: info: CoreStateMachine::pushState May 08 07:10:08 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:08 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushState May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output update for this device May 08 07:10:08 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output May 08 07:10:08 minidsp-shd volumio[689]: info: ------------------------------ 486ms May 08 07:10:08 minidsp-shd volumio[689]: info: ------------------------------ 450ms May 08 07:10:08 minidsp-shd volumio[689]: info: ------------------------------ 443ms May 08 07:10:08 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 08 07:10:08 minidsp-shd go-librespot[2203]: time="2024-05-08T07:10:08+08:00" level=debug msg="obtained new client token: AAAWl1refjLu/js9vf7u8rQKc06kLX/vD+hvTzXfGv8JXTRzqYQ55wFUKpGf7aVVYr4EbL4jMzXYRstV+iVEJm6EFI5D+iLYC1nMJXxhIhrKawlSnoE9sb205vHp6Xk8Jrmc0jNiFI0wWjGjNcjBBW2b6noWOBUkidFHo294xBCyaWXIJV0lwKHu5WsrMdDVFrqmcRvtRjn8N9tqgM6qik+gognDMez+1lErx5yiRlo7wzugnW3PYSygSADtdbjc" May 08 07:10:08 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 08 07:10:08 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 08 07:10:08 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 08 07:10:09 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 08 07:10:09 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 08 07:10:09 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 08 07:10:09 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 08 07:10:09 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 08 07:10:09 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 08 07:10:09 minidsp-shd go-librespot[2203]: time="2024-05-08T07:10:09+08: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]" May 08 07:10:09 minidsp-shd go-librespot[2203]: time="2024-05-08T07:10:09+08:00" level=debug msg="completed keyexchange" May 08 07:10:10 minidsp-shd go-librespot[2203]: time="2024-05-08T07:10:10+08:00" level=debug msg="completed challenge" May 08 07:10:10 minidsp-shd go-librespot[2203]: time="2024-05-08T07:10:10+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 08 07:10:10 minidsp-shd volumio[689]: info: Connection to go-librespot Websocket closed May 08 07:10:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 08 07:10:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 08 07:10:11 minidsp-shd volumio[689]: info: Getting Spotify volume May 08 07:10:11 minidsp-shd volumio[689]: (node:689) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:11 minidsp-shd volumio[689]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 08 07:10:11 minidsp-shd volumio[689]: (node:689) 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: 31) May 08 07:10:11 minidsp-shd volumio[689]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 May 08 07:10:11 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioGetState May 08 07:10:11 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:11 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 08 07:10:13 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:10:13 minidsp-shd volumio[689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:13 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 08 07:10:13 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. May 08 07:10:13 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 08 07:10:13 minidsp-shd systemd[1]: Started go-librespot Daemon. May 08 07:10:13 minidsp-shd go-librespot[2227]: Librespot-go daemon starting... May 08 07:10:13 minidsp-shd go-librespot[2227]: time="2024-05-08T07:10:13+08:00" level=info msg="generated new device id: 9000cfcf2c84cefba3d43312a3b3019c949853c1" May 08 07:10:13 minidsp-shd go-librespot[2227]: time="2024-05-08T07:10:13+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j" May 08 07:10:14 minidsp-shd go-librespot[2227]: time="2024-05-08T07:10:14+08:00" level=debug msg="obtained new client token: AAB/yPX1YlpcN2DMwDbh73R2KYMTNtqSfpCycYquM0TimOmCTVnhyjMuzim+3ze5Ra7KK68bxNfDCstzxXV+dXawmLEQeSijX0DXLmx8ZZ0HSpQUKlGQzIbAB/Qd8gQDZTIs/iqn/cMbL8iBwLzTDLLReU4gP+wC8nBtqEj04RmcElG2kYalKoNKDL9wnXCzyjSKYw/g4xiG2BfGZR2DRJlmfeLSab07wXckj+Q0KBolztiE+UK0Mz7D4mtubSsP" May 08 07:10:15 minidsp-shd go-librespot[2227]: time="2024-05-08T07:10:15+08: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]" May 08 07:10:15 minidsp-shd go-librespot[2227]: time="2024-05-08T07:10:15+08:00" level=debug msg="completed keyexchange" May 08 07:10:15 minidsp-shd go-librespot[2227]: time="2024-05-08T07:10:15+08:00" level=debug msg="completed challenge" May 08 07:10:15 minidsp-shd go-librespot[2227]: time="2024-05-08T07:10:15+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 08 07:10:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 08 07:10:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 08 07:10:16 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:10:16 minidsp-shd volumio[689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:18 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 08 07:10:18 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49. May 08 07:10:18 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 08 07:10:18 minidsp-shd systemd[1]: Started go-librespot Daemon. May 08 07:10:19 minidsp-shd go-librespot[2245]: Librespot-go daemon starting... May 08 07:10:19 minidsp-shd go-librespot[2245]: time="2024-05-08T07:10:19+08:00" level=info msg="generated new device id: 8263282e8e2c702e5ccbf40306a5a9b778a4e4e7" May 08 07:10:19 minidsp-shd go-librespot[2245]: time="2024-05-08T07:10:19+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j" May 08 07:10:19 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:10:19 minidsp-shd go-librespot[2245]: time="2024-05-08T07:10:19+08:00" level=debug msg="new websocket client" May 08 07:10:19 minidsp-shd volumio[689]: info: Connection to go-librespot Websocket established May 08 07:10:19 minidsp-shd go-librespot[2245]: time="2024-05-08T07:10:19+08:00" level=debug msg="obtained new client token: AABsnbpQBCwvDEH3qEY1hBQ1OHX7SOq6IZUzjchOKhs9neNyI1YsI40q3zBUafJWhGUWB9tUJzthCYZWKY6zL0GJRyH8h0Kb4mpx/ohzjcC2ui6rhA2a3gkWysXhwHD0ypMFZSDVKAqXq4DjJtioqI4edvFZihnxoi44HseupS5OXrXmCC5fi+9Cd7+oA0OxzxJdl2q3cUIFL79kJwIg7AJ8kSw7UQqNo2UlvcZA5EkB2Z2SG0byjVO95IXHKj5s" May 08 07:10:20 minidsp-shd go-librespot[2245]: time="2024-05-08T07:10:20+08: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]" May 08 07:10:20 minidsp-shd go-librespot[2245]: time="2024-05-08T07:10:20+08:00" level=debug msg="completed keyexchange" May 08 07:10:21 minidsp-shd go-librespot[2245]: time="2024-05-08T07:10:21+08:00" level=debug msg="completed challenge" May 08 07:10:21 minidsp-shd go-librespot[2245]: time="2024-05-08T07:10:21+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 08 07:10:21 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 08 07:10:21 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 08 07:10:21 minidsp-shd volumio[689]: info: Connection to go-librespot Websocket closed May 08 07:10:21 minidsp-shd volumio[689]: info: CoreCommandRouter::executeOnPlugin: inputs , setVolume May 08 07:10:21 minidsp-shd volumio[689]: info: msSurfaceDial volumioupdatevolume callback: {"vol":91,"dbVolume":-11.5,"mute":false,"disableVolumeControl":false} May 08 07:10:21 minidsp-shd volumio[689]: info: CoreStateMachine::pushState May 08 07:10:21 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:21 minidsp-shd volumio[689]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 07:10:21 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushState May 08 07:10:21 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output update for this device May 08 07:10:21 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output May 08 07:10:21 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 May 08 07:10:21 minidsp-shd volumio[689]: SPOTIFY: SPOTIFY VOLUME 90 May 08 07:10:21 minidsp-shd volumio[689]: SPOTIFY: VOLUMIO VOLUME 91 May 08 07:10:21 minidsp-shd volumio[689]: SPOTIFY: DELTA VOLUME ENOUGH: false May 08 07:10:22 minidsp-shd volumio[689]: info: Getting Spotify volume May 08 07:10:22 minidsp-shd volumio[689]: (node:689) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:22 minidsp-shd volumio[689]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 08 07:10:22 minidsp-shd volumio[689]: (node:689) 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: 32) May 08 07:10:22 minidsp-shd volumio[689]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 May 08 07:10:22 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioGetState May 08 07:10:22 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:22 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 May 08 07:10:22 minidsp-shd volumio[689]: SPOTIFY: SPOTIFY VOLUME 90 May 08 07:10:22 minidsp-shd volumio[689]: SPOTIFY: VOLUMIO VOLUME 91 May 08 07:10:22 minidsp-shd volumio[689]: SPOTIFY: DELTA VOLUME ENOUGH: false May 08 07:10:22 minidsp-shd volumio[689]: info: CoreCommandRouter::executeOnPlugin: inputs , setVolume May 08 07:10:22 minidsp-shd volumio[689]: info: msSurfaceDial volumioupdatevolume callback: {"vol":92,"dbVolume":-10,"mute":false,"disableVolumeControl":false} May 08 07:10:22 minidsp-shd volumio[689]: info: CoreStateMachine::pushState May 08 07:10:22 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:22 minidsp-shd volumio[689]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 07:10:22 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushState May 08 07:10:22 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output update for this device May 08 07:10:22 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output May 08 07:10:22 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 May 08 07:10:22 minidsp-shd volumio[689]: SPOTIFY: SPOTIFY VOLUME 90 May 08 07:10:22 minidsp-shd volumio[689]: SPOTIFY: VOLUMIO VOLUME 92 May 08 07:10:22 minidsp-shd volumio[689]: SPOTIFY: DELTA VOLUME ENOUGH: true May 08 07:10:22 minidsp-shd volumio[689]: info: Setting Spotify Volume from Volumio: 92 May 08 07:10:23 minidsp-shd volumio[689]: info: CoreCommandRouter::executeOnPlugin: inputs , setVolume May 08 07:10:23 minidsp-shd volumio[689]: info: msSurfaceDial volumioupdatevolume callback: {"vol":93,"dbVolume":-9,"mute":false,"disableVolumeControl":false} May 08 07:10:23 minidsp-shd volumio[689]: info: CoreStateMachine::pushState May 08 07:10:23 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:23 minidsp-shd volumio[689]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 07:10:23 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushState May 08 07:10:23 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output update for this device May 08 07:10:23 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output May 08 07:10:23 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 93 May 08 07:10:23 minidsp-shd volumio[689]: SPOTIFY: SPOTIFY VOLUME 92 May 08 07:10:23 minidsp-shd volumio[689]: SPOTIFY: VOLUMIO VOLUME 93 May 08 07:10:23 minidsp-shd volumio[689]: SPOTIFY: DELTA VOLUME ENOUGH: false May 08 07:10:24 minidsp-shd volumio[689]: SPOTIFY: SETTING SPOTIFY VOLUME 92 May 08 07:10:24 minidsp-shd volumio[689]: info: Sending Spotify command with payload to local API: /player/volume May 08 07:10:24 minidsp-shd volumio[689]: error: Failed to send command to Spotify local API: /player/volume: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:24 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:10:24 minidsp-shd volumio[689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:24 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 08 07:10:24 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. May 08 07:10:24 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 08 07:10:24 minidsp-shd systemd[1]: Started go-librespot Daemon. May 08 07:10:24 minidsp-shd go-librespot[2263]: Librespot-go daemon starting... May 08 07:10:24 minidsp-shd go-librespot[2263]: time="2024-05-08T07:10:24+08:00" level=info msg="generated new device id: d497220bd65af757f34087e4b551c13722065a87" May 08 07:10:24 minidsp-shd go-librespot[2263]: time="2024-05-08T07:10:24+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j" May 08 07:10:25 minidsp-shd volumio[689]: info: CoreCommandRouter::executeOnPlugin: inputs , setVolume May 08 07:10:25 minidsp-shd volumio[689]: info: msSurfaceDial volumioupdatevolume callback: {"vol":94,"dbVolume":-7.5,"mute":false,"disableVolumeControl":false} May 08 07:10:25 minidsp-shd volumio[689]: info: CoreStateMachine::pushState May 08 07:10:25 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:25 minidsp-shd volumio[689]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 07:10:25 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushState May 08 07:10:25 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output update for this device May 08 07:10:25 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output May 08 07:10:25 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 94 May 08 07:10:25 minidsp-shd volumio[689]: SPOTIFY: SPOTIFY VOLUME 92 May 08 07:10:25 minidsp-shd volumio[689]: SPOTIFY: VOLUMIO VOLUME 94 May 08 07:10:25 minidsp-shd volumio[689]: SPOTIFY: DELTA VOLUME ENOUGH: true May 08 07:10:25 minidsp-shd volumio[689]: info: Setting Spotify Volume from Volumio: 94 May 08 07:10:25 minidsp-shd go-librespot[2263]: time="2024-05-08T07:10:25+08:00" level=debug msg="obtained new client token: AADCq8G/bjdpR+3Dvf/12u0Y6nOn/7rpwBwbzE1T/R0bOUHiXpk+6scX3K/4b+bYI0yaF2Kn7TWzDV/we+RDiv8Qx7frQYlKJgIhTxYD8yC1iXG8eBR8RhSYQwirPxYt/EYo0F/zQzofmTHFJ0Bn0pHXDNlCCkDdH9remTUYHiTavlxNf1Npjs/kCYMnUwmadLknFclL0WigX25of/9mDQqPXBCIvQzAsPEdoDXfjK7iWYvHoFpHus9Vph/5ptNy" May 08 07:10:26 minidsp-shd go-librespot[2263]: time="2024-05-08T07:10:26+08: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]" May 08 07:10:26 minidsp-shd go-librespot[2263]: time="2024-05-08T07:10:26+08:00" level=debug msg="completed keyexchange" May 08 07:10:26 minidsp-shd go-librespot[2263]: time="2024-05-08T07:10:26+08:00" level=debug msg="completed challenge" May 08 07:10:26 minidsp-shd go-librespot[2263]: time="2024-05-08T07:10:26+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 08 07:10:26 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 08 07:10:26 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 08 07:10:26 minidsp-shd volumio[689]: SPOTIFY: SETTING SPOTIFY VOLUME 94 May 08 07:10:26 minidsp-shd volumio[689]: info: Sending Spotify command with payload to local API: /player/volume May 08 07:10:26 minidsp-shd volumio[689]: error: Failed to send command to Spotify local API: /player/volume: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:27 minidsp-shd volumio[689]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. May 08 07:10:27 minidsp-shd volumio[689]: info: Retrying Login Due to Network Error May 08 07:10:27 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:10:27 minidsp-shd volumio[689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:28 minidsp-shd volumio[689]: info: CoreCommandRouter::executeOnPlugin: inputs , setVolume May 08 07:10:28 minidsp-shd volumio[689]: info: msSurfaceDial volumioupdatevolume callback: {"vol":95,"dbVolume":-6.5,"mute":false,"disableVolumeControl":false} May 08 07:10:28 minidsp-shd volumio[689]: info: CoreStateMachine::pushState May 08 07:10:28 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:28 minidsp-shd volumio[689]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 07:10:28 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushState May 08 07:10:28 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output update for this device May 08 07:10:28 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output May 08 07:10:28 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 May 08 07:10:28 minidsp-shd volumio[689]: SPOTIFY: SPOTIFY VOLUME 94 May 08 07:10:28 minidsp-shd volumio[689]: SPOTIFY: VOLUMIO VOLUME 95 May 08 07:10:28 minidsp-shd volumio[689]: SPOTIFY: DELTA VOLUME ENOUGH: false May 08 07:10:28 minidsp-shd volumio[689]: info: msSurfaceDial volumioupdatevolume callback: {"vol":95,"dbVolume":-6.5,"mute":false,"disableVolumeControl":false} May 08 07:10:28 minidsp-shd volumio[689]: info: CoreStateMachine::pushState May 08 07:10:28 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:28 minidsp-shd volumio[689]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 07:10:28 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushState May 08 07:10:28 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output update for this device May 08 07:10:28 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output May 08 07:10:28 minidsp-shd volumio[689]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume May 08 07:10:28 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 May 08 07:10:28 minidsp-shd volumio[689]: SPOTIFY: SPOTIFY VOLUME 94 May 08 07:10:28 minidsp-shd volumio[689]: SPOTIFY: VOLUMIO VOLUME 95 May 08 07:10:28 minidsp-shd volumio[689]: SPOTIFY: DELTA VOLUME ENOUGH: false May 08 07:10:29 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 08 07:10:29 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. May 08 07:10:29 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 08 07:10:29 minidsp-shd systemd[1]: Started go-librespot Daemon. May 08 07:10:30 minidsp-shd go-librespot[2285]: Librespot-go daemon starting... May 08 07:10:30 minidsp-shd go-librespot[2285]: time="2024-05-08T07:10:30+08:00" level=info msg="generated new device id: aa10c980818ed7c951f29a61ce61026c48bbaa65" May 08 07:10:30 minidsp-shd go-librespot[2285]: time="2024-05-08T07:10:30+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j" May 08 07:10:30 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:10:30 minidsp-shd go-librespot[2285]: time="2024-05-08T07:10:30+08:00" level=debug msg="new websocket client" May 08 07:10:30 minidsp-shd volumio[689]: info: Connection to go-librespot Websocket established May 08 07:10:30 minidsp-shd go-librespot[2285]: time="2024-05-08T07:10:30+08:00" level=debug msg="obtained new client token: AACInmv3/Kan0MwymxMyVZIROPkhRTS185MXmOehbFB71Ueg+pDyyKCeEXD4j0ePkNRpQ8Rze9m+lns3gAH2/TT7/Q2ZdhOijei9i9ATY8s3cu0IWR4UkSJxhJDw+ATf2q0FJPjQxLzhvS8+siVUd4JWzyHDhwMrD9n2gKMjKTAplHPpPS4xTAfuILAKe7bL/gTTxIwocds6/cvcrBsFdScPRZtzGZxJMZoCwB4GbCiIG2DZfIoyggHqceUzAuwD" May 08 07:10:31 minidsp-shd go-librespot[2285]: time="2024-05-08T07:10:31+08: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]" May 08 07:10:31 minidsp-shd go-librespot[2285]: time="2024-05-08T07:10:31+08:00" level=debug msg="completed keyexchange" May 08 07:10:32 minidsp-shd go-librespot[2285]: time="2024-05-08T07:10:32+08:00" level=debug msg="completed challenge" May 08 07:10:32 minidsp-shd go-librespot[2285]: time="2024-05-08T07:10:32+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 08 07:10:32 minidsp-shd volumio[689]: info: Connection to go-librespot Websocket closed May 08 07:10:32 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 08 07:10:32 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 08 07:10:32 minidsp-shd volumio[689]: info: CoreCommandRouter::servicePushState May 08 07:10:32 minidsp-shd volumio[689]: info: CoreStateMachine::pushState May 08 07:10:32 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:32 minidsp-shd volumio[689]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 07:10:32 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioPushState May 08 07:10:32 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output update for this device May 08 07:10:32 minidsp-shd volumio[689]: info: MRS: Pushing multiroomSync output May 08 07:10:32 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:32 minidsp-shd volumio[689]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received raat May 08 07:10:32 minidsp-shd volumio[689]: info: Updating RAAT Signal Path May 08 07:10:32 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 May 08 07:10:32 minidsp-shd volumio[689]: SPOTIFY: SPOTIFY VOLUME 94 May 08 07:10:32 minidsp-shd volumio[689]: SPOTIFY: VOLUMIO VOLUME 95 May 08 07:10:32 minidsp-shd volumio[689]: SPOTIFY: DELTA VOLUME ENOUGH: false May 08 07:10:33 minidsp-shd volumio[689]: info: Getting Spotify volume May 08 07:10:33 minidsp-shd volumio[689]: (node:689) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:33 minidsp-shd volumio[689]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 08 07:10:33 minidsp-shd volumio[689]: (node:689) 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: 33) May 08 07:10:33 minidsp-shd volumio[689]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 May 08 07:10:33 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioGetState May 08 07:10:33 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:33 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 May 08 07:10:33 minidsp-shd volumio[689]: SPOTIFY: SPOTIFY VOLUME 94 May 08 07:10:33 minidsp-shd volumio[689]: SPOTIFY: VOLUMIO VOLUME 95 May 08 07:10:33 minidsp-shd volumio[689]: SPOTIFY: DELTA VOLUME ENOUGH: false May 08 07:10:35 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:10:35 minidsp-shd volumio[689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:35 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 08 07:10:35 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52. May 08 07:10:35 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 08 07:10:35 minidsp-shd systemd[1]: Started go-librespot Daemon. May 08 07:10:35 minidsp-shd go-librespot[2304]: Librespot-go daemon starting... May 08 07:10:35 minidsp-shd go-librespot[2304]: time="2024-05-08T07:10:35+08:00" level=info msg="generated new device id: ab5b75a9b9f7dcc3835e95904f6e997de186b5cb" May 08 07:10:35 minidsp-shd go-librespot[2304]: time="2024-05-08T07:10:35+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j" May 08 07:10:36 minidsp-shd go-librespot[2304]: time="2024-05-08T07:10:36+08:00" level=debug msg="obtained new client token: AABAw9eZ9x3ugLa/GvotXTRWudnBHTvwoL0D1vXyHxUGVd0Jyb8QXJXsI8Tq+e+p6YBoorQOS41P/IaybQfepAjsiFGBZeHmb2L6lFTibzhs4kDtQLsU6tbiKGZrBLwVhkzM0lcKfGfBUV/l5Gr+4aR7GmHOVzFkWWY6mFlOElzIa7edtmVQ3f83CwtPmU6gwSetph5L533cCRi2VqsMSFF7ShVx1soDqbt2Wu+T2EAkqiMqEUUfdlFZlteW/w1e" May 08 07:10:37 minidsp-shd volumio[689]: info: MyVolumio login type: Token May 08 07:10:37 minidsp-shd go-librespot[2304]: time="2024-05-08T07:10:37+08: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]" May 08 07:10:37 minidsp-shd go-librespot[2304]: time="2024-05-08T07:10:37+08:00" level=debug msg="completed keyexchange" May 08 07:10:37 minidsp-shd go-librespot[2304]: time="2024-05-08T07:10:37+08:00" level=debug msg="completed challenge" May 08 07:10:37 minidsp-shd go-librespot[2304]: time="2024-05-08T07:10:37+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 08 07:10:37 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 08 07:10:37 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 08 07:10:38 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:10:38 minidsp-shd volumio[689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:40 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 08 07:10:40 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53. May 08 07:10:40 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 08 07:10:40 minidsp-shd systemd[1]: Started go-librespot Daemon. May 08 07:10:41 minidsp-shd go-librespot[2324]: Librespot-go daemon starting... May 08 07:10:41 minidsp-shd go-librespot[2324]: time="2024-05-08T07:10:41+08:00" level=info msg="generated new device id: 47fd408c0bb53211982cf1f090ded57e10192ebc" May 08 07:10:41 minidsp-shd go-librespot[2324]: time="2024-05-08T07:10:41+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j" May 08 07:10:41 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:10:41 minidsp-shd go-librespot[2324]: time="2024-05-08T07:10:41+08:00" level=debug msg="new websocket client" May 08 07:10:41 minidsp-shd volumio[689]: info: Connection to go-librespot Websocket established May 08 07:10:41 minidsp-shd go-librespot[2324]: time="2024-05-08T07:10:41+08:00" level=debug msg="obtained new client token: AADEStRafPJimLHZkUPTVGgpmm7LsAqu6S4T8q4+KnCTh0GiodCSGkAoNgV16g8KEx5FW5ApKHfLaOnuT7KXJPy4PO5TNEjB/J6xkBmMWOm/J+cNZZFvpjvS3R5ttzDSzM+1LlsPbtYhA2c+aSfhjfvrb4A+EgcnXzpF+bqfaxCoHhpMYg20EoB9tv1k/3EIpPfn9ZigrMCS7nthpRZHW9EBwPxGEXk42+CQNuW5/ocAu72xE12XyFjF1hJu7c0C" May 08 07:10:42 minidsp-shd go-librespot[2324]: time="2024-05-08T07:10:42+08: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]" May 08 07:10:42 minidsp-shd go-librespot[2324]: time="2024-05-08T07:10:42+08:00" level=debug msg="completed keyexchange" May 08 07:10:43 minidsp-shd go-librespot[2324]: time="2024-05-08T07:10:43+08:00" level=debug msg="completed challenge" May 08 07:10:43 minidsp-shd go-librespot[2324]: time="2024-05-08T07:10:43+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 08 07:10:43 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 08 07:10:43 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 08 07:10:43 minidsp-shd volumio[689]: info: Connection to go-librespot Websocket closed May 08 07:10:44 minidsp-shd volumio[689]: info: Getting Spotify volume May 08 07:10:44 minidsp-shd volumio[689]: (node:689) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:44 minidsp-shd volumio[689]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 08 07:10:44 minidsp-shd volumio[689]: (node:689) 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: 34) May 08 07:10:44 minidsp-shd volumio[689]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 May 08 07:10:44 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioGetState May 08 07:10:44 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:44 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 May 08 07:10:44 minidsp-shd volumio[689]: SPOTIFY: SPOTIFY VOLUME 94 May 08 07:10:44 minidsp-shd volumio[689]: SPOTIFY: VOLUMIO VOLUME 95 May 08 07:10:44 minidsp-shd volumio[689]: SPOTIFY: DELTA VOLUME ENOUGH: false May 08 07:10:46 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:10:46 minidsp-shd volumio[689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:46 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 08 07:10:46 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54. May 08 07:10:46 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 08 07:10:46 minidsp-shd systemd[1]: Started go-librespot Daemon. May 08 07:10:46 minidsp-shd go-librespot[2344]: Librespot-go daemon starting... May 08 07:10:46 minidsp-shd go-librespot[2344]: time="2024-05-08T07:10:46+08:00" level=info msg="generated new device id: 493260737770d7ab5b2c9784b8ed0a3e0da0ad65" May 08 07:10:46 minidsp-shd go-librespot[2344]: time="2024-05-08T07:10:46+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j" May 08 07:10:47 minidsp-shd go-librespot[2344]: time="2024-05-08T07:10:47+08:00" level=debug msg="obtained new client token: AAALLP8BoeXMZyIbCL1U4ew2APsdvwCRcjJnIImm9PscvVC6yJoqLajI3t79HD72UqpSyxeQsLfr8HayISFDQEjrei9Pmef/wzyqh3R4YeGuAL8wAVbn93qPOUFiajJSOIWuvEwePX61ML0im25wPV347LLPI3AGygMFdyAUOxlJBOZ5Wed4F6rh9wvZRMbsUW33CjcRxqgG5UQ3Bc7a3yLKnG031vX5otIQ1c0CNG6DbU0LpxKWtFLRH9FDt+Ti" May 08 07:10:48 minidsp-shd go-librespot[2344]: time="2024-05-08T07:10:48+08: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]" May 08 07:10:48 minidsp-shd go-librespot[2344]: time="2024-05-08T07:10:48+08:00" level=debug msg="completed keyexchange" May 08 07:10:48 minidsp-shd go-librespot[2344]: time="2024-05-08T07:10:48+08:00" level=debug msg="completed challenge" May 08 07:10:48 minidsp-shd go-librespot[2344]: time="2024-05-08T07:10:48+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 08 07:10:48 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 08 07:10:48 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 08 07:10:49 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:10:49 minidsp-shd volumio[689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:51 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 08 07:10:51 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55. May 08 07:10:51 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 08 07:10:51 minidsp-shd systemd[1]: Started go-librespot Daemon. May 08 07:10:52 minidsp-shd go-librespot[2364]: Librespot-go daemon starting... May 08 07:10:52 minidsp-shd go-librespot[2364]: time="2024-05-08T07:10:52+08:00" level=info msg="generated new device id: cf9b5d18c8da56769bfe0900758b5796a8680a17" May 08 07:10:52 minidsp-shd go-librespot[2364]: time="2024-05-08T07:10:52+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j" May 08 07:10:52 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:10:52 minidsp-shd go-librespot[2364]: time="2024-05-08T07:10:52+08:00" level=debug msg="new websocket client" May 08 07:10:52 minidsp-shd volumio[689]: info: Connection to go-librespot Websocket established May 08 07:10:52 minidsp-shd go-librespot[2364]: time="2024-05-08T07:10:52+08:00" level=debug msg="obtained new client token: AABMzwkDMwz6JAeG3fqp+EnXKMxbmwUukU9dAxGIhf06fm6ru9wzQc1af6bfAvEYGLJYUmYzbcwceNm1o4r3FaKvccxkaAUG8iIqL+OhCK/HBpSfPp15RUhG3A45b6k+sfQcerKibGOZy7yxi2zYOn97DqJ6/d7DnAawuMY2gFhSSnc9OTn5gtfPr7TwCOhkJiSu6mzaE7MdOUu8Bp4nUzGy/4TEJwWczytja1uH4sIVBP4xhJqklDpy5nK8xbAS" May 08 07:10:53 minidsp-shd go-librespot[2364]: time="2024-05-08T07:10:53+08: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]" May 08 07:10:53 minidsp-shd go-librespot[2364]: time="2024-05-08T07:10:53+08:00" level=debug msg="completed keyexchange" May 08 07:10:54 minidsp-shd go-librespot[2364]: time="2024-05-08T07:10:54+08:00" level=debug msg="completed challenge" May 08 07:10:54 minidsp-shd go-librespot[2364]: time="2024-05-08T07:10:54+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 08 07:10:54 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 08 07:10:54 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 08 07:10:54 minidsp-shd volumio[689]: info: Connection to go-librespot Websocket closed May 08 07:10:55 minidsp-shd volumio[689]: info: Getting Spotify volume May 08 07:10:55 minidsp-shd volumio[689]: (node:689) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:55 minidsp-shd volumio[689]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 08 07:10:55 minidsp-shd volumio[689]: (node:689) 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: 35) May 08 07:10:55 minidsp-shd volumio[689]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 May 08 07:10:55 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioGetState May 08 07:10:55 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:10:55 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 May 08 07:10:55 minidsp-shd volumio[689]: SPOTIFY: SPOTIFY VOLUME 94 May 08 07:10:55 minidsp-shd volumio[689]: SPOTIFY: VOLUMIO VOLUME 95 May 08 07:10:55 minidsp-shd volumio[689]: SPOTIFY: DELTA VOLUME ENOUGH: false May 08 07:10:57 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:10:57 minidsp-shd volumio[689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:10:57 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 08 07:10:57 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56. May 08 07:10:57 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 08 07:10:57 minidsp-shd systemd[1]: Started go-librespot Daemon. May 08 07:10:57 minidsp-shd go-librespot[2420]: Librespot-go daemon starting... May 08 07:10:57 minidsp-shd go-librespot[2420]: time="2024-05-08T07:10:57+08:00" level=info msg="generated new device id: d60ca75aa9bccd6a76d577bd783ee184e5c108a6" May 08 07:10:57 minidsp-shd go-librespot[2420]: time="2024-05-08T07:10:57+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j" May 08 07:10:58 minidsp-shd go-librespot[2420]: time="2024-05-08T07:10:58+08:00" level=debug msg="obtained new client token: AADK8e42ipIIcsW95/0sJ13mEFTwJLyENfj7Rc9MeUFNAEc68IycJWNybptnO8NEVU5q0iI4PstapVKqzFtzXnA7oHCdilrlQHkP5es2PJJWtjKmucg8xUTN7P3eg3xODWyDThDl8R3tp7OzVPb8y/HGOIxThwaLZI9EyhyamPw3g4mGPexyvA+m6PxiN314hR67wfb5kplDOajZnc+otWLVrApRgRX9GpG6TXQSy564Om33Nm3FnJug46jF0fcX" May 08 07:10:59 minidsp-shd go-librespot[2420]: time="2024-05-08T07:10:59+08: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]" May 08 07:10:59 minidsp-shd go-librespot[2420]: time="2024-05-08T07:10:59+08:00" level=debug msg="completed keyexchange" May 08 07:10:59 minidsp-shd go-librespot[2420]: time="2024-05-08T07:10:59+08:00" level=debug msg="completed challenge" May 08 07:10:59 minidsp-shd go-librespot[2420]: time="2024-05-08T07:10:59+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 08 07:10:59 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 08 07:10:59 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 08 07:11:00 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:11:00 minidsp-shd volumio[689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:11:02 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 08 07:11:02 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57. May 08 07:11:02 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 08 07:11:02 minidsp-shd systemd[1]: Started go-librespot Daemon. May 08 07:11:03 minidsp-shd go-librespot[2441]: Librespot-go daemon starting... May 08 07:11:03 minidsp-shd go-librespot[2441]: time="2024-05-08T07:11:03+08:00" level=info msg="generated new device id: 35826e5682b552f6fdc53d2bdd5f14ba97c56e39" May 08 07:11:03 minidsp-shd go-librespot[2441]: time="2024-05-08T07:11:03+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j" May 08 07:11:03 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:11:03 minidsp-shd go-librespot[2441]: time="2024-05-08T07:11:03+08:00" level=debug msg="new websocket client" May 08 07:11:03 minidsp-shd volumio[689]: info: Connection to go-librespot Websocket established May 08 07:11:03 minidsp-shd go-librespot[2441]: time="2024-05-08T07:11:03+08:00" level=debug msg="obtained new client token: AAD9K65lPkzv5cwI35WeVr/L6hcTQqYpcAFfcRsBQZVHKGOVbxMJJaq+f9jxrd4CMvvVSM+6DqN5n4hGvm9UJ4jdOM6uV6RP7PXdq4pFw753qJg6XwHRJxIbcQr2XUOIG/+xwovfsedtyuKGk4/E9/e10hrfoZRFiSr+4Rjybz21RDZhdrEMPW2UhKp4gQcxNMMZPGno3lEPvNN7vFYvWz3OivZHG8Y9ORVdBlGtTAWajy+3JxsxXmrpkt3Y/Z18" May 08 07:11:04 minidsp-shd go-librespot[2441]: time="2024-05-08T07:11:04+08: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]" May 08 07:11:04 minidsp-shd go-librespot[2441]: time="2024-05-08T07:11:04+08:00" level=debug msg="completed keyexchange" May 08 07:11:05 minidsp-shd go-librespot[2441]: time="2024-05-08T07:11:05+08:00" level=debug msg="completed challenge" May 08 07:11:05 minidsp-shd go-librespot[2441]: time="2024-05-08T07:11:05+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 08 07:11:05 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 08 07:11:05 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 08 07:11:05 minidsp-shd volumio[689]: info: Connection to go-librespot Websocket closed May 08 07:11:06 minidsp-shd volumio[689]: info: Getting Spotify volume May 08 07:11:06 minidsp-shd volumio[689]: (node:689) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:11:06 minidsp-shd volumio[689]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 08 07:11:06 minidsp-shd volumio[689]: (node:689) 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: 36) May 08 07:11:06 minidsp-shd volumio[689]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 May 08 07:11:06 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioGetState May 08 07:11:06 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:11:06 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 May 08 07:11:06 minidsp-shd volumio[689]: SPOTIFY: SPOTIFY VOLUME 94 May 08 07:11:06 minidsp-shd volumio[689]: SPOTIFY: VOLUMIO VOLUME 95 May 08 07:11:06 minidsp-shd volumio[689]: SPOTIFY: DELTA VOLUME ENOUGH: false May 08 07:11:07 minidsp-shd volumio[689]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. May 08 07:11:07 minidsp-shd volumio[689]: info: Retrying Login Due to Network Error May 08 07:11:08 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:11:08 minidsp-shd volumio[689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:11:08 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 08 07:11:08 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 58. May 08 07:11:08 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 08 07:11:08 minidsp-shd systemd[1]: Started go-librespot Daemon. May 08 07:11:08 minidsp-shd go-librespot[2460]: Librespot-go daemon starting... May 08 07:11:08 minidsp-shd go-librespot[2460]: time="2024-05-08T07:11:08+08:00" level=info msg="generated new device id: 79050dbf59a8566ff5a6d2868c21109e74be6d08" May 08 07:11:08 minidsp-shd go-librespot[2460]: time="2024-05-08T07:11:08+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j" May 08 07:11:09 minidsp-shd go-librespot[2460]: time="2024-05-08T07:11:09+08:00" level=debug msg="obtained new client token: AABft5HsQ2R5CggKB6fxB1BPv0QegjCCAz6GSGZo2WLryugBzLDKXJQeNbs5HE1FEQhZaT9mm+gA4TDje2p2Ih0DmK9zo4K4+Xzrb1NbZNdyHrwDtSene+yKp2G+hBLeJLiLq+mnXpfr1YUldjcIXpqeyTmccdNAlH7F3vrRXKl+rpqiUBLiSLEblKX3FTuGCVYaNvXvGCC4d2RhA8guNOSW1+Og/a/ePjs2nKFPK91cloMrTKVonL6PUsiYSpWY" May 08 07:11:10 minidsp-shd go-librespot[2460]: time="2024-05-08T07:11:10+08: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]" May 08 07:11:10 minidsp-shd go-librespot[2460]: time="2024-05-08T07:11:10+08:00" level=debug msg="completed keyexchange" May 08 07:11:10 minidsp-shd go-librespot[2460]: time="2024-05-08T07:11:10+08:00" level=debug msg="completed challenge" May 08 07:11:10 minidsp-shd go-librespot[2460]: time="2024-05-08T07:11:10+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 08 07:11:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 08 07:11:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 08 07:11:11 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:11:11 minidsp-shd volumio[689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:11:13 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 08 07:11:13 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59. May 08 07:11:13 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 08 07:11:13 minidsp-shd systemd[1]: Started go-librespot Daemon. May 08 07:11:14 minidsp-shd go-librespot[2479]: Librespot-go daemon starting... May 08 07:11:14 minidsp-shd go-librespot[2479]: time="2024-05-08T07:11:14+08:00" level=info msg="generated new device id: fd90ff5d1bcb138aa85461e916f4b767db02ec19" May 08 07:11:14 minidsp-shd go-librespot[2479]: time="2024-05-08T07:11:14+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j" May 08 07:11:14 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:11:14 minidsp-shd go-librespot[2479]: time="2024-05-08T07:11:14+08:00" level=debug msg="new websocket client" May 08 07:11:14 minidsp-shd volumio[689]: info: Connection to go-librespot Websocket established May 08 07:11:14 minidsp-shd go-librespot[2479]: time="2024-05-08T07:11:14+08:00" level=debug msg="obtained new client token: AABT4DhWcSame/FSnxtodvJ0SBaqA47oJh9/Q5K99mvK12GdAvNOTWzSD+48/ab9aX+aS4l3CwpzuCfLgFOC3TQzk9DZE254cJpENrQsMSuGyQqJFbT7TaqEYz/vZTxpIG0kegvvAh1awYu4Jgi7X+lxkBI07dpB8r7hqLss80kpRevtBwak2WhihVKDtaoP6Nxfv4M0tYMsOlE6c0Vkw9wVw2Kucq0/WmmcAJOWXcOojXHXR9Uh/SlbNVF6FhLV" May 08 07:11:15 minidsp-shd go-librespot[2479]: time="2024-05-08T07:11:15+08: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]" May 08 07:11:15 minidsp-shd go-librespot[2479]: time="2024-05-08T07:11:15+08:00" level=debug msg="completed keyexchange" May 08 07:11:16 minidsp-shd go-librespot[2479]: time="2024-05-08T07:11:16+08:00" level=debug msg="completed challenge" May 08 07:11:16 minidsp-shd go-librespot[2479]: time="2024-05-08T07:11:16+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 08 07:11:16 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 08 07:11:16 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 08 07:11:16 minidsp-shd volumio[689]: info: Connection to go-librespot Websocket closed May 08 07:11:17 minidsp-shd volumio[689]: info: MyVolumio login type: Token May 08 07:11:17 minidsp-shd volumio[689]: info: Getting Spotify volume May 08 07:11:17 minidsp-shd volumio[689]: (node:689) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:11:17 minidsp-shd volumio[689]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 08 07:11:17 minidsp-shd volumio[689]: (node:689) 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: 37) May 08 07:11:17 minidsp-shd volumio[689]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 May 08 07:11:17 minidsp-shd volumio[689]: info: CoreCommandRouter::volumioGetState May 08 07:11:17 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:11:17 minidsp-shd volumio[689]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 May 08 07:11:17 minidsp-shd volumio[689]: SPOTIFY: SPOTIFY VOLUME 94 May 08 07:11:17 minidsp-shd volumio[689]: SPOTIFY: VOLUMIO VOLUME 95 May 08 07:11:17 minidsp-shd volumio[689]: SPOTIFY: DELTA VOLUME ENOUGH: false May 08 07:11:19 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:11:19 minidsp-shd volumio[689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:11:19 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 08 07:11:19 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 60. May 08 07:11:19 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 08 07:11:19 minidsp-shd systemd[1]: Started go-librespot Daemon. May 08 07:11:19 minidsp-shd go-librespot[2500]: Librespot-go daemon starting... May 08 07:11:19 minidsp-shd go-librespot[2500]: time="2024-05-08T07:11:19+08:00" level=info msg="generated new device id: b46a1d6699f38ae66bfb6394d6aac3f9fbaaaa84" May 08 07:11:19 minidsp-shd go-librespot[2500]: time="2024-05-08T07:11:19+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j" May 08 07:11:20 minidsp-shd volumio[689]: info: CoreCommandRouter::servicePushState May 08 07:11:20 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:11:20 minidsp-shd volumio[689]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received raat May 08 07:11:20 minidsp-shd volumio[689]: info: Updating RAAT Signal Path May 08 07:11:20 minidsp-shd go-librespot[2500]: time="2024-05-08T07:11:20+08:00" level=debug msg="obtained new client token: AABUnSFdkyycK4YsOdeHC0Bm4Y2SL1oXCNv8V4MpWin4fGcG2hA/fBAmSTIJovM8r0EAqJQR28Ww9rrTFA7G1cq55qGJbFqpgGxsOmmzgdQJFLlI4+//STt4YcVbvm23rxpidhTDA9WXc8knyRraQDjsn2KyQtVl1d/H5vkgsc5iYMcug1wpBNog7uWo/x5OhCZct883dTWpIWyphtpgAE7szNmjf3mFx7+XofzB23/BRQeBol5d1M4msAn1cfsB" May 08 07:11:20 minidsp-shd volumio[689]: info: CoreCommandRouter::servicePushState May 08 07:11:20 minidsp-shd volumio[689]: info: CorePlayQueue::getTrack 0 May 08 07:11:20 minidsp-shd volumio[689]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received raat May 08 07:11:21 minidsp-shd go-librespot[2500]: time="2024-05-08T07:11:21+08: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]" May 08 07:11:21 minidsp-shd go-librespot[2500]: time="2024-05-08T07:11:21+08:00" level=debug msg="completed keyexchange" May 08 07:11:21 minidsp-shd go-librespot[2500]: time="2024-05-08T07:11:21+08:00" level=debug msg="completed challenge" May 08 07:11:21 minidsp-shd go-librespot[2500]: time="2024-05-08T07:11:21+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 08 07:11:21 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 08 07:11:21 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 08 07:11:22 minidsp-shd volumio[689]: info: Initializing connection to go-librespot Websocket May 08 07:11:22 minidsp-shd volumio[689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 08 07:11:22 minidsp-shd volumio[689]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 08 07:11:22 minidsp-shd volumio[689]: Error: connect ETIMEDOUT 157.240.20.8:443 May 08 07:11:22 minidsp-shd volumio[689]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { May 08 07:11:22 minidsp-shd volumio[689]: errno: -110, May 08 07:11:22 minidsp-shd volumio[689]: code: 'ETIMEDOUT', May 08 07:11:22 minidsp-shd volumio[689]: syscall: 'connect', May 08 07:11:22 minidsp-shd volumio[689]: address: '157.240.20.8', May 08 07:11:22 minidsp-shd volumio[689]: port: 443 May 08 07:11:22 minidsp-shd volumio[689]: } May 08 07:11:22 minidsp-shd volumio[689]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 08 07:11:23 minidsp-shd sudo[2523]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-08 07:10 May 08 07:11:23 minidsp-shd sudo[2523]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="17fcb754ddd6bd152b01008c46cc4ba1ca48bf35" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="281cefcd7a302aa7cfba569185cf7aae19b8c376" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 22 Mar 2024 03:13:25 PM CET" VOLUMIO_VERSION="3.608" VOLUMIO_HARDWARE="nanopineo3" VOLUMIO_DEVICENAME="Nanopi Neo3" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="18533ba33f8f92d7e7e459bb30f70beb"