-- Logs begin at Tue 2025-03-11 16:31:10 UTC, end at Tue 2025-03-11 18:52:54 UTC. -- Mar 11 18:51:00 volumio volumio[875]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 11 18:51:00 volumio volumio[875]: info: CURURI: music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits Mar 11 18:51:00 volumio volumio[875]: info: Preload queue cleared Mar 11 18:51:00 volumio volumio[875]: info: Preloading song: music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/01 - Dire Straits - Down To The Waterline.dsf Mar 11 18:51:00 volumio volumio[875]: info: Preloading song: music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/02 - Dire Straits - Water Of Love.dsf Mar 11 18:51:00 volumio volumio[875]: info: Preloading song: music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/03 - Dire Straits - Setting Me Up.dsf Mar 11 18:51:00 volumio volumio[875]: info: Preloading song: music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/04 - Dire Straits - Six Blade Knife.dsf Mar 11 18:51:00 volumio volumio[875]: info: Preloading song: music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/05 - Dire Straits - Southbound Again.dsf Mar 11 18:51:00 volumio volumio[875]: info: Preloading song: music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/06 - Dire Straits - Sultans Of Swing.dsf Mar 11 18:51:00 volumio volumio[875]: info: Preloading song: music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/07 - Dire Straits - In The Gallery.dsf Mar 11 18:51:00 volumio volumio[875]: info: Preloading song: music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/08 - Dire Straits - Wild West End.dsf Mar 11 18:51:00 volumio volumio[875]: info: Preloading song: music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/09 - Dire Straits - Lions.dsf Mar 11 18:51:00 volumio volumio[875]: info: Exploding uri music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/01 - Dire Straits - Down To The Waterline.dsf in service mpd Mar 11 18:51:00 volumio volumio[875]: info: ALBUMART /albumart?cacheid=114&web=Dire%20Straits/Dire%20Straits/extralarge&path=%2Fmnt%2FNAS%2FDSD_MUSIC%2FSACD%20A-E%2FDire%20Straits%20-%20Dire%20Straits%20(1978)%20%5B2019%5D%20MFSL%2FDire%20Straits%20-%20Dire%20Straits%2F01%20-%20Dire%20Straits%20-%20Down%20To%20The%20Waterline.dsf&metadata=false Mar 11 18:51:00 volumio volumio[875]: info: URI /mnt/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/01 - Dire Straits - Down To The Waterline.dsf Mar 11 18:51:00 volumio volumio[875]: info: Exploding uri music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/02 - Dire Straits - Water Of Love.dsf in service mpd Mar 11 18:51:00 volumio volumio[875]: info: ALBUMART /albumart?cacheid=114&web=Dire%20Straits/Dire%20Straits/extralarge&path=%2Fmnt%2FNAS%2FDSD_MUSIC%2FSACD%20A-E%2FDire%20Straits%20-%20Dire%20Straits%20(1978)%20%5B2019%5D%20MFSL%2FDire%20Straits%20-%20Dire%20Straits%2F02%20-%20Dire%20Straits%20-%20Water%20Of%20Love.dsf&metadata=false Mar 11 18:51:00 volumio volumio[875]: info: URI /mnt/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/02 - Dire Straits - Water Of Love.dsf Mar 11 18:51:00 volumio volumio[875]: info: Exploding uri music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/03 - Dire Straits - Setting Me Up.dsf in service mpd Mar 11 18:51:00 volumio volumio[875]: info: ALBUMART /albumart?cacheid=114&web=Dire%20Straits/Dire%20Straits/extralarge&path=%2Fmnt%2FNAS%2FDSD_MUSIC%2FSACD%20A-E%2FDire%20Straits%20-%20Dire%20Straits%20(1978)%20%5B2019%5D%20MFSL%2FDire%20Straits%20-%20Dire%20Straits%2F03%20-%20Dire%20Straits%20-%20Setting%20Me%20Up.dsf&metadata=false Mar 11 18:51:00 volumio volumio[875]: info: URI /mnt/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/03 - Dire Straits - Setting Me Up.dsf Mar 11 18:51:00 volumio volumio[875]: info: Exploding uri music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/04 - Dire Straits - Six Blade Knife.dsf in service mpd Mar 11 18:51:00 volumio volumio[875]: info: ALBUMART /albumart?cacheid=114&web=Dire%20Straits/Dire%20Straits/extralarge&path=%2Fmnt%2FNAS%2FDSD_MUSIC%2FSACD%20A-E%2FDire%20Straits%20-%20Dire%20Straits%20(1978)%20%5B2019%5D%20MFSL%2FDire%20Straits%20-%20Dire%20Straits%2F04%20-%20Dire%20Straits%20-%20Six%20Blade%20Knife.dsf&metadata=false Mar 11 18:51:00 volumio volumio[875]: info: URI /mnt/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/04 - Dire Straits - Six Blade Knife.dsf Mar 11 18:51:00 volumio volumio[875]: info: Exploding uri music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/05 - Dire Straits - Southbound Again.dsf in service mpd Mar 11 18:51:00 volumio volumio[875]: info: ALBUMART /albumart?cacheid=114&web=Dire%20Straits/Dire%20Straits/extralarge&path=%2Fmnt%2FNAS%2FDSD_MUSIC%2FSACD%20A-E%2FDire%20Straits%20-%20Dire%20Straits%20(1978)%20%5B2019%5D%20MFSL%2FDire%20Straits%20-%20Dire%20Straits%2F05%20-%20Dire%20Straits%20-%20Southbound%20Again.dsf&metadata=false Mar 11 18:51:00 volumio volumio[875]: info: URI /mnt/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/05 - Dire Straits - Southbound Again.dsf Mar 11 18:51:00 volumio volumio[875]: info: Exploding uri music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/06 - Dire Straits - Sultans Of Swing.dsf in service mpd Mar 11 18:51:00 volumio volumio[875]: info: ALBUMART /albumart?cacheid=114&web=Dire%20Straits/Dire%20Straits/extralarge&path=%2Fmnt%2FNAS%2FDSD_MUSIC%2FSACD%20A-E%2FDire%20Straits%20-%20Dire%20Straits%20(1978)%20%5B2019%5D%20MFSL%2FDire%20Straits%20-%20Dire%20Straits%2F06%20-%20Dire%20Straits%20-%20Sultans%20Of%20Swing.dsf&metadata=false Mar 11 18:51:00 volumio volumio[875]: info: URI /mnt/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/06 - Dire Straits - Sultans Of Swing.dsf Mar 11 18:51:00 volumio volumio[875]: info: Exploding uri music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/07 - Dire Straits - In The Gallery.dsf in service mpd Mar 11 18:51:00 volumio volumio[875]: info: ALBUMART /albumart?cacheid=114&web=Dire%20Straits/Dire%20Straits/extralarge&path=%2Fmnt%2FNAS%2FDSD_MUSIC%2FSACD%20A-E%2FDire%20Straits%20-%20Dire%20Straits%20(1978)%20%5B2019%5D%20MFSL%2FDire%20Straits%20-%20Dire%20Straits%2F07%20-%20Dire%20Straits%20-%20In%20The%20Gallery.dsf&metadata=false Mar 11 18:51:00 volumio volumio[875]: info: URI /mnt/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/07 - Dire Straits - In The Gallery.dsf Mar 11 18:51:00 volumio volumio[875]: info: Exploding uri music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/08 - Dire Straits - Wild West End.dsf in service mpd Mar 11 18:51:00 volumio volumio[875]: info: ALBUMART /albumart?cacheid=114&web=Dire%20Straits/Dire%20Straits/extralarge&path=%2Fmnt%2FNAS%2FDSD_MUSIC%2FSACD%20A-E%2FDire%20Straits%20-%20Dire%20Straits%20(1978)%20%5B2019%5D%20MFSL%2FDire%20Straits%20-%20Dire%20Straits%2F08%20-%20Dire%20Straits%20-%20Wild%20West%20End.dsf&metadata=false Mar 11 18:51:00 volumio volumio[875]: info: URI /mnt/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/08 - Dire Straits - Wild West End.dsf Mar 11 18:51:00 volumio volumio[875]: info: Exploding uri music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/09 - Dire Straits - Lions.dsf in service mpd Mar 11 18:51:00 volumio volumio[875]: info: ALBUMART /albumart?cacheid=114&web=Dire%20Straits/Dire%20Straits/extralarge&path=%2Fmnt%2FNAS%2FDSD_MUSIC%2FSACD%20A-E%2FDire%20Straits%20-%20Dire%20Straits%20(1978)%20%5B2019%5D%20MFSL%2FDire%20Straits%20-%20Dire%20Straits%2F09%20-%20Dire%20Straits%20-%20Lions.dsf&metadata=false Mar 11 18:51:00 volumio volumio[875]: info: URI /mnt/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/09 - Dire Straits - Lions.dsf Mar 11 18:51:00 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:00 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:00 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:00 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:00 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:51:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7196. Mar 11 18:51:00 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:51:01 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:51:01 volumio go-librespot[21076]: Librespot-go daemon starting... Mar 11 18:51:01 volumio go-librespot[21076]: time="2025-03-11T18:51:01Z" level=info msg="generated new device id: a5a596305d7490941cd33952f245a778dea4d712" Mar 11 18:51:01 volumio go-librespot[21076]: time="2025-03-11T18:51:01Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:51:01 volumio go-librespot[21076]: time="2025-03-11T18:51:01Z" level=debug msg="obtained new client token: AAArByIGlC6ACalmkxsLBc6l25300LZoKF+rWCsaTUY5pDkwhmnUgxJTcFKzOVaIWG5yrmmb7r7vlIQzemtWLuGe/AddCsLYDwPqDcdBE1CYNslwOU3qsNfOCtxudJ4XgDlnjFtFR8Z+n+1q078MwWjLD6PtdPQRl4NAZEEKq1Sf+8lif43jkj7popiyBQy/lMB0v3so8GS4CdhLcJK2mBn3wZWYh6h92XPizQCM31i/R8qvdBUTcECwH8tx" Mar 11 18:51:01 volumio go-librespot[21076]: time="2025-03-11T18:51:01Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:51:01 volumio go-librespot[21076]: time="2025-03-11T18:51:01Z" level=debug msg="completed keyexchange" Mar 11 18:51:01 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:01 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:01 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:01 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:01 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:01 volumio go-librespot[21076]: time="2025-03-11T18:51:01Z" level=debug msg="completed challenge" Mar 11 18:51:01 volumio go-librespot[21076]: time="2025-03-11T18:51:01Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:51:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:51:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:51:02 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:02 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:02 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:02 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:02 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:02 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:02 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:03 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:03 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:03 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:03 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:03 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:04 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:04 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:04 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:04 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:04 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:51:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7197. Mar 11 18:51:04 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:51:05 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:51:05 volumio go-librespot[21090]: Librespot-go daemon starting... Mar 11 18:51:05 volumio go-librespot[21090]: time="2025-03-11T18:51:05Z" level=info msg="generated new device id: 2690459aa7239885693eee700fae92c6d4f940ba" Mar 11 18:51:05 volumio go-librespot[21090]: time="2025-03-11T18:51:05Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:51:05 volumio go-librespot[21090]: time="2025-03-11T18:51:05Z" level=debug msg="obtained new client token: AAD/YSV4jle314XAWP7V9/o2hLV+WvnYChv+ZfmFwwW985t3dCTCTzJ4Y+iBpL/jSk65Yt35Z5TDNJUvr4QavuiE19lH1X17XSD29sDy/SgAp2mhGYrbSrxvNl4O1zy1nP9Pmj+gn8MDwGWk35pm2bim8abdUSyAlyM3JY0BMZxlSSv+qfdCK+0l2Y6+zaQLzMEoadAbX/8stBSEp4Gncd8LpmzXLj2NGb68HjJCUurTxoNqoxYIw26LA/PV" Mar 11 18:51:05 volumio go-librespot[21090]: time="2025-03-11T18:51:05Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 11 18:51:05 volumio go-librespot[21090]: time="2025-03-11T18:51:05Z" level=debug msg="completed keyexchange" Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::ClearQueue Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::stop Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::stPlaybackTimer Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::updateTrackBlock Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrackBlock Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::pushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushState Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::serviceStop Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::serviceStop Mar 11 18:51:05 volumio volumio[875]: info: ControllerMpd::stop Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand stop Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::clearPlayQueue Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::saveQueue Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushQueue Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::addQueueItems Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::addQueueItems Mar 11 18:51:05 volumio volumio[875]: info: Preload queue cleared Mar 11 18:51:05 volumio volumio[875]: info: Adding Item to queue: music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/06 - Dire Straits - Sultans Of Swing.dsf Mar 11 18:51:05 volumio volumio[875]: info: Using cached record of: music-library/NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/06 - Dire Straits - Sultans Of Swing.dsf Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushQueue Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::saveQueue Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::updateTrackBlock Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrackBlock Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPlay Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::play index 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::stop Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::play index undefined Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::startPlaybackTimer Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::clearAddPlayTracks NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/06 - Dire Straits - Sultans Of Swing.dsf Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand stop Mar 11 18:51:05 volumio volumio[875]: info: Mar 11 18:51:05 volumio volumio[875]: ---------------------------- MPD announces state update: player Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand stop took 18 milliseconds Mar 11 18:51:05 volumio volumio[875]: info: ControllerMpd::getState Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand status Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand stop took 12 milliseconds Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand status took 0 milliseconds Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand clear Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::parseState Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 18:51:05 volumio volumio[875]: info: Mar 11 18:51:05 volumio volumio[875]: ---------------------------- MPD announces state update: player Mar 11 18:51:05 volumio volumio[875]: info: ControllerMpd::getState Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand status Mar 11 18:51:05 volumio volumio[875]: info: Mar 11 18:51:05 volumio volumio[875]: ---------------------------- MPD announces state update: player Mar 11 18:51:05 volumio volumio[875]: info: ControllerMpd::getState Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand status Mar 11 18:51:05 volumio volumio[875]: info: Mar 11 18:51:05 volumio volumio[875]: ---------------------------- MPD announces system playlist update Mar 11 18:51:05 volumio volumio[875]: info: Ignoring MPD Status Update Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand clear took 2 milliseconds Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand status took 2 milliseconds Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand status took 1 milliseconds Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand add "NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/06 - Dire Straits - Sultans Of Swing.dsf" Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::parseTrackInfo Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::parseState Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::parseState Mar 11 18:51:05 volumio volumio[875]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Mar 11 18:51:05 volumio volumio[875]: info: ControllerMpd::pushState Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::servicePushState Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::pushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Mar 11 18:51:05 volumio volumio[875]: verbose: CURRENT POSITION 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::syncState stateService stop Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::syncState currentStatus stop Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::pushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushState Mar 11 18:51:05 volumio volumio[875]: info: No code Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::pushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushState Mar 11 18:51:05 volumio volumio[875]: info: ControllerMpd::pushState Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::servicePushState Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::pushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Mar 11 18:51:05 volumio volumio[875]: verbose: CURRENT POSITION 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::syncState stateService stop Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::syncState currentStatus stop Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::pushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushState Mar 11 18:51:05 volumio volumio[875]: info: No code Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::pushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushState Mar 11 18:51:05 volumio volumio[875]: info: ------------------------------ 14ms Mar 11 18:51:05 volumio volumio[875]: info: ------------------------------ 22ms Mar 11 18:51:05 volumio volumio[875]: info: ------------------------------ 22ms Mar 11 18:51:05 volumio volumio[875]: info: Mar 11 18:51:05 volumio volumio[875]: ---------------------------- MPD announces system playlist update Mar 11 18:51:05 volumio volumio[875]: info: Ignoring MPD Status Update Mar 11 18:51:05 volumio volumio[875]: info: Mar 11 18:51:05 volumio volumio[875]: ---------------------------- MPD announces system playlist update Mar 11 18:51:05 volumio volumio[875]: info: Ignoring MPD Status Update Mar 11 18:51:05 volumio volumio[875]: error: updateQueue error: null Mar 11 18:51:05 volumio volumio[875]: info: Mar 11 18:51:05 volumio volumio[875]: ---------------------------- MPD announces system playlist update Mar 11 18:51:05 volumio volumio[875]: info: Ignoring MPD Status Update Mar 11 18:51:05 volumio volumio[875]: info: ------------------------------ 24ms Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand add "NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/06 - Dire Straits - Sultans Of Swing.dsf" took 23 milliseconds Mar 11 18:51:05 volumio volumio[875]: info: ------------------------------ 3ms Mar 11 18:51:05 volumio volumio[875]: info: ------------------------------ 2ms Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand play Mar 11 18:51:05 volumio volumio[875]: info: Mar 11 18:51:05 volumio volumio[875]: ---------------------------- MPD announces system playlist update Mar 11 18:51:05 volumio volumio[875]: info: Ignoring MPD Status Update Mar 11 18:51:05 volumio volumio[875]: info: Mar 11 18:51:05 volumio volumio[875]: ---------------------------- MPD announces system playlist update Mar 11 18:51:05 volumio volumio[875]: info: Ignoring MPD Status Update Mar 11 18:51:05 volumio volumio[875]: info: ------------------------------ 8ms Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand play took 7 milliseconds Mar 11 18:51:05 volumio volumio[875]: info: ------------------------------ 8ms Mar 11 18:51:05 volumio volumio[875]: info: ------------------------------ 7ms Mar 11 18:51:05 volumio volumio[875]: info: Mar 11 18:51:05 volumio volumio[875]: ---------------------------- MPD announces state update: player Mar 11 18:51:05 volumio volumio[875]: info: ControllerMpd::getState Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand status Mar 11 18:51:05 volumio volumio[875]: info: Mar 11 18:51:05 volumio volumio[875]: ---------------------------- MPD announces state update: player Mar 11 18:51:05 volumio volumio[875]: info: ControllerMpd::getState Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand status Mar 11 18:51:05 volumio volumio[875]: info: Mar 11 18:51:05 volumio volumio[875]: ---------------------------- MPD announces state update: player Mar 11 18:51:05 volumio volumio[875]: info: ControllerMpd::getState Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand status Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand status took 145 milliseconds Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::parseState Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 18:51:05 volumio volumio[875]: info: Mar 11 18:51:05 volumio volumio[875]: ---------------------------- MPD announces state update: player Mar 11 18:51:05 volumio volumio[875]: info: ControllerMpd::getState Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand status Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand status took 147 milliseconds Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand status took 145 milliseconds Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::parseState Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::parseState Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::parseTrackInfo Mar 11 18:51:05 volumio volumio[875]: info: ControllerMpd::pushState Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::servicePushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":349,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"Sultans Of Swing","artist":"Dire Straits","album":"Dire Straits","uri":"NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/06 - Dire Straits - Sultans Of Swing.dsf","trackType":"dsf"} Mar 11 18:51:05 volumio volumio[875]: verbose: CURRENT POSITION 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::syncState stateService play Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::syncState currentStatus stop Mar 11 18:51:05 volumio volumio[875]: info: ------------------------------ 152ms Mar 11 18:51:05 volumio volumio[875]: info: Mar 11 18:51:05 volumio volumio[875]: ---------------------------- MPD announces state update: player Mar 11 18:51:05 volumio volumio[875]: info: ControllerMpd::getState Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand status Mar 11 18:51:05 volumio volumio[875]: info: Mar 11 18:51:05 volumio volumio[875]: ---------------------------- MPD announces state update: player Mar 11 18:51:05 volumio volumio[875]: info: ControllerMpd::getState Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand status Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand status took 6 milliseconds Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand playlistinfo took 5 milliseconds Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand playlistinfo took 5 milliseconds Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand status took 2 milliseconds Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand status took 2 milliseconds Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::parseState Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::parseTrackInfo Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::parseTrackInfo Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::parseState Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::parseState Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 18:51:05 volumio volumio[875]: info: ControllerMpd::pushState Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::servicePushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: verbose: STATE SERVICE {"status":"play","position":0,"seek":22,"duration":349,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"Sultans Of Swing","artist":"Dire Straits","album":"Dire Straits","uri":"NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/06 - Dire Straits - Sultans Of Swing.dsf","trackType":"dsf"} Mar 11 18:51:05 volumio volumio[875]: verbose: CURRENT POSITION 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::syncState stateService play Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::syncState currentStatus play Mar 11 18:51:05 volumio volumio[875]: info: Received an update from plugin. extracting info from payload Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::pushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushState Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::pushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushState Mar 11 18:51:05 volumio volumio[875]: info: ControllerMpd::pushState Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::servicePushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45,"duration":349,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"Sultans Of Swing","artist":"Dire Straits","album":"Dire Straits","uri":"NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/06 - Dire Straits - Sultans Of Swing.dsf","trackType":"dsf"} Mar 11 18:51:05 volumio volumio[875]: verbose: CURRENT POSITION 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::syncState stateService play Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::syncState currentStatus play Mar 11 18:51:05 volumio volumio[875]: info: Received an update from plugin. extracting info from payload Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::pushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushState Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::pushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushState Mar 11 18:51:05 volumio volumio[875]: info: ------------------------------ 179ms Mar 11 18:51:05 volumio volumio[875]: info: ------------------------------ 179ms Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand playlistinfo took 26 milliseconds Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand playlistinfo took 24 milliseconds Mar 11 18:51:05 volumio volumio[875]: info: sendMpdCommand playlistinfo took 24 milliseconds Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::parseTrackInfo Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::parseTrackInfo Mar 11 18:51:05 volumio volumio[875]: verbose: ControllerMpd::parseTrackInfo Mar 11 18:51:05 volumio volumio[875]: info: ControllerMpd::pushState Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::servicePushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: verbose: STATE SERVICE {"status":"play","position":0,"seek":440,"duration":349,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"Sultans Of Swing","artist":"Dire Straits","album":"Dire Straits","uri":"NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/06 - Dire Straits - Sultans Of Swing.dsf","trackType":"dsf"} Mar 11 18:51:05 volumio volumio[875]: verbose: CURRENT POSITION 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::syncState stateService play Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::syncState currentStatus play Mar 11 18:51:05 volumio volumio[875]: info: Received an update from plugin. extracting info from payload Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::pushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushState Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::pushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushState Mar 11 18:51:05 volumio volumio[875]: info: ControllerMpd::pushState Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::servicePushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: verbose: STATE SERVICE {"status":"play","position":0,"seek":989,"duration":349,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"Sultans Of Swing","artist":"Dire Straits","album":"Dire Straits","uri":"NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/06 - Dire Straits - Sultans Of Swing.dsf","trackType":"dsf"} Mar 11 18:51:05 volumio volumio[875]: verbose: CURRENT POSITION 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::syncState stateService play Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::syncState currentStatus play Mar 11 18:51:05 volumio volumio[875]: info: Received an update from plugin. extracting info from payload Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::pushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushState Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::pushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushState Mar 11 18:51:05 volumio volumio[875]: info: ControllerMpd::pushState Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::servicePushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: verbose: STATE SERVICE {"status":"play","position":0,"seek":989,"duration":349,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"Sultans Of Swing","artist":"Dire Straits","album":"Dire Straits","uri":"NAS/DSD_MUSIC/SACD A-E/Dire Straits - Dire Straits (1978) [2019] MFSL/Dire Straits - Dire Straits/06 - Dire Straits - Sultans Of Swing.dsf","trackType":"dsf"} Mar 11 18:51:05 volumio volumio[875]: verbose: CURRENT POSITION 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::syncState stateService play Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::syncState currentStatus play Mar 11 18:51:05 volumio volumio[875]: info: Received an update from plugin. extracting info from payload Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::pushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushState Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::pushState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioPushState Mar 11 18:51:05 volumio volumio[875]: info: ------------------------------ 70ms Mar 11 18:51:05 volumio volumio[875]: info: ------------------------------ 65ms Mar 11 18:51:05 volumio volumio[875]: info: ------------------------------ 65ms Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:05 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:05 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:05 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:05 volumio go-librespot[21090]: time="2025-03-11T18:51:05Z" level=debug msg="completed challenge" Mar 11 18:51:05 volumio go-librespot[21090]: time="2025-03-11T18:51:05Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:51:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:51:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:51:05 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:05 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:06 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:06 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:06 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:06 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:06 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:07 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:07 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:07 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:07 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:07 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:08 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:08 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:08 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:08 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:08 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:08 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:08 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:51:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7198. Mar 11 18:51:08 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:51:09 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:51:09 volumio go-librespot[21111]: Librespot-go daemon starting... Mar 11 18:51:09 volumio go-librespot[21111]: time="2025-03-11T18:51:09Z" level=info msg="generated new device id: d22700aac3bb0083367ac10deb6219297da9bb89" Mar 11 18:51:09 volumio go-librespot[21111]: time="2025-03-11T18:51:09Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:51:09 volumio go-librespot[21111]: time="2025-03-11T18:51:09Z" level=debug msg="obtained new client token: AAAFYFk3DZKsQJ1qcLEhZkOvS8qUhgodCIvMLBcnTfn9Qc6XUHL22JGSEgbMiPD8O44mpJKA4u46ZXIpS1rKRb8I4zUtIoeCzU9mIEgL3X5LZzWum5WuyniGhfq0x0HDqwJNhgDdQXx2fZOe6MS+kGTIV9L3liIVZq1PFNEPciXTOMVcfAK31WrECVeAA0HzsFPfnfFu2WCQRAIhugbokPWD3afm5MblsaOfKuxCKR7FeYCUFUXR8HClz6A9" Mar 11 18:51:09 volumio go-librespot[21111]: time="2025-03-11T18:51:09Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 11 18:51:09 volumio go-librespot[21111]: time="2025-03-11T18:51:09Z" level=debug msg="completed keyexchange" Mar 11 18:51:09 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:09 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:09 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:09 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:09 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:09 volumio go-librespot[21111]: time="2025-03-11T18:51:09Z" level=debug msg="completed challenge" Mar 11 18:51:09 volumio go-librespot[21111]: time="2025-03-11T18:51:09Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:51:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:51:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:51:10 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:10 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:10 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:10 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:10 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:11 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:11 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:11 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:11 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:11 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:11 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:11 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:12 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:12 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:12 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:12 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:12 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:51:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7199. Mar 11 18:51:12 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:51:13 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:51:13 volumio go-librespot[21128]: Librespot-go daemon starting... Mar 11 18:51:13 volumio go-librespot[21128]: time="2025-03-11T18:51:13Z" level=info msg="generated new device id: 08b00e8c47689b3e780d693f443a049fd35d0ea3" Mar 11 18:51:13 volumio go-librespot[21128]: time="2025-03-11T18:51:13Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:51:13 volumio go-librespot[21128]: time="2025-03-11T18:51:13Z" level=debug msg="obtained new client token: AACu0Kd3rd+mg2xtlKA4uYnyGYl/wT074WX+LmIqD1UHOJC3gvLlWgbEdrCMDQeqzwVmtd8w2WC8pxC0A8zU6QIr2GAPlq4fvs/IBAOhSos2s7Iyybnud52h47Q0uuL1cM2lMypK+NTgdFYy7n3n5/uDK7Pm422GDJe6m+NE3UEOPKYuHJS8kJ5AueJTHTh/rIrvupApkQSfSzSoPv3xrJY6AuKvbtIdShjKqECIOAZZmjaLP7DpR+6JEXXf" Mar 11 18:51:13 volumio go-librespot[21128]: time="2025-03-11T18:51:13Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:51:13 volumio go-librespot[21128]: time="2025-03-11T18:51:13Z" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 34.158.1.133:4070: connect: connection refused" Mar 11 18:51:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:51:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:51:13 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:13 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:13 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:13 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:13 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:14 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:14 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:14 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:14 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:14 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:14 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:14 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:15 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:15 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:15 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:15 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:15 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:51:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7200. Mar 11 18:51:16 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:51:16 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:51:16 volumio go-librespot[21142]: Librespot-go daemon starting... Mar 11 18:51:16 volumio go-librespot[21142]: time="2025-03-11T18:51:16Z" level=info msg="generated new device id: 0ed50fa69efaee4780d4c71728cedc6f8613c471" Mar 11 18:51:16 volumio go-librespot[21142]: time="2025-03-11T18:51:16Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:51:16 volumio go-librespot[21142]: time="2025-03-11T18:51:16Z" level=debug msg="obtained new client token: AABONLDu+lkLLCC1cJN/2YO0z9JrofELS79Os0kJZKdXHqXvNZZdfmGzGlx52k28NT/UNitmh53DzsKY/6epjKe+Mr5Bs4BGCeAtAik33Y9OsfVHBOhayJL7rSoFGuB06hLjyZoQU6RxIYy5VxP8SOfeTfJY6/T39SWFsDVT4f2D0qV12RHT0TChQ++FcBrjVGnnQ+gh1YAZ7pz5tcyCz0WPCl9lsMyPAMv6QY2SRoTKM5+nOfhk0DiApImxcGI=" Mar 11 18:51:16 volumio go-librespot[21142]: time="2025-03-11T18:51:16Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:51:16 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:16 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:16 volumio go-librespot[21142]: time="2025-03-11T18:51:16Z" level=debug msg="completed keyexchange" Mar 11 18:51:16 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:16 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:16 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:17 volumio go-librespot[21142]: time="2025-03-11T18:51:17Z" level=debug msg="completed challenge" Mar 11 18:51:17 volumio go-librespot[21142]: time="2025-03-11T18:51:17Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:51:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:51:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:51:17 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:17 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:17 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:17 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:17 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:17 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:17 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:18 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:18 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:18 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:18 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:18 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:19 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:19 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:19 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:19 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:19 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:51:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7201. Mar 11 18:51:20 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:51:20 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:51:20 volumio go-librespot[21158]: Librespot-go daemon starting... Mar 11 18:51:20 volumio go-librespot[21158]: time="2025-03-11T18:51:20Z" level=info msg="generated new device id: 72e9d261f2bee239a0d5f8a70fcd222b3cf8b23c" Mar 11 18:51:20 volumio go-librespot[21158]: time="2025-03-11T18:51:20Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:51:20 volumio go-librespot[21158]: time="2025-03-11T18:51:20Z" level=debug msg="obtained new client token: AABjHxPDiDT65jvs7spRDZO/R1yuUyDTCn7jZuYJ9dRq6LhKCV9IP5m3odABPbrr/hASh++QdBTSuSO6bIZ2eXx1NGlTnsEoq0FLjx+2tTgD4ZqaZqmkV//1UPyQe62LNJVo94lwAEC1JrobKixI4FDLIUAfq7qM6C7FWlKjGeWva65tUGzRvX9sbCABf6onZ0v0X9flzkC89pBsFbl5mamZSJ6kjVQ5zAqn79Jz5/FhbwYZqcsOjmM7elfwCh0=" Mar 11 18:51:20 volumio go-librespot[21158]: time="2025-03-11T18:51:20Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:51:20 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:20 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:20 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:20 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:20 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:20 volumio go-librespot[21158]: time="2025-03-11T18:51:20Z" level=debug msg="completed keyexchange" Mar 11 18:51:20 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:20 volumio volumio[875]: info: Connection to go-librespot Websocket established Mar 11 18:51:20 volumio go-librespot[21158]: time="2025-03-11T18:51:20Z" level=debug msg="new websocket client" Mar 11 18:51:21 volumio go-librespot[21158]: time="2025-03-11T18:51:21Z" level=debug msg="completed challenge" Mar 11 18:51:21 volumio go-librespot[21158]: time="2025-03-11T18:51:21Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:51:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:51:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:51:21 volumio volumio[875]: info: Connection to go-librespot Websocket closed Mar 11 18:51:21 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:21 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:21 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:21 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:21 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:22 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:22 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:22 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:22 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:22 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:23 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:23 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:23 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:23 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:23 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:23 volumio volumio[875]: info: Getting Spotify volume Mar 11 18:51:23 volumio volumio[875]: (node:875) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:23 volumio volumio[875]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 11 18:51:23 volumio volumio[875]: (node:875) 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: 773) Mar 11 18:51:23 volumio volumio[875]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 11 18:51:23 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:23 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:24 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:24 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:51:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7202. Mar 11 18:51:24 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:51:24 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:51:24 volumio go-librespot[21212]: Librespot-go daemon starting... Mar 11 18:51:24 volumio go-librespot[21212]: time="2025-03-11T18:51:24Z" level=info msg="generated new device id: cabebc2b7de16a154e7b95e748078959c5a9130f" Mar 11 18:51:24 volumio go-librespot[21212]: time="2025-03-11T18:51:24Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:51:24 volumio go-librespot[21212]: time="2025-03-11T18:51:24Z" level=debug msg="obtained new client token: AAC9Ia5vJtD91vnAhEud4qn3Cva8NfVppeOsdd4QEJFLHURzGoHgqzPfwDvj85pyDFj29YEOPj0MOq7Euz0fZ6VfQTs/+sNc83HU1WGny/o/C7iVZodzeeyNBsHBhQ5PtWMi3Pibg84nTb9XrXfRTvZ7hBGW9Z6ciJzxFW5RfilEthEaJz8qRU2RDG3LrWlKZBJlMiMfSoK2KGM5QuJzjChKM17rrxIoLOEunqiQS9SEC9I+eYBu+Ny89ltFlyc=" Mar 11 18:51:24 volumio go-librespot[21212]: time="2025-03-11T18:51:24Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 11 18:51:24 volumio go-librespot[21212]: time="2025-03-11T18:51:24Z" level=debug msg="completed keyexchange" Mar 11 18:51:24 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:24 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:24 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:24 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:24 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:25 volumio go-librespot[21212]: time="2025-03-11T18:51:25Z" level=debug msg="completed challenge" Mar 11 18:51:25 volumio go-librespot[21212]: time="2025-03-11T18:51:25Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:51:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:51:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:51:25 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:25 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:25 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:25 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:25 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:26 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:26 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:26 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:26 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:26 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:27 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:27 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:27 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:27 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:27 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:27 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:27 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:51:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7203. Mar 11 18:51:28 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:51:28 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:51:28 volumio go-librespot[21228]: Librespot-go daemon starting... Mar 11 18:51:28 volumio go-librespot[21228]: time="2025-03-11T18:51:28Z" level=info msg="generated new device id: 53af602b07c619b4ad4533c01c2646dd9d040757" Mar 11 18:51:28 volumio go-librespot[21228]: time="2025-03-11T18:51:28Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:51:28 volumio go-librespot[21228]: time="2025-03-11T18:51:28Z" level=debug msg="obtained new client token: AABPmPTHjjn5ulA3t7oezO329RTmbrKvLgJDK13J6Y/CQjLBcCZZKN0a8zOTowMOq2LGbJH/SLM9mE2zfa2PmjycXTouRtYlzrUVMo7hsAzf0hp9F3sDfj2x1ntmDElcWkgSw+YtOIeMEZswAoTs0XR6d7BG6Gv3eYdE3LtMU99gzCrSltxkVPAIZlM/y7Zo6ccrYPdvn9FhmdfcWUyLRX5cYsn5dAMh05UXglpx647yONJe7DQDidOqtCUHA6Q=" Mar 11 18:51:28 volumio go-librespot[21228]: time="2025-03-11T18:51:28Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:51:28 volumio go-librespot[21228]: time="2025-03-11T18:51:28Z" level=debug msg="completed keyexchange" Mar 11 18:51:28 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:28 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:28 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:28 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:28 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:29 volumio go-librespot[21228]: time="2025-03-11T18:51:29Z" level=debug msg="completed challenge" Mar 11 18:51:29 volumio go-librespot[21228]: time="2025-03-11T18:51:29Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:51:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:51:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:51:29 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:29 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:29 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:29 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:29 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:30 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:30 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:30 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:30 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:30 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:30 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:30 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:31 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:31 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:31 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:31 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:31 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:51:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7204. Mar 11 18:51:32 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:51:32 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:51:32 volumio go-librespot[21245]: Librespot-go daemon starting... Mar 11 18:51:32 volumio go-librespot[21245]: time="2025-03-11T18:51:32Z" level=info msg="generated new device id: dc1206e503170c00ec96b41007c485b58febe4f9" Mar 11 18:51:32 volumio go-librespot[21245]: time="2025-03-11T18:51:32Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:51:32 volumio go-librespot[21245]: time="2025-03-11T18:51:32Z" level=debug msg="obtained new client token: AACZxnhlQDWKGKn9BVUNpzcVgD9b+rfziJlzINUuTMeLMtLJsv7QYqF/zcKxyxguyk/KJucNRfAoUZ4bIX9UeahxDaVvlaTpUiQ1eBv0ILFCw0mCla7fOqy5+CdrLyJRf1ZlAvjst7redS1jcbfGs+ZlC7qnXCvFhK3aHs2fENC8iF6wEtAkLlStRiKauxuHFZ3WGG4ZkSA+DgWLY7bYH9dAja4UjjzOZ+PNHl1GGfYVM+OIgp4zQfir9hUBYDc=" Mar 11 18:51:32 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:32 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:32 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:32 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:32 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:32 volumio go-librespot[21245]: time="2025-03-11T18:51:32Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:51:32 volumio go-librespot[21245]: time="2025-03-11T18:51:32Z" level=debug msg="completed keyexchange" Mar 11 18:51:33 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:33 volumio go-librespot[21245]: time="2025-03-11T18:51:33Z" level=debug msg="new websocket client" Mar 11 18:51:33 volumio volumio[875]: info: Connection to go-librespot Websocket established Mar 11 18:51:33 volumio go-librespot[21245]: time="2025-03-11T18:51:33Z" level=debug msg="completed challenge" Mar 11 18:51:33 volumio go-librespot[21245]: time="2025-03-11T18:51:33Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:51:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:51:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:51:33 volumio volumio[875]: info: Connection to go-librespot Websocket closed Mar 11 18:51:33 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:33 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:33 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:33 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:33 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:34 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:34 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:34 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:34 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:34 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:35 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:35 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:35 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:35 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:35 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:36 volumio volumio[875]: info: Getting Spotify volume Mar 11 18:51:36 volumio volumio[875]: (node:875) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:36 volumio volumio[875]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 11 18:51:36 volumio volumio[875]: (node:875) 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: 774) Mar 11 18:51:36 volumio volumio[875]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 11 18:51:36 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:36 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:36 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:36 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:51:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7205. Mar 11 18:51:36 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:51:36 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:51:36 volumio go-librespot[21262]: Librespot-go daemon starting... Mar 11 18:51:36 volumio go-librespot[21262]: time="2025-03-11T18:51:36Z" level=info msg="generated new device id: 4a3c6680755043947e0835e641c1563eeef4e6af" Mar 11 18:51:36 volumio go-librespot[21262]: time="2025-03-11T18:51:36Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:51:36 volumio go-librespot[21262]: time="2025-03-11T18:51:36Z" level=debug msg="obtained new client token: AADielxs6Sc3be6EjOJYTNFEIneACE1nLkaK3AmOexttB08WRaeS9PmsO2CHDIclVsrKz5pkhQ4tlKQwKDHgM+wh4phS1ECX7D2dArxasE1BLtMl8DWLsqPRZm5Ds5k4raBhwPkAk1sIzHW7vjCgICgLRfDO4DZpU1w+Zmfs87a1Vg11XkUZrrSUVmfWTHcIW1LqQH9c3P6wF8Ayiu8oS4Yw/73kksJTlDjTOFO4xiQt+SQNob2ZIBt+172w6I4=" Mar 11 18:51:36 volumio go-librespot[21262]: time="2025-03-11T18:51:36Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:51:36 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:36 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:36 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:36 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:36 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:36 volumio go-librespot[21262]: time="2025-03-11T18:51:36Z" level=debug msg="completed keyexchange" Mar 11 18:51:37 volumio go-librespot[21262]: time="2025-03-11T18:51:37Z" level=debug msg="completed challenge" Mar 11 18:51:37 volumio go-librespot[21262]: time="2025-03-11T18:51:37Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:51:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:51:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:51:37 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:37 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:37 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:37 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:37 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:38 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:38 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:38 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:38 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:38 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:39 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:39 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:39 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:39 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:39 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:39 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:39 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:51:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7206. Mar 11 18:51:40 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:51:40 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:51:40 volumio go-librespot[21278]: Librespot-go daemon starting... Mar 11 18:51:40 volumio go-librespot[21278]: time="2025-03-11T18:51:40Z" level=info msg="generated new device id: 4c321bab2f295dcaadac7235cf9019e3d0f9be5b" Mar 11 18:51:40 volumio go-librespot[21278]: time="2025-03-11T18:51:40Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:51:40 volumio go-librespot[21278]: time="2025-03-11T18:51:40Z" level=debug msg="obtained new client token: AABYN2EP0Hkk9184mu7UXBWPEemruSaZIulGljBbTXjJd+HigaornmlguQrBQumeuMonm4FpXgB9zdDWyOfTpzKUJ+7wqiUQRimzkzJQvsx9OZRBUmDwIRmt6XKLebG8GgLWFgXlzTVUTtTwBpjFMt/mFK6SwNfJzKvhbrS59LZkhprTX2eaYfC992+qCTKlUZl26iZ4X9BI1GjA80otDKvBg1MnjIx4SCZOba8WKw9QbSANlS/QC0yhkRSOJzw=" Mar 11 18:51:40 volumio go-librespot[21278]: time="2025-03-11T18:51:40Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:51:40 volumio go-librespot[21278]: time="2025-03-11T18:51:40Z" level=debug msg="completed keyexchange" Mar 11 18:51:40 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:40 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:40 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:40 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:40 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:41 volumio go-librespot[21278]: time="2025-03-11T18:51:41Z" level=debug msg="completed challenge" Mar 11 18:51:41 volumio go-librespot[21278]: time="2025-03-11T18:51:41Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:51:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:51:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:51:41 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:41 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:41 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:41 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:41 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:42 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:42 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:42 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:42 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:42 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:42 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:42 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:43 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:43 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:43 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:43 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:43 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:51:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7207. Mar 11 18:51:44 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:51:44 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:51:44 volumio go-librespot[21295]: Librespot-go daemon starting... Mar 11 18:51:44 volumio go-librespot[21295]: time="2025-03-11T18:51:44Z" level=info msg="generated new device id: 7741af7b938a10c60b7dbdfda9e5939f2cda2c80" Mar 11 18:51:44 volumio go-librespot[21295]: time="2025-03-11T18:51:44Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:51:44 volumio go-librespot[21295]: time="2025-03-11T18:51:44Z" level=debug msg="obtained new client token: AABP15eoJOSVySN0PZaE4QxJXGovyuR9XFgAM5vIXO3I0gxpfZcqBxjRUdmTVmbiyuU5zicLleW3+8urS1XlXsJGKb+qCU+TwovQQ/1TEMHXOorxRPrhG4lmNXLhH9O1bcEj+bB3p5UlnKGw2T/nEkz1JbgTki3ZP3P7tOC2tOV6WL2jtnqiyIsa2wICyGnhQLn9GIQRkjphSUPxC8hLZTKdOTXEtlHd2yfJhvYg8IdOuF7kKO+k3pJ4EZBropg=" Mar 11 18:51:44 volumio go-librespot[21295]: time="2025-03-11T18:51:44Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:51:44 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:44 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:44 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:44 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:44 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:44 volumio go-librespot[21295]: time="2025-03-11T18:51:44Z" level=debug msg="completed keyexchange" Mar 11 18:51:45 volumio go-librespot[21295]: time="2025-03-11T18:51:45Z" level=debug msg="completed challenge" Mar 11 18:51:45 volumio go-librespot[21295]: time="2025-03-11T18:51:45Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:51:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:51:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:51:45 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:45 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:45 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:45 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:45 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:45 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:45 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:46 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:46 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:46 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:46 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:46 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:47 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:47 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:47 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:47 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:47 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:48 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:48 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:51:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7208. Mar 11 18:51:48 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:51:48 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:51:48 volumio go-librespot[21311]: Librespot-go daemon starting... Mar 11 18:51:48 volumio go-librespot[21311]: time="2025-03-11T18:51:48Z" level=info msg="generated new device id: 4c6fdb90cc4413cb4a9e957ed92b893e2edbe56c" Mar 11 18:51:48 volumio go-librespot[21311]: time="2025-03-11T18:51:48Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:51:48 volumio go-librespot[21311]: time="2025-03-11T18:51:48Z" level=debug msg="obtained new client token: AADxfQKohlSCSND6hlQkW6MMbXkPZjBluy4oE/ePaILXkFPvv5hQMBcNx+gEyEKEjBuT3/rNUYvorNJXteyA6f1kVKxqlWyx+OS9LC5Lt2v+K6x6PCHsunYxhw+WZGAj8XJqxMjVzll366F9SY6m2XbCQVCBgMTexyJXqydzJn+qIFXA8vuLZYYUw7VdRKOv4+R5VpkdjvUcv+gWtPXlxr8NSdnpBazy+weCwNcMU5XWcEtuJApA1AUeT+vFsMU=" Mar 11 18:51:48 volumio go-librespot[21311]: time="2025-03-11T18:51:48Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 11 18:51:48 volumio go-librespot[21311]: time="2025-03-11T18:51:48Z" level=debug msg="completed keyexchange" Mar 11 18:51:48 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:48 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:48 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:48 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:48 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:49 volumio go-librespot[21311]: time="2025-03-11T18:51:49Z" level=debug msg="completed challenge" Mar 11 18:51:49 volumio go-librespot[21311]: time="2025-03-11T18:51:49Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:51:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:51:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:51:49 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:49 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:49 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:49 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:49 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:50 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:50 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:50 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:50 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:50 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:51 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:51 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:51 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:51 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:51 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:51 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:51 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:51:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7209. Mar 11 18:51:52 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:51:52 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:51:52 volumio go-librespot[21328]: Librespot-go daemon starting... Mar 11 18:51:52 volumio go-librespot[21328]: time="2025-03-11T18:51:52Z" level=info msg="generated new device id: a535128e3ddbffa253163e78a9e477fba7929c7f" Mar 11 18:51:52 volumio go-librespot[21328]: time="2025-03-11T18:51:52Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:51:52 volumio go-librespot[21328]: time="2025-03-11T18:51:52Z" level=debug msg="obtained new client token: AADlClKxf14rscd9VOydgyZqbx4LrrTM+feEIHAbbKUiTdUOwEV5RUTzzjRLZJSWjP37wd7tmNEwWDNolJykwfrQp5d3Q5V2ShWHybSqo4sZRtbMrd16T1WN/0BeVApUoMsyg8uIOaiX3rE3gdcn/fRfDemhsiGJQOjeniD+qmVff2DEUL00TZJHx8rpHpH2F7l036zspo50zPLy2cKTMET6q9n6duxDyx2apbc9dq0gco+F3ol7cRXH0Vw91mc=" Mar 11 18:51:52 volumio go-librespot[21328]: time="2025-03-11T18:51:52Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:51:52 volumio go-librespot[21328]: time="2025-03-11T18:51:52Z" level=debug msg="completed keyexchange" Mar 11 18:51:52 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:52 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:52 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:52 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:52 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:53 volumio go-librespot[21328]: time="2025-03-11T18:51:53Z" level=debug msg="completed challenge" Mar 11 18:51:53 volumio go-librespot[21328]: time="2025-03-11T18:51:53Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:51:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:51:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:51:53 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:53 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:53 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:53 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:53 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:54 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:54 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:54 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:54 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:54 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:54 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:54 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:55 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:55 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:55 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:55 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:55 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:56 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:51:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7210. Mar 11 18:51:56 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:51:56 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:51:56 volumio go-librespot[21344]: Librespot-go daemon starting... Mar 11 18:51:56 volumio go-librespot[21344]: time="2025-03-11T18:51:56Z" level=info msg="generated new device id: 9ee682f699d5f90d895346a0f6dcf94b97d55e44" Mar 11 18:51:56 volumio go-librespot[21344]: time="2025-03-11T18:51:56Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:51:56 volumio go-librespot[21344]: time="2025-03-11T18:51:56Z" level=debug msg="obtained new client token: AAC1qk8GAJE0g8t7AIG4+q29hsrHNbj8cMqS8mIr4x16ls3SC6gi2ermv6m9tXMbe4B2f/tczkffrjStz4WHgsn4neDPXx40ScOSyFZqnoOsXtbBxzg947SHNTHeG4eT8pQKupTX/7An9+N5JYODKN5p9UeNxgw8N+MdR0AcHl/Zxg+YgmB46T59jYM1bWMOWEJz7hn1WcBZ/nahYfFaUd0s6LkCfV7Ct8zy1YDvakGkWa79UYQQ1kL6vunurWo=" Mar 11 18:51:56 volumio go-librespot[21344]: time="2025-03-11T18:51:56Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 11 18:51:56 volumio go-librespot[21344]: time="2025-03-11T18:51:56Z" level=debug msg="completed keyexchange" Mar 11 18:51:56 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:56 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:56 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:56 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:56 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:57 volumio go-librespot[21344]: time="2025-03-11T18:51:57Z" level=debug msg="completed challenge" Mar 11 18:51:57 volumio go-librespot[21344]: time="2025-03-11T18:51:57Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:51:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:51:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:51:57 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:51:57 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:51:57 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:57 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:57 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:57 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:57 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:58 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:58 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:58 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:58 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:58 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:51:59 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:51:59 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:51:59 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:51:59 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:51:59 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:00 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:52:00 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:52:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:52:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7211. Mar 11 18:52:00 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:52:00 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:52:00 volumio go-librespot[21360]: Librespot-go daemon starting... Mar 11 18:52:00 volumio go-librespot[21360]: time="2025-03-11T18:52:00Z" level=info msg="generated new device id: 57e6a489ef7d5bb6820f901fdc9a8ebf6779a846" Mar 11 18:52:00 volumio go-librespot[21360]: time="2025-03-11T18:52:00Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:52:00 volumio go-librespot[21360]: time="2025-03-11T18:52:00Z" level=debug msg="obtained new client token: AABH3a6KXJBRehGHSnf60HMiVXEhCkMDw3LU/1G+9vHI6m4aEmADwYUtP+6YAsPCtIm02VNsc0WUjKXY/a7SnqkPMOamye2d1bwA2yg0hw9iljF7kio50e3m3W8UNtuRd12h+j+X7AhWzvobTCU3hlEVcjSJnhBAcxB1R1Fd+czpcGiGJ0ZmVzpALHw1UPT0EoSzs45eJcm8kFRzVeCft8jbHbG6RyGt/JOaLQ9F/s0Zv1WTIy4beaY2JK94Org=" Mar 11 18:52:00 volumio go-librespot[21360]: time="2025-03-11T18:52:00Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 11 18:52:00 volumio go-librespot[21360]: time="2025-03-11T18:52:00Z" level=debug msg="completed keyexchange" Mar 11 18:52:00 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:00 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:00 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:00 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:00 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:01 volumio go-librespot[21360]: time="2025-03-11T18:52:01Z" level=debug msg="completed challenge" Mar 11 18:52:01 volumio go-librespot[21360]: time="2025-03-11T18:52:01Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:52:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:52:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:52:01 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:01 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:01 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:01 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:01 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:02 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:02 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:02 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:02 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:02 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:03 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:52:03 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:52:03 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:03 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:03 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:03 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:03 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:52:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7212. Mar 11 18:52:04 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:52:04 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:52:04 volumio go-librespot[21377]: Librespot-go daemon starting... Mar 11 18:52:04 volumio go-librespot[21377]: time="2025-03-11T18:52:04Z" level=info msg="generated new device id: ad3fbcb2d18b5aa4a9e752088d966e0452c97d2b" Mar 11 18:52:04 volumio go-librespot[21377]: time="2025-03-11T18:52:04Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:52:04 volumio go-librespot[21377]: time="2025-03-11T18:52:04Z" level=debug msg="obtained new client token: AAAPHiR6fyDEDEm2m2pSbhpVp346i6YGTJHWg/nnzUUDGrHvJ1divd90SkcN184sv49JUmolY77O0N1GVlVfFx/ovg2AifAtApdP2uAyjBOW/EodN0H3tVGUl2hLO3r9a36JU5COVuvhBNvnNInGXLK9h4StF7FHuf/B6YPzVBxw7fWUcdVjgHjLFOEpIhhO0FBeNvgqdOgkM4oqZ0gwa3Qtq1srXMRVGM5u9tEFKqwDcH9nm3NJopRtEEAkfOE=" Mar 11 18:52:04 volumio go-librespot[21377]: time="2025-03-11T18:52:04Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:52:04 volumio go-librespot[21377]: time="2025-03-11T18:52:04Z" level=debug msg="completed keyexchange" Mar 11 18:52:04 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:04 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:04 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:04 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:04 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:05 volumio go-librespot[21377]: time="2025-03-11T18:52:05Z" level=debug msg="completed challenge" Mar 11 18:52:05 volumio go-librespot[21377]: time="2025-03-11T18:52:05Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:52:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:52:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:52:05 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:05 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:05 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:05 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:05 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:06 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:52:06 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:52:06 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:06 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:06 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:06 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:06 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:07 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:07 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:07 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:07 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:07 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:52:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7213. Mar 11 18:52:08 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:52:08 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:52:08 volumio go-librespot[21393]: Librespot-go daemon starting... Mar 11 18:52:08 volumio go-librespot[21393]: time="2025-03-11T18:52:08Z" level=info msg="generated new device id: ee5c6792c6e0e5301327480c7c425bde3a2ecec3" Mar 11 18:52:08 volumio go-librespot[21393]: time="2025-03-11T18:52:08Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:52:08 volumio go-librespot[21393]: time="2025-03-11T18:52:08Z" level=debug msg="obtained new client token: AADStQUUycF1MjtTKg8vl8H2RB4w1X42ZcJMnggbWxHHlyoxeRcQfA0SmQ94QGxeNZmEmGKFlP3/Wkm1A3Y3VtIgm1V+7djLZGBfD+wYXsfPsOThPqeujmXpsPTmrSp2FZrMdvdt3BzgDaRWKZlaBB7pkyiSJajRU/QFc+fvY2I2Q9OVxfvHarY+f6hygVK/+i58kCYjBrmhHcIkLK1b0LVbbDG+WYaKdmZVzi6s2pVovBceB4Li+1eOxsgXNa4=" Mar 11 18:52:08 volumio go-librespot[21393]: time="2025-03-11T18:52:08Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:52:08 volumio go-librespot[21393]: time="2025-03-11T18:52:08Z" level=debug msg="completed keyexchange" Mar 11 18:52:08 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:08 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:08 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:08 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:08 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:09 volumio go-librespot[21393]: time="2025-03-11T18:52:09Z" level=debug msg="completed challenge" Mar 11 18:52:09 volumio go-librespot[21393]: time="2025-03-11T18:52:09Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:52:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:52:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:52:09 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:52:09 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:52:09 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:09 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:09 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:09 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:09 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:10 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:10 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:10 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:10 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:10 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:11 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:11 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:11 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:11 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:11 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:12 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:52:12 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:52:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:52:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7214. Mar 11 18:52:12 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:52:12 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:52:12 volumio go-librespot[21409]: Librespot-go daemon starting... Mar 11 18:52:12 volumio go-librespot[21409]: time="2025-03-11T18:52:12Z" level=info msg="generated new device id: 913593747a7136235a95066906133a4b7de437b8" Mar 11 18:52:12 volumio go-librespot[21409]: time="2025-03-11T18:52:12Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:52:12 volumio go-librespot[21409]: time="2025-03-11T18:52:12Z" level=debug msg="obtained new client token: AADYOzFFXQY82Z3QHz4mnf/nnBdPMPt6CMfEJQC+g5NARsRIi1eNSZJZdkN6u3MgseAQUIdCB+9ImbuJ7W1Wi5FhcettdZpMzSsH8ITe3J+aPbZSpA99/Uw7YpTinH03SWHns/f4oYIGKsekOMLAoZSs65y2qJJwrsmJ9uPHD6/p0f9ELqoVN13QOWg3ax2On7dVrIpzXc7aUj+UIW13u88GKzIlHEE5OyQcTSv9/cmwNpY77izlLMueXJ1d4xk=" Mar 11 18:52:12 volumio go-librespot[21409]: time="2025-03-11T18:52:12Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:52:12 volumio go-librespot[21409]: time="2025-03-11T18:52:12Z" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 34.158.1.133:4070: connect: connection refused" Mar 11 18:52:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:52:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:52:12 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:12 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:12 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:12 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:12 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:13 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:13 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:13 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:13 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:13 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:14 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:14 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:14 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:14 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:14 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:15 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:52:15 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:52:15 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:15 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:15 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:15 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:15 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:52:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7215. Mar 11 18:52:15 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:52:16 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:52:16 volumio go-librespot[21424]: Librespot-go daemon starting... Mar 11 18:52:16 volumio go-librespot[21424]: time="2025-03-11T18:52:16Z" level=info msg="generated new device id: c59e5e806fd372cf5c8a5865fd217d94c22f0f2e" Mar 11 18:52:16 volumio go-librespot[21424]: time="2025-03-11T18:52:16Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:52:16 volumio go-librespot[21424]: time="2025-03-11T18:52:16Z" level=debug msg="obtained new client token: AAD8E+z9/jyw7eO3Kqj+B6KMOE4PgQ/4HZKOa7B9eVLDQj6qvuhHbSQKWkH0ijUiKPmjFAX4ad0ncSxy3TrX5MvbH+lNPdx+X49kgixs5WFsmUqRfadp6UQVrRdIye6hGftmUtsHUtwHeekkIgfxStevLbZlk8w32OvLZZtVHDy4M6mfKUEqULKX2hHRqctucKSDwiZbukKm27T5HWE/LrisC6nVAdUXl/EGICy421qM8cYrmUybQpBEqMCv" Mar 11 18:52:16 volumio go-librespot[21424]: time="2025-03-11T18:52:16Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:52:16 volumio go-librespot[21424]: time="2025-03-11T18:52:16Z" level=debug msg="completed keyexchange" Mar 11 18:52:16 volumio go-librespot[21424]: time="2025-03-11T18:52:16Z" level=debug msg="completed challenge" Mar 11 18:52:16 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:16 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:16 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:16 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:16 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:17 volumio go-librespot[21424]: time="2025-03-11T18:52:17Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:52:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:52:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:52:17 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:17 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:17 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:17 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:17 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:18 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:52:18 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:52:18 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:18 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:18 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:18 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:18 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:19 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:19 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:19 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:19 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:19 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:52:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7216. Mar 11 18:52:20 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:52:20 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:52:20 volumio go-librespot[21442]: Librespot-go daemon starting... Mar 11 18:52:20 volumio go-librespot[21442]: time="2025-03-11T18:52:20Z" level=info msg="generated new device id: 4bcd75428292cee0a4f0cd8778b0a1b29c24c466" Mar 11 18:52:20 volumio go-librespot[21442]: time="2025-03-11T18:52:20Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:52:20 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:20 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:20 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:20 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:20 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:20 volumio go-librespot[21442]: time="2025-03-11T18:52:20Z" level=debug msg="obtained new client token: AADe3/ytQCfjg+83Icm78oj6WfUgHv9LOpdjhD9/u/gR1SKCCu58gsFhS+DuMQ+tAW5/5R2Hj3JjeM1FRTcCJTp0sKYya+motCyNU4qRT2JrWgNMAhLE5Tv0lJGucdPtGsV1vdonEntEXxWfMS4XFD0JCqttV9hvDxqJSNfmvJ7Io3svhFJyPRxi/Z5go1bhKV6tBdPrzHgghsVM06Tk8oPT1POcrMfh0FtfSeIf+OKiA3AZE/Rg6HghX/B9muw=" Mar 11 18:52:21 volumio go-librespot[21442]: time="2025-03-11T18:52:21Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:52:21 volumio go-librespot[21442]: time="2025-03-11T18:52:21Z" level=debug msg="completed keyexchange" Mar 11 18:52:21 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:52:21 volumio go-librespot[21442]: time="2025-03-11T18:52:21Z" level=debug msg="new websocket client" Mar 11 18:52:21 volumio volumio[875]: info: Connection to go-librespot Websocket established Mar 11 18:52:21 volumio go-librespot[21442]: time="2025-03-11T18:52:21Z" level=debug msg="completed challenge" Mar 11 18:52:21 volumio go-librespot[21442]: time="2025-03-11T18:52:21Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:52:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:52:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:52:21 volumio volumio[875]: info: Connection to go-librespot Websocket closed Mar 11 18:52:21 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:21 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:21 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:21 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:21 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:22 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:22 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:22 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:22 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:22 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:23 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:23 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:23 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:23 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:23 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:24 volumio volumio[875]: info: Getting Spotify volume Mar 11 18:52:24 volumio volumio[875]: (node:875) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:52:24 volumio volumio[875]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 11 18:52:24 volumio volumio[875]: (node:875) 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: 775) Mar 11 18:52:24 volumio volumio[875]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 11 18:52:24 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:24 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:24 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:52:24 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:52:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:52:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7217. Mar 11 18:52:24 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:52:24 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:52:24 volumio go-librespot[21496]: Librespot-go daemon starting... Mar 11 18:52:24 volumio go-librespot[21496]: time="2025-03-11T18:52:24Z" level=info msg="generated new device id: e2850ee979cc1dd761e4e107eec188982e6a9601" Mar 11 18:52:24 volumio go-librespot[21496]: time="2025-03-11T18:52:24Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:52:24 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:24 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:24 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:24 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:24 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:24 volumio go-librespot[21496]: time="2025-03-11T18:52:24Z" level=debug msg="obtained new client token: AADxFslX8+05uytV3BydUeRFkpxthc/xMY2yRa6shJVFtWRWGKMC8/nCj27101ZUbvCA/Pv1ZXHCyNTZ8H84onqOu+BucrEY09D2O6xqsGPp4BcMeFbdgl7p4h59eobVDufpkBTlebw1daJoks2+AvCnkZcjCvXUNqxIPEVleKfyTo6+IsBjNjWsyxYi3x9TomZUnTO3mdPx1NRU2lyAdzhJ39464g3JDXvJHmaL74Q4esQLio/5uQIXmJvLqiE=" Mar 11 18:52:25 volumio go-librespot[21496]: time="2025-03-11T18:52:25Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 11 18:52:25 volumio go-librespot[21496]: time="2025-03-11T18:52:25Z" level=debug msg="completed keyexchange" Mar 11 18:52:25 volumio go-librespot[21496]: time="2025-03-11T18:52:25Z" level=debug msg="completed challenge" Mar 11 18:52:25 volumio go-librespot[21496]: time="2025-03-11T18:52:25Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:52:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:52:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:52:25 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:25 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:25 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:25 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:25 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:26 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:26 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:26 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:26 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:26 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:27 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:52:27 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:52:27 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:27 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:27 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:27 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:27 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:52:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7218. Mar 11 18:52:28 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:52:28 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:52:28 volumio go-librespot[21512]: Librespot-go daemon starting... Mar 11 18:52:28 volumio go-librespot[21512]: time="2025-03-11T18:52:28Z" level=info msg="generated new device id: d7732248441a29ce470facab77b1874d8ea6b95d" Mar 11 18:52:28 volumio go-librespot[21512]: time="2025-03-11T18:52:28Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:52:28 volumio go-librespot[21512]: time="2025-03-11T18:52:28Z" level=debug msg="obtained new client token: AACFMkCjOQLDBkI9XoORF7wezH63Smm0ZHzgNwNpJpzsaNQlnvPsCcXcahB7ZN7gaS2UOMcsxsjn9IrZqOFT6tdLUnMU9VRQonbj15Q75t07UsJ9EPfNq9z7L7uRp92hmdDA0VICpDYNBLpFT9L/ZPlZoS60ORErPdhYGpNUidJTnGrqVG6soA3VRD1d9L9bR4xEwdyJ96LYVGjoqz8lUHxE26QuvufoVsmpghfgf3jE42LhuRjyY6gQrN7ospc=" Mar 11 18:52:28 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:28 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:28 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:28 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:28 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:28 volumio go-librespot[21512]: time="2025-03-11T18:52:28Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:52:29 volumio go-librespot[21512]: time="2025-03-11T18:52:29Z" level=debug msg="completed keyexchange" Mar 11 18:52:29 volumio go-librespot[21512]: time="2025-03-11T18:52:29Z" level=debug msg="completed challenge" Mar 11 18:52:29 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:29 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:29 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:29 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:29 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:29 volumio go-librespot[21512]: time="2025-03-11T18:52:29Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:52:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:52:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:52:30 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:52:30 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:52:30 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:30 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:30 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:30 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:30 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:31 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:31 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:31 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:31 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:31 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:32 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:32 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:32 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:32 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:32 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:52:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7219. Mar 11 18:52:33 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:52:33 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:52:33 volumio go-librespot[21528]: Librespot-go daemon starting... Mar 11 18:52:33 volumio go-librespot[21528]: time="2025-03-11T18:52:33Z" level=info msg="generated new device id: 46555cfbfa12304509eb4605019392c21776e817" Mar 11 18:52:33 volumio go-librespot[21528]: time="2025-03-11T18:52:33Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:52:33 volumio go-librespot[21528]: time="2025-03-11T18:52:33Z" level=debug msg="obtained new client token: AACagUbZvRyXeEXmpdYyhLql0STF8URmAzYPmcY7d+kjfud4Jr1xgyL2ER3FKgN0rOJMoYCT0iHjIWLbhR+r7B9klzHSHwAz3l1bHPO8Xn73RRC8EAipmD/lsel+tPFjkPhI7NTYB0k1RIwCjpkWDzOdJ0/U9U4s5BbTxpZ16C7903yJjkz0DEt+oDpOsRFhsAxAeHzNJJ+WB83H7AU/qOzdM3YIxCTrYOUwoCgqxtMJyKd5qcZbMKlSrM9bn+Y=" Mar 11 18:52:33 volumio go-librespot[21528]: time="2025-03-11T18:52:33Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:52:33 volumio go-librespot[21528]: time="2025-03-11T18:52:33Z" level=debug msg="completed keyexchange" Mar 11 18:52:33 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:52:33 volumio go-librespot[21528]: time="2025-03-11T18:52:33Z" level=debug msg="new websocket client" Mar 11 18:52:33 volumio volumio[875]: info: Connection to go-librespot Websocket established Mar 11 18:52:33 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:33 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:33 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:33 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:33 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:34 volumio go-librespot[21528]: time="2025-03-11T18:52:34Z" level=debug msg="completed challenge" Mar 11 18:52:34 volumio go-librespot[21528]: time="2025-03-11T18:52:34Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:52:34 volumio volumio[875]: info: Connection to go-librespot Websocket closed Mar 11 18:52:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:52:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:52:34 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:34 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:34 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:34 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:34 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:35 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:35 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:35 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:35 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:35 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:36 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:36 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:36 volumio volumio[875]: info: Getting Spotify volume Mar 11 18:52:36 volumio volumio[875]: (node:875) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:52:36 volumio volumio[875]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 11 18:52:36 volumio volumio[875]: (node:875) 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: 776) Mar 11 18:52:36 volumio volumio[875]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 11 18:52:36 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:36 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:36 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:36 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:36 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:36 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:36 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:37 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:52:37 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:52:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:52:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7220. Mar 11 18:52:37 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:52:37 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:52:37 volumio go-librespot[21545]: Librespot-go daemon starting... Mar 11 18:52:37 volumio go-librespot[21545]: time="2025-03-11T18:52:37Z" level=info msg="generated new device id: d0cecd18c661ab29016ff943d985e24ef4175914" Mar 11 18:52:37 volumio go-librespot[21545]: time="2025-03-11T18:52:37Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:52:37 volumio go-librespot[21545]: time="2025-03-11T18:52:37Z" level=debug msg="obtained new client token: AAD0/ujakhToeAtX+nU7vHGtmrV8iUjp6wTEk7yT2ljF+GoXDG7zxBj85zezcWb1CORBAfok9IOaiLjsw73UvaHaHi7w1q/0geA0FJx23nzcUQM9Gf55vO0Ceh4EWdKpMyY2Z2IrzAxul4f4uk5Fza+6Rn5tj58Y6abJmsLjs7RE0lixMGZtDzvmc3yGxb86PlCPCyBc7BTf3TbkU1NIuj0Gp6oIaw4n4UP+kFvC9KW/zjAuFBBe4OlCURnVY88=" Mar 11 18:52:37 volumio go-librespot[21545]: time="2025-03-11T18:52:37Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:52:37 volumio go-librespot[21545]: time="2025-03-11T18:52:37Z" level=debug msg="completed keyexchange" Mar 11 18:52:37 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:37 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:37 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:37 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:37 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:38 volumio go-librespot[21545]: time="2025-03-11T18:52:38Z" level=debug msg="completed challenge" Mar 11 18:52:38 volumio go-librespot[21545]: time="2025-03-11T18:52:38Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:52:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:52:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:52:38 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:38 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:38 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:38 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:38 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:39 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:39 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:39 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:39 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:39 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:40 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:52:40 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:52:40 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:40 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:40 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:40 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:40 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:52:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7221. Mar 11 18:52:41 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:52:41 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:52:41 volumio go-librespot[21561]: Librespot-go daemon starting... Mar 11 18:52:41 volumio go-librespot[21561]: time="2025-03-11T18:52:41Z" level=info msg="generated new device id: 9e1e7ea9b034bb9ac2d5b15040f6612e4f5ef3f8" Mar 11 18:52:41 volumio go-librespot[21561]: time="2025-03-11T18:52:41Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:52:41 volumio go-librespot[21561]: time="2025-03-11T18:52:41Z" level=debug msg="obtained new client token: AAAxl2LNxkc5vf/0+zTNnkJOIHypLo8U5BDy0GePpUyDczvNURnxjBeuaS9oTiHkAbCood7mgtdNoC5rrwZ60c7gFx3lvzYNBtJi7+UtDxbTSUVAee/UL+6etu1NQB2ndNrcvigbg1yXhM9EO/iektBu6LRdllExiE2X8W/fbfgB9c863CSwySrwoDzp2N6fiAlWjoHEnRMv/+r7Y9NE93Q6NCvuWEQ1D+m/NSWRAAnfuOgzaThYx0650ezb8y4=" Mar 11 18:52:41 volumio go-librespot[21561]: time="2025-03-11T18:52:41Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:52:41 volumio go-librespot[21561]: time="2025-03-11T18:52:41Z" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 34.158.1.133:4070: connect: connection refused" Mar 11 18:52:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:52:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:52:41 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:41 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:41 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:41 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:41 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:42 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:42 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:42 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:42 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:42 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:43 volumio volumio[875]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 11 18:52:43 volumio volumio[875]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 11 18:52:43 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:52:43 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:52:43 volumio volumio[875]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 11 18:52:43 volumio volumio[875]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 11 18:52:43 volumio volumio[875]: info: Received Get System Version Mar 11 18:52:43 volumio volumio[875]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 11 18:52:43 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:43 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:43 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:43 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:43 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:52:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7222. Mar 11 18:52:44 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:52:44 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:52:44 volumio go-librespot[21591]: Librespot-go daemon starting... Mar 11 18:52:44 volumio go-librespot[21591]: time="2025-03-11T18:52:44Z" level=info msg="generated new device id: 93a5db8c42f128326a1806932d7793d1e59e53ab" Mar 11 18:52:44 volumio go-librespot[21591]: time="2025-03-11T18:52:44Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:52:44 volumio go-librespot[21591]: time="2025-03-11T18:52:44Z" level=debug msg="obtained new client token: AABZTGorvtQZ0yhq/eXNgo7p6N6rCwU2F+WwjEGUETugjtH8X6TWVv4gTd07NFbzjXBnIgTcHDpeV9AGgUgvG/+sF6OkF8FW0+6TrabAX3XH8/E5/e3LT/0Q2+wjUF7hYe1vtjqSuTZRF7MT1Orbb3A1oHXPvZ221pDEAB3f2OX8LO47VhTbmb9yW+gcFR4fh4EfKRn8E9bk37WkVWQgHb8Lx9u0R6Z+M9uGcJkQQ5wNUU6HvcHfIXymRuYhoEk=" Mar 11 18:52:44 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:44 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:44 volumio go-librespot[21591]: time="2025-03-11T18:52:44Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 11 18:52:44 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:44 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:44 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:45 volumio go-librespot[21591]: time="2025-03-11T18:52:45Z" level=debug msg="completed keyexchange" Mar 11 18:52:45 volumio go-librespot[21591]: time="2025-03-11T18:52:45Z" level=debug msg="completed challenge" Mar 11 18:52:45 volumio go-librespot[21591]: time="2025-03-11T18:52:45Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:52:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:52:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:52:45 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:45 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:45 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:45 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:45 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:46 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:52:46 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:52:46 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:46 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:46 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:46 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:46 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:46 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:46 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:47 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:47 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:47 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:47 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:47 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:52:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7223. Mar 11 18:52:48 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:52:48 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:52:48 volumio go-librespot[21607]: Librespot-go daemon starting... Mar 11 18:52:48 volumio go-librespot[21607]: time="2025-03-11T18:52:48Z" level=info msg="generated new device id: b91834566aed1e2e2c276e08ea30e5dad63678a3" Mar 11 18:52:48 volumio go-librespot[21607]: time="2025-03-11T18:52:48Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:52:48 volumio go-librespot[21607]: time="2025-03-11T18:52:48Z" level=debug msg="obtained new client token: AACnRcFjo7iSQzeOgLdsRwEtpTx9JJXAKja34xsVl+Kp698P5MWTMNMWSHNk3LqRTunVpqea3G2wSsPTvggGcCvDQBhwezB/X61NvYRZflWll7YhkbVKR2V+ovWF3ieIAdyrqC9dXuMBPfFrkU0k1lMQYlUSI8b1H/vjkUm8ig/C58k7E0OU8933+53jRGjhAniRkE+Lj52kbOhWkqh7150Fr+eXqmoDyGQwY68Hy9dtyg2jteI8aNS2zxmBQTk=" Mar 11 18:52:48 volumio go-librespot[21607]: time="2025-03-11T18:52:48Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 11 18:52:48 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:48 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:48 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:48 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:48 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:49 volumio go-librespot[21607]: time="2025-03-11T18:52:49Z" level=debug msg="completed keyexchange" Mar 11 18:52:49 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:52:49 volumio go-librespot[21607]: time="2025-03-11T18:52:49Z" level=debug msg="new websocket client" Mar 11 18:52:49 volumio volumio[875]: info: Connection to go-librespot Websocket established Mar 11 18:52:49 volumio go-librespot[21607]: time="2025-03-11T18:52:49Z" level=debug msg="completed challenge" Mar 11 18:52:49 volumio go-librespot[21607]: time="2025-03-11T18:52:49Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 11 18:52:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:52:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:52:49 volumio volumio[875]: info: Connection to go-librespot Websocket closed Mar 11 18:52:49 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:49 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:49 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:49 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:49 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:50 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:50 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:50 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:50 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:50 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:51 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:51 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:51 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:51 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:51 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:52 volumio volumio[875]: info: Getting Spotify volume Mar 11 18:52:52 volumio volumio[875]: (node:875) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:52:52 volumio volumio[875]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 11 18:52:52 volumio volumio[875]: (node:875) 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: 777) Mar 11 18:52:52 volumio volumio[875]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 11 18:52:52 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:52 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:52 volumio volumio[875]: info: Initializing connection to go-librespot Websocket Mar 11 18:52:52 volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 11 18:52:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 11 18:52:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7224. Mar 11 18:52:52 volumio systemd[1]: Stopped go-librespot Daemon. Mar 11 18:52:52 volumio systemd[1]: Started go-librespot Daemon. Mar 11 18:52:52 volumio go-librespot[21621]: Librespot-go daemon starting... Mar 11 18:52:52 volumio go-librespot[21621]: time="2025-03-11T18:52:52Z" level=info msg="generated new device id: 64af37bfae88d2e6d1987cf0fdaf4888c93f2a51" Mar 11 18:52:52 volumio go-librespot[21621]: time="2025-03-11T18:52:52Z" level=debug msg="stored credentials found for adonzell" Mar 11 18:52:52 volumio go-librespot[21621]: time="2025-03-11T18:52:52Z" level=debug msg="obtained new client token: AAAnc+WeiXMtJojpPhV5y3jt1BrqR91WR+kE97/mFH1NZ/UoAPFFMGyMSfF9OSryMIPfs29fJohxK+SQ8yQyOnRq+lNy7WBM9QT2sfFdEYkEHxUByFSp5iFCCKcpgGS/1LuVeAJfmU8JhVBptt8FZyx6ZsoobTyqMw674jvb/xJ4y3l8TfJRcGbxMTjNGoKW++n/rsnKk/JJ5jUjK+e+gJOITLQXXA7UOsNwbl5Jx2Eogt2hJXLDA/yhRdCF38c=" Mar 11 18:52:52 volumio volumio[875]: info: CoreCommandRouter::volumioGetState Mar 11 18:52:52 volumio volumio[875]: info: CorePlayQueue::getTrack 0 Mar 11 18:52:52 volumio volumio[875]: info: CoreCommandRouter::volumioGetQueue Mar 11 18:52:52 volumio volumio[875]: info: CoreStateMachine::getQueue Mar 11 18:52:52 volumio volumio[875]: info: CorePlayQueue::getQueue Mar 11 18:52:53 volumio go-librespot[21621]: time="2025-03-11T18:52:53Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 11 18:52:53 volumio go-librespot[21621]: time="2025-03-11T18:52:53Z" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 34.158.1.133:4070: connect: connection refused" Mar 11 18:52:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 11 18:52:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 11 18:52:53 volumio volumio[875]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________ Mar 11 18:52:53 volumio volumio[875]: info: PLUGIN onReboot : networkfs Mar 11 18:52:53 volumio sudo[21634]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount -f /mnt/NAS/DSD_MUSIC Mar 11 18:52:53 volumio sudo[21634]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 11 18:52:54 volumio sudo[21634]: pam_unix(sudo:session): session closed for user root Mar 11 18:52:54 volumio volumio[875]: umount.nfs: /mnt/NAS/DSD_MUSIC: device is busy Mar 11 18:52:54 volumio volumio[875]: error: Cannot umount share DSD_MUSIC : Error: Command failed: /usr/bin/sudo /bin/umount -f /mnt/NAS/DSD_MUSIC Mar 11 18:52:54 volumio volumio[875]: umount.nfs: /mnt/NAS/DSD_MUSIC: device is busy Mar 11 18:52:54 volumio sudo[21638]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount -f /mnt/NAS/Leftovers Mar 11 18:52:54 volumio sudo[21638]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 11 18:52:54 volumio systemd[1]: mnt-NAS-Leftovers.mount: Succeeded. Mar 11 18:52:54 volumio sudo[21638]: pam_unix(sudo:session): session closed for user root Mar 11 18:52:54 volumio sudo[21642]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount -f /mnt/NAS/Music Mar 11 18:52:54 volumio sudo[21642]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 11 18:52:54 volumio systemd[1]: mnt-NAS-Music.mount: Succeeded. Mar 11 18:52:54 volumio sudo[21642]: pam_unix(sudo:session): session closed for user root Mar 11 18:52:54 volumio volumio[875]: info: PLUGIN onReboot : audiophonicsonoff Mar 11 18:52:54 volumio volumio[875]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 11 18:52:54 volumio volumio[875]: TypeError: Cannot read property 'writeSync' of undefined Mar 11 18:52:54 volumio volumio[875]: at ControllerAudiophonicsOnOff.onVolumioReboot (/data/plugins/system_controller/audiophonicsonoff/index.js:35:25) Mar 11 18:52:54 volumio volumio[875]: at PluginManager.onVolumioRebootPlugin (/volumio/app/pluginmanager.js:684:30) Mar 11 18:52:54 volumio volumio[875]: at HashMap. (/volumio/app/pluginmanager.js:668:31) Mar 11 18:52:54 volumio volumio[875]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Mar 11 18:52:54 volumio volumio[875]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Mar 11 18:52:54 volumio volumio[875]: at PluginManager.onVolumioReboot (/volumio/app/pluginmanager.js:666:20) Mar 11 18:52:54 volumio volumio[875]: at CoreCommandRouter.reboot (/volumio/app/index.js:1331:22) Mar 11 18:52:54 volumio volumio[875]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:857:33) Mar 11 18:52:54 volumio volumio[875]: at Socket.emit (events.js:315:20) Mar 11 18:52:54 volumio volumio[875]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Mar 11 18:52:54 volumio volumio[875]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Mar 11 18:52:54 volumio volumio[875]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 11 18:52:54 volumio sudo[21659]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-11 18:51 Mar 11 18:52:54 volumio sudo[21659]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"