-- Logs begin at Thu 2019-02-14 18:11:59 CST, end at Sat 2025-03-01 18:18:01 CST. -- Mar 01 18:17:00 dac.x1 volumio[1146]: info: CALLMETHOD: user_interface peppymeterbasic savepeppy1 [object Object] Mar 01 18:17:00 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: peppymeterbasic , savepeppy1 Mar 01 18:17:00 dac.x1 volumio[1146]: error: Failed callmethod call: TypeError: Cannot read property 'then' of undefined Mar 01 18:17:00 dac.x1 volumio[1146]: info: PeppyMeterBasic -----------------------meter45G5_SACD Cover Mar 01 18:17:00 dac.x1 volumio[1146]: info: PeppyMeterBasic -----------------------$basefolder/data/INTERNAL/PeppyMeterBasic/Templates Mar 01 18:17:00 dac.x1 volumio[1146]: info: PeppyMeterBasic -----------------------screensize1280x400_Gelo5 00-99 Skin_200 Mar 01 18:17:00 dac.x1 volumio[1146]: info: PeppyMeterBasic -----------------------screenwidth1280 Mar 01 18:17:00 dac.x1 volumio[1146]: info: PeppyMeterBasic -----------------------screenheight400 Mar 01 18:17:00 dac.x1 volumio[1146]: info: PeppyMeterBasic -----------------------metersize30 Mar 01 18:17:00 dac.x1 volumio[1146]: error: PeppyMeterBasic ---Error writing config null Mar 01 18:17:00 dac.x1 volumio[1146]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 01 18:17:00 dac.x1 volumio[1146]: info: CoreCommandRouter::Close All Modals sent Mar 01 18:17:00 dac.x1 sudo[2337]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart peppymeterbasic.service Mar 01 18:17:00 dac.x1 sudo[2337]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 01 18:17:00 dac.x1 volumio[1146]: info: PeppyMeterBasic ---list is random,01G5_Naim,02G5_Naim 2,03G5_McIntosh,04G5_Accuphase,05G5_Luxman,06G5_Technics TX30,07G5_Technics_silver,08G5_Technics_Black,09G5_Advence,10G5_Advance2,11G5_Adv_X220,12G5_Sony TA-N77,13G5_Onkyo 5570,14G5_Krell KAS,15G5_T+A 3000HV,16G5_Turnable Black B,17G5_TurnOld,18G5_Turnable Black,19G5_Turnable Green,20G5_Turnable Blue,21G5_Audio Research,22G5_BlackBlur,23G5_BlueSea_Black,24G5_Bocatech,25G5_Classe,26G5_Dagostino,27G5_Kenwood Rev,28G5_Kenwood Single,29G5_Klanghelm,30G5_Caltec,31G5_Alvin,32G5_Magnetcord,33G5_NAD C3050,34G5_Onvi,35G5_Onvi centre,36G5_Old Braun,37G5_PeppyP Bang,38G5_WestonHouse,39G5_Weston,40G5_Retro,41G5_Abrahamsen,42G5_Casette Full,43G5_Cayin,44G5_CD Cover,45G5_SACD Cover,46G5_Disco,47G5_Dorrough Vertical,48G5_Dorrough crooked,49G5_Dorrought horizon,50G5_Led Strips,51G5_Loudspeaker IN,52G5_MarantzCD,53G5_Sansui,54G5_Unison Research,55G5_Rose3 Line,56G5_Rose IN,57G5_Rose OUT,58G5_TechnicsLed,59G5_Winamp,60G5_Eher,61G5_Old Accuphase Only,62G5_Caltec Blue,63G5_Caltec Red,64G5_Berlant Only,65G5_BlackBlur only meters,66G5_Dark Spotify Only meters,67G5_Denon Only,68G5_Deviation Only,69G5_DF202 Only meters,70G5_Gemonti ONLY meters,71G5_Hartman Only,72G5_Hitachi7500 ONLY meters,73G5_Hitachi7500 Purple,74G5_Kenwood Rev only meters,75G5_Line Magnetic,76G5_NAD M10 only,77G5_Namson Only meters,78G5_Philmore Only,79G5_Teletronix Only,80G5_VU Peak Only,81G5_SG Only meters,82G5_Weston ONLY meters,83G5_Realistic,84G5_Rudeer Only,85G5_R55 Only,87G5_Yamaha S3000 Only,88G5_WestonHouse Only,89G5_OnkyoM508,90G5_Yamaha MX2000,91G5_Teac,92G5_SG,93G5_BOSS Orange,94G5_Tascam,95G5_LED Out ONLY,96G5_Bose Rev,97G5_Sharp,98G5_TCD Deck,99G5_Round 180 Mar 01 18:17:00 dac.x1 volumio[1146]: info: PeppyMeterBasic ---800x480-test Mar 01 18:17:00 dac.x1 volumio[1146]: info: PeppyMeterBasic ---800x480-balbuze Mar 01 18:17:00 dac.x1 volumio[1146]: info: PeppyMeterBasic ---1600x720-balbuze Mar 01 18:17:00 dac.x1 volumio[1146]: info: PeppyMeterBasic ---1920x1080-balbuze Mar 01 18:17:00 dac.x1 volumio[1146]: info: PeppyMeterBasic --- Mar 01 18:17:00 dac.x1 systemd[1]: Started peppymeterbasic Daemon. Mar 01 18:17:00 dac.x1 sudo[2337]: pam_unix(sudo:session): session closed for user root Mar 01 18:17:00 dac.x1 volumio[1146]: info: peppymeterbasic Daemon Started Mar 01 18:17:01 dac.x1 volumio[1146]: info: Initializing connection to go-librespot Websocket Mar 01 18:17:01 dac.x1 volumio[1146]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 18:17:01 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 18:17:01 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 01 18:17:01 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 18:17:01 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 18:17:01 dac.x1 go-librespot[2341]: go-librespot daemon starting... Mar 01 18:17:01 dac.x1 go-librespot[2341]: time="2025-03-01T18:17:01+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 18:17:01 dac.x1 go-librespot[2341]: time="2025-03-01T18:17:01+08:00" level=debug msg="app state loaded" Mar 01 18:17:01 dac.x1 go-librespot[2341]: time="2025-03-01T18:17:01+08:00" level=debug msg="stored credentials not found" Mar 01 18:17:01 dac.x1 go-librespot[2341]: time="2025-03-01T18:17:01+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 18:17:02 dac.x1 go-librespot[2341]: time="2025-03-01T18:17:02+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 18:17:02 dac.x1 go-librespot[2341]: time="2025-03-01T18:17:02+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 18:17:02 dac.x1 go-librespot[2341]: time="2025-03-01T18:17:02+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 18:17:02 dac.x1 go-librespot[2341]: time="2025-03-01T18:17:02+08:00" level=info msg="zeroconf server listening on port 45929" Mar 01 18:17:02 dac.x1 go-librespot[2341]: time="2025-03-01T18:17:02+08:00" level=debug msg="obtained new client token: AAAv8vdTY2FK5E0cARJG5qmn5cQFE1ynoyBmpIIkuxqGM48w+et1yL0C370vcBH3EuuLwm739h4KebzNYvh6/qgNRcvaA+zjSyRHAJPRpxKkjMaGre727CMYbu0Uenwo9k5YfycQoMgHoXxjaKRSXfboAyzIQ/MoWyU1Tz5JuT/skmc7C8BfE+66/LTvWMVHFW8JvtJBX5vJBQwUQIyQCBOaIFiPRb73+9Zbs5dVEY/nP1P5XAHiW3g=" Mar 01 18:17:02 dac.x1 go-librespot[2341]: time="2025-03-01T18:17:02+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 18:17:02 dac.x1 go-librespot[2341]: time="2025-03-01T18:17:02+08:00" level=debug msg="completed keyexchange" Mar 01 18:17:02 dac.x1 go-librespot[2341]: time="2025-03-01T18:17:02+08:00" level=debug msg="completed challenge" Mar 01 18:17:02 dac.x1 go-librespot[2341]: time="2025-03-01T18:17:02+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 18:17:02 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 18:17:02 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 18:17:04 dac.x1 volumio[1146]: info: Initializing connection to go-librespot Websocket Mar 01 18:17:04 dac.x1 volumio[1146]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 18:17:06 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 18:17:06 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 01 18:17:06 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 18:17:06 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 18:17:06 dac.x1 go-librespot[2355]: go-librespot daemon starting... Mar 01 18:17:06 dac.x1 go-librespot[2355]: time="2025-03-01T18:17:06+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 18:17:06 dac.x1 go-librespot[2355]: time="2025-03-01T18:17:06+08:00" level=debug msg="app state loaded" Mar 01 18:17:06 dac.x1 go-librespot[2355]: time="2025-03-01T18:17:06+08:00" level=debug msg="stored credentials not found" Mar 01 18:17:06 dac.x1 go-librespot[2355]: time="2025-03-01T18:17:06+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 18:17:06 dac.x1 go-librespot[2355]: time="2025-03-01T18:17:06+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 18:17:06 dac.x1 go-librespot[2355]: time="2025-03-01T18:17:06+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 18:17:06 dac.x1 go-librespot[2355]: time="2025-03-01T18:17:06+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 18:17:06 dac.x1 go-librespot[2355]: time="2025-03-01T18:17:06+08:00" level=info msg="zeroconf server listening on port 41957" Mar 01 18:17:07 dac.x1 volumio[1146]: info: Initializing connection to go-librespot Websocket Mar 01 18:17:07 dac.x1 go-librespot[2355]: time="2025-03-01T18:17:07+08:00" level=debug msg="new websocket client" Mar 01 18:17:07 dac.x1 volumio[1146]: info: Connection to go-librespot Websocket established Mar 01 18:17:07 dac.x1 go-librespot[2355]: time="2025-03-01T18:17:07+08:00" level=debug msg="obtained new client token: AAA6chlDCWafiBHLfgDSsvnmuS9DkN+POymxZsZghBekF6LbthTjTM+4oNrNaE7NbOf4QozS7ePve4Wc4DiVHGYBSv2Ct64OtBGP2CWT1/czeI1PP9YMwISU1jPZYXIsWtej9KLLUWrb671iSxBXvocW7oZhzOLY4wWilCQ2SKv4y2LVvro/Am0hnOG/jIZG8e/VLAdnowZLF+R65hB+4wV6wZDDciOIQjspJYboxmEBjmRUT/8dPSQ=" Mar 01 18:17:08 dac.x1 wpa_supplicant[865]: wlan0: Failed to initiate sched scan Mar 01 18:17:08 dac.x1 go-librespot[2355]: time="2025-03-01T18:17:08+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 18:17:08 dac.x1 go-librespot[2355]: time="2025-03-01T18:17:08+08:00" level=debug msg="completed keyexchange" Mar 01 18:17:08 dac.x1 go-librespot[2355]: time="2025-03-01T18:17:08+08:00" level=debug msg="completed challenge" Mar 01 18:17:08 dac.x1 go-librespot[2355]: time="2025-03-01T18:17:08+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 18:17:08 dac.x1 volumio[1146]: info: Connection to go-librespot Websocket closed Mar 01 18:17:08 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 18:17:08 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 18:17:10 dac.x1 volumio[1146]: info: Getting Spotify volume Mar 01 18:17:10 dac.x1 volumio[1146]: (node:1146) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 18:17:10 dac.x1 volumio[1146]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 01 18:17:10 dac.x1 volumio[1146]: (node:1146) 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: 10) Mar 01 18:17:10 dac.x1 volumio[1146]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Mar 01 18:17:10 dac.x1 volumio[1146]: info: CoreCommandRouter::volumioGetState Mar 01 18:17:10 dac.x1 volumio[1146]: info: CorePlayQueue::getTrack 0 Mar 01 18:17:10 dac.x1 systemd[1]: peppymeterbasic.service: Succeeded. Mar 01 18:17:11 dac.x1 volumio[1146]: info: Initializing connection to go-librespot Websocket Mar 01 18:17:11 dac.x1 volumio[1146]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 18:17:11 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 18:17:11 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Mar 01 18:17:11 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 18:17:11 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 18:17:11 dac.x1 go-librespot[2381]: go-librespot daemon starting... Mar 01 18:17:11 dac.x1 go-librespot[2381]: time="2025-03-01T18:17:11+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 18:17:11 dac.x1 go-librespot[2381]: time="2025-03-01T18:17:11+08:00" level=debug msg="app state loaded" Mar 01 18:17:11 dac.x1 go-librespot[2381]: time="2025-03-01T18:17:11+08:00" level=debug msg="stored credentials not found" Mar 01 18:17:11 dac.x1 go-librespot[2381]: time="2025-03-01T18:17:11+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 18:17:12 dac.x1 go-librespot[2381]: time="2025-03-01T18:17:12+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 18:17:12 dac.x1 go-librespot[2381]: time="2025-03-01T18:17:12+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 18:17:12 dac.x1 go-librespot[2381]: time="2025-03-01T18:17:12+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 18:17:12 dac.x1 go-librespot[2381]: time="2025-03-01T18:17:12+08:00" level=info msg="zeroconf server listening on port 40949" Mar 01 18:17:13 dac.x1 go-librespot[2381]: time="2025-03-01T18:17:13+08:00" level=debug msg="obtained new client token: AAB+t+AkJ0rVkvWuV0tppa0yOQV/c42DAJqSDIkDjgPZr5nuepaHD89B7bdHAP4yKyQQz7j1jqcFPNOv2gGQEWBc+hZj8cmf2lp9vkzwShYj2HkBn9b251ifqLOrpzvrkhVIaKE1cyclNIGlXT/upZtrrxOHwGDlzYaRVM/0H1u0AjawNNqPRAi1S51kKTO829Z4f9/ePIiGoPCsJsE23g76RUSs9ykRX0V053U7yCrf6WfMybbn" Mar 01 18:17:13 dac.x1 go-librespot[2381]: time="2025-03-01T18:17:13+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 18:17:13 dac.x1 go-librespot[2381]: time="2025-03-01T18:17:13+08:00" level=debug msg="completed keyexchange" Mar 01 18:17:13 dac.x1 go-librespot[2381]: time="2025-03-01T18:17:13+08:00" level=debug msg="completed challenge" Mar 01 18:17:13 dac.x1 go-librespot[2381]: time="2025-03-01T18:17:13+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 18:17:13 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 18:17:13 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 18:17:14 dac.x1 volumio[1146]: info: Initializing connection to go-librespot Websocket Mar 01 18:17:14 dac.x1 volumio[1146]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 18:17:15 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 01 18:17:16 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 18:17:16 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Mar 01 18:17:16 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 18:17:16 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 18:17:16 dac.x1 go-librespot[2390]: go-librespot daemon starting... Mar 01 18:17:16 dac.x1 wpa_supplicant[865]: wlan0: Failed to initiate sched scan Mar 01 18:17:17 dac.x1 go-librespot[2390]: time="2025-03-01T18:17:17+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 18:17:17 dac.x1 go-librespot[2390]: time="2025-03-01T18:17:17+08:00" level=debug msg="app state loaded" Mar 01 18:17:17 dac.x1 go-librespot[2390]: time="2025-03-01T18:17:17+08:00" level=debug msg="stored credentials not found" Mar 01 18:17:17 dac.x1 go-librespot[2390]: time="2025-03-01T18:17:17+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 18:17:17 dac.x1 volumio[1146]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Mar 01 18:17:17 dac.x1 volumio[1146]: info: Received Get System Info Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 01 18:17:17 dac.x1 volumio[1146]: info: Discovery: Getting this device information Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::volumioGetState Mar 01 18:17:17 dac.x1 volumio[1146]: info: CorePlayQueue::getTrack 0 Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::volumioGetState Mar 01 18:17:17 dac.x1 volumio[1146]: info: CorePlayQueue::getTrack 0 Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::volumioGetVisibleSources Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::volumioGetState Mar 01 18:17:17 dac.x1 volumio[1146]: info: CorePlayQueue::getTrack 0 Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 01 18:17:17 dac.x1 volumio[1146]: info: Received Get System Info Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 01 18:17:17 dac.x1 volumio[1146]: info: Discovery: Getting this device information Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::volumioGetState Mar 01 18:17:17 dac.x1 volumio[1146]: info: CorePlayQueue::getTrack 0 Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::volumioGetState Mar 01 18:17:17 dac.x1 volumio[1146]: info: CorePlayQueue::getTrack 0 Mar 01 18:17:17 dac.x1 volumio[1146]: info: Listing playlists Mar 01 18:17:17 dac.x1 volumio[1146]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 01 18:17:17 dac.x1 volumio[1146]: info: Initializing connection to go-librespot Websocket Mar 01 18:17:17 dac.x1 go-librespot[2390]: time="2025-03-01T18:17:17+08:00" level=debug msg="new websocket client" Mar 01 18:17:17 dac.x1 volumio[1146]: info: Connection to go-librespot Websocket established Mar 01 18:17:17 dac.x1 go-librespot[2390]: time="2025-03-01T18:17:17+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 18:17:17 dac.x1 go-librespot[2390]: time="2025-03-01T18:17:17+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 18:17:17 dac.x1 go-librespot[2390]: time="2025-03-01T18:17:17+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 18:17:17 dac.x1 volumio[1146]: info: Received Get System Info Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 01 18:17:17 dac.x1 volumio[1146]: info: Discovery: Getting this device information Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::volumioGetState Mar 01 18:17:17 dac.x1 volumio[1146]: info: CorePlayQueue::getTrack 0 Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::volumioGetState Mar 01 18:17:17 dac.x1 volumio[1146]: info: CorePlayQueue::getTrack 0 Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::volumioGetVisibleSources Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::volumioGetState Mar 01 18:17:17 dac.x1 volumio[1146]: info: CorePlayQueue::getTrack 0 Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 01 18:17:17 dac.x1 go-librespot[2390]: time="2025-03-01T18:17:17+08:00" level=info msg="zeroconf server listening on port 34681" Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 01 18:17:17 dac.x1 volumio[1146]: info: Received Get System Info Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 01 18:17:17 dac.x1 volumio[1146]: info: Discovery: Getting this device information Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::volumioGetState Mar 01 18:17:17 dac.x1 volumio[1146]: info: CorePlayQueue::getTrack 0 Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 01 18:17:17 dac.x1 volumio[1146]: info: CoreCommandRouter::volumioGetState Mar 01 18:17:17 dac.x1 volumio[1146]: info: CorePlayQueue::getTrack 0 Mar 01 18:17:17 dac.x1 volumio[1146]: info: Listing playlists Mar 01 18:17:18 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 01 18:17:18 dac.x1 go-librespot[2390]: time="2025-03-01T18:17:18+08:00" level=debug msg="obtained new client token: AACMULTHTExWuqixQul7bE1y4DNSYorsJhBCJtbJi/zxKncN+Uk3rRWsqz8axsgiuoxvp8tudJWjLB1XfwHEiHr4OOkKcW0rZUFAEXui9agSj0a3QEJe3sSqqNnoBZYtb0bheKcFUmgwUnP4T48Gja47bDTwgpEO783DPyrolFqutxOAuG+OgOF9iUByc85kRnpMGs4IMnsPJ9EwbukZw+kkEK7D21Ox+9E2l7XXXpX4Wrp+TJRrsMc=" Mar 01 18:17:18 dac.x1 go-librespot[2390]: time="2025-03-01T18:17:18+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 18:17:18 dac.x1 go-librespot[2390]: time="2025-03-01T18:17:18+08:00" level=debug msg="completed keyexchange" Mar 01 18:17:18 dac.x1 go-librespot[2390]: time="2025-03-01T18:17:18+08:00" level=debug msg="completed challenge" Mar 01 18:17:18 dac.x1 go-librespot[2390]: time="2025-03-01T18:17:18+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 18:17:18 dac.x1 volumio[1146]: info: Connection to go-librespot Websocket closed Mar 01 18:17:18 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 18:17:18 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 18:17:20 dac.x1 volumio[1146]: info: Getting Spotify volume Mar 01 18:17:20 dac.x1 volumio[1146]: (node:1146) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 18:17:20 dac.x1 volumio[1146]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 01 18:17:20 dac.x1 volumio[1146]: (node:1146) 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: 11) Mar 01 18:17:20 dac.x1 volumio[1146]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Mar 01 18:17:20 dac.x1 volumio[1146]: info: CoreCommandRouter::volumioGetState Mar 01 18:17:20 dac.x1 volumio[1146]: info: CorePlayQueue::getTrack 0 Mar 01 18:17:21 dac.x1 volumio[1146]: info: Initializing connection to go-librespot Websocket Mar 01 18:17:21 dac.x1 volumio[1146]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 18:17:21 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 18:17:21 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Mar 01 18:17:21 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 18:17:21 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 18:17:21 dac.x1 volumio[1146]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Mar 01 18:17:21 dac.x1 volumio[1146]: info: Retrying Login Due to Network Error Mar 01 18:17:21 dac.x1 go-librespot[2417]: go-librespot daemon starting... Mar 01 18:17:21 dac.x1 go-librespot[2417]: time="2025-03-01T18:17:21+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 18:17:21 dac.x1 go-librespot[2417]: time="2025-03-01T18:17:21+08:00" level=debug msg="app state loaded" Mar 01 18:17:21 dac.x1 go-librespot[2417]: time="2025-03-01T18:17:21+08:00" level=debug msg="stored credentials not found" Mar 01 18:17:21 dac.x1 go-librespot[2417]: time="2025-03-01T18:17:21+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 18:17:22 dac.x1 go-librespot[2417]: time="2025-03-01T18:17:22+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 18:17:22 dac.x1 go-librespot[2417]: time="2025-03-01T18:17:22+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 18:17:22 dac.x1 go-librespot[2417]: time="2025-03-01T18:17:22+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 18:17:22 dac.x1 go-librespot[2417]: time="2025-03-01T18:17:22+08:00" level=info msg="zeroconf server listening on port 43427" Mar 01 18:17:23 dac.x1 go-librespot[2417]: time="2025-03-01T18:17:23+08:00" level=debug msg="obtained new client token: AADzyw9XuzvZeZCmg6P6FBdRhHftAz51OGstKriQTYOXybu+1hPdcY9uSADpc2/YxyXta7s0koQc8oSz76Y0XkXNL+d9ZQO6lR8IxuPYINXO9o6xxdwUmPb6l5kfeaTdU1vt9O7qNE1JJcOU7t8AbcVXMzXAbCXUKj+kRlJP8QFWRduskyUOOnHntTEy1ceXFPpMFnfTjz4csgl6tgNvU/uGcIUdyGbcb72RFq/4+RTQOZFBgpKD" Mar 01 18:17:23 dac.x1 go-librespot[2417]: time="2025-03-01T18:17:23+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 18:17:23 dac.x1 go-librespot[2417]: time="2025-03-01T18:17:23+08:00" level=debug msg="completed keyexchange" Mar 01 18:17:23 dac.x1 go-librespot[2417]: time="2025-03-01T18:17:23+08:00" level=debug msg="completed challenge" Mar 01 18:17:23 dac.x1 go-librespot[2417]: time="2025-03-01T18:17:23+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 18:17:23 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 18:17:23 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 18:17:24 dac.x1 volumio[1146]: info: Initializing connection to go-librespot Websocket Mar 01 18:17:24 dac.x1 volumio[1146]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 18:17:25 dac.x1 wpa_supplicant[865]: wlan0: Failed to initiate sched scan Mar 01 18:17:26 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 18:17:26 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Mar 01 18:17:26 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 18:17:26 dac.x1 volumio[1146]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 01 18:17:26 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 18:17:26 dac.x1 go-librespot[2425]: go-librespot daemon starting... Mar 01 18:17:26 dac.x1 go-librespot[2425]: time="2025-03-01T18:17:26+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 18:17:26 dac.x1 go-librespot[2425]: time="2025-03-01T18:17:26+08:00" level=debug msg="app state loaded" Mar 01 18:17:26 dac.x1 go-librespot[2425]: time="2025-03-01T18:17:26+08:00" level=debug msg="stored credentials not found" Mar 01 18:17:26 dac.x1 go-librespot[2425]: time="2025-03-01T18:17:26+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 18:17:26 dac.x1 volumio[1146]: info: PeppyMeterBasic ---list is random,01G5_Naim,02G5_Naim 2,03G5_McIntosh,04G5_Accuphase,05G5_Luxman,06G5_Technics TX30,07G5_Technics_silver,08G5_Technics_Black,09G5_Advence,10G5_Advance2,11G5_Adv_X220,12G5_Sony TA-N77,13G5_Onkyo 5570,14G5_Krell KAS,15G5_T+A 3000HV,16G5_Turnable Black B,17G5_TurnOld,18G5_Turnable Black,19G5_Turnable Green,20G5_Turnable Blue,21G5_Audio Research,22G5_BlackBlur,23G5_BlueSea_Black,24G5_Bocatech,25G5_Classe,26G5_Dagostino,27G5_Kenwood Rev,28G5_Kenwood Single,29G5_Klanghelm,30G5_Caltec,31G5_Alvin,32G5_Magnetcord,33G5_NAD C3050,34G5_Onvi,35G5_Onvi centre,36G5_Old Braun,37G5_PeppyP Bang,38G5_WestonHouse,39G5_Weston,40G5_Retro,41G5_Abrahamsen,42G5_Casette Full,43G5_Cayin,44G5_CD Cover,45G5_SACD Cover,46G5_Disco,47G5_Dorrough Vertical,48G5_Dorrough crooked,49G5_Dorrought horizon,50G5_Led Strips,51G5_Loudspeaker IN,52G5_MarantzCD,53G5_Sansui,54G5_Unison Research,55G5_Rose3 Line,56G5_Rose IN,57G5_Rose OUT,58G5_TechnicsLed,59G5_Winamp,60G5_Eher,61G5_Old Accuphase Only,62G5_Caltec Blue,63G5_Caltec Red,64G5_Berlant Only,65G5_BlackBlur only meters,66G5_Dark Spotify Only meters,67G5_Denon Only,68G5_Deviation Only,69G5_DF202 Only meters,70G5_Gemonti ONLY meters,71G5_Hartman Only,72G5_Hitachi7500 ONLY meters,73G5_Hitachi7500 Purple,74G5_Kenwood Rev only meters,75G5_Line Magnetic,76G5_NAD M10 only,77G5_Namson Only meters,78G5_Philmore Only,79G5_Teletronix Only,80G5_VU Peak Only,81G5_SG Only meters,82G5_Weston ONLY meters,83G5_Realistic,84G5_Rudeer Only,85G5_R55 Only,87G5_Yamaha S3000 Only,88G5_WestonHouse Only,89G5_OnkyoM508,90G5_Yamaha MX2000,91G5_Teac,92G5_SG,93G5_BOSS Orange,94G5_Tascam,95G5_LED Out ONLY,96G5_Bose Rev,97G5_Sharp,98G5_TCD Deck,99G5_Round 180 Mar 01 18:17:26 dac.x1 volumio[1146]: info: PeppyMeterBasic ---800x480-test Mar 01 18:17:26 dac.x1 volumio[1146]: info: PeppyMeterBasic ---800x480-balbuze Mar 01 18:17:26 dac.x1 volumio[1146]: info: PeppyMeterBasic ---1600x720-balbuze Mar 01 18:17:26 dac.x1 volumio[1146]: info: PeppyMeterBasic ---1920x1080-balbuze Mar 01 18:17:26 dac.x1 volumio[1146]: info: PeppyMeterBasic --- Mar 01 18:17:27 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 01 18:17:27 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 01 18:17:27 dac.x1 go-librespot[2425]: time="2025-03-01T18:17:27+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 18:17:27 dac.x1 go-librespot[2425]: time="2025-03-01T18:17:27+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 18:17:27 dac.x1 go-librespot[2425]: time="2025-03-01T18:17:27+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 18:17:27 dac.x1 go-librespot[2425]: time="2025-03-01T18:17:27+08:00" level=info msg="zeroconf server listening on port 35919" Mar 01 18:17:27 dac.x1 volumio[1146]: info: Initializing connection to go-librespot Websocket Mar 01 18:17:27 dac.x1 go-librespot[2425]: time="2025-03-01T18:17:27+08:00" level=debug msg="new websocket client" Mar 01 18:17:27 dac.x1 volumio[1146]: info: Connection to go-librespot Websocket established Mar 01 18:17:28 dac.x1 go-librespot[2425]: time="2025-03-01T18:17:28+08:00" level=debug msg="obtained new client token: AAD9f4nnYDKasnJzt+uPpNoGXXkEeAFvpojx8rfpuATwGXl/Zeijil/fqPAET/owj5M5QY+nqaWyk1XTmL8n+HwSgvHr8BZPUrUrr+t1wie0ZroYEnZ77ZA221txzSjEiJUY6xel+V9hwtzcTIr6/1zULoys6hi7qg9oZYqK/f0D6SCX61YtcJzWu3um91Xowg9ur/fBBXUgtNDh8Yw2ItA733iK5aMQ/2Cv+dFigIaAAtB/SGSx" Mar 01 18:17:28 dac.x1 go-librespot[2425]: time="2025-03-01T18:17:28+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 18:17:28 dac.x1 go-librespot[2425]: time="2025-03-01T18:17:28+08:00" level=debug msg="completed keyexchange" Mar 01 18:17:28 dac.x1 go-librespot[2425]: time="2025-03-01T18:17:28+08:00" level=debug msg="completed challenge" Mar 01 18:17:28 dac.x1 go-librespot[2425]: time="2025-03-01T18:17:28+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 18:17:28 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 18:17:28 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 18:17:28 dac.x1 volumio[1146]: info: Connection to go-librespot Websocket closed Mar 01 18:17:30 dac.x1 volumio[1146]: info: Getting Spotify volume Mar 01 18:17:30 dac.x1 volumio[1146]: (node:1146) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 18:17:30 dac.x1 volumio[1146]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 01 18:17:30 dac.x1 volumio[1146]: (node:1146) 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: 12) Mar 01 18:17:30 dac.x1 volumio[1146]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Mar 01 18:17:30 dac.x1 volumio[1146]: info: CoreCommandRouter::volumioGetState Mar 01 18:17:30 dac.x1 volumio[1146]: info: CorePlayQueue::getTrack 0 Mar 01 18:17:31 dac.x1 volumio[1146]: info: Initializing connection to go-librespot Websocket Mar 01 18:17:31 dac.x1 volumio[1146]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 18:17:31 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 18:17:31 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Mar 01 18:17:31 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 18:17:31 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 18:17:31 dac.x1 go-librespot[2450]: go-librespot daemon starting... Mar 01 18:17:31 dac.x1 go-librespot[2450]: time="2025-03-01T18:17:31+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 18:17:31 dac.x1 go-librespot[2450]: time="2025-03-01T18:17:31+08:00" level=debug msg="app state loaded" Mar 01 18:17:31 dac.x1 go-librespot[2450]: time="2025-03-01T18:17:31+08:00" level=debug msg="stored credentials not found" Mar 01 18:17:31 dac.x1 go-librespot[2450]: time="2025-03-01T18:17:31+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 18:17:31 dac.x1 volumio[1146]: info: MyVolumio login type: Token Mar 01 18:17:32 dac.x1 go-librespot[2450]: time="2025-03-01T18:17:32+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 18:17:32 dac.x1 go-librespot[2450]: time="2025-03-01T18:17:32+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 18:17:32 dac.x1 go-librespot[2450]: time="2025-03-01T18:17:32+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 18:17:32 dac.x1 go-librespot[2450]: time="2025-03-01T18:17:32+08:00" level=info msg="zeroconf server listening on port 38607" Mar 01 18:17:33 dac.x1 go-librespot[2450]: time="2025-03-01T18:17:33+08:00" level=debug msg="obtained new client token: AAByT1fz8g09bJ6s77FWcOtiiJnA3ukJLYhxlHIA0EDl8nrWAHnjRI0sIvZu097fMNVSTxV5IB34g0xRJ6BhqsYo49FoUKO6wK1y4qQiSGUtJpKJAvXI0xiJ7fahcvvmAmkR5S7eS++0f3bm+zAL5hFaJDXusGDvdEASKiL+axm1mynzJcg7Z4cjV7kdV1Mj9Z4ZVnVsDf8u0Q4wg6aO0uqUdnuKhWoCu1vwKHSYW2n1DHA1CxEdZtI=" Mar 01 18:17:33 dac.x1 go-librespot[2450]: time="2025-03-01T18:17:33+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 18:17:33 dac.x1 go-librespot[2450]: time="2025-03-01T18:17:33+08:00" level=debug msg="completed keyexchange" Mar 01 18:17:33 dac.x1 go-librespot[2450]: time="2025-03-01T18:17:33+08:00" level=debug msg="completed challenge" Mar 01 18:17:33 dac.x1 go-librespot[2450]: time="2025-03-01T18:17:33+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 18:17:33 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 18:17:33 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 18:17:33 dac.x1 wpa_supplicant[865]: wlan0: Failed to initiate sched scan Mar 01 18:17:34 dac.x1 volumio[1146]: info: Initializing connection to go-librespot Websocket Mar 01 18:17:34 dac.x1 volumio[1146]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 18:17:36 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 18:17:36 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Mar 01 18:17:36 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 18:17:36 dac.x1 go-librespot[2499]: go-librespot daemon starting... Mar 01 18:17:36 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 18:17:36 dac.x1 go-librespot[2499]: time="2025-03-01T18:17:36+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 18:17:36 dac.x1 go-librespot[2499]: time="2025-03-01T18:17:36+08:00" level=debug msg="app state loaded" Mar 01 18:17:36 dac.x1 go-librespot[2499]: time="2025-03-01T18:17:36+08:00" level=debug msg="stored credentials not found" Mar 01 18:17:36 dac.x1 go-librespot[2499]: time="2025-03-01T18:17:36+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 18:17:37 dac.x1 go-librespot[2499]: time="2025-03-01T18:17:37+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 01 18:17:37 dac.x1 go-librespot[2499]: time="2025-03-01T18:17:37+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 01 18:17:37 dac.x1 go-librespot[2499]: time="2025-03-01T18:17:37+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 01 18:17:37 dac.x1 go-librespot[2499]: time="2025-03-01T18:17:37+08:00" level=info msg="zeroconf server listening on port 33979" Mar 01 18:17:37 dac.x1 volumio[1146]: info: Initializing connection to go-librespot Websocket Mar 01 18:17:37 dac.x1 volumio[1146]: info: Connection to go-librespot Websocket established Mar 01 18:17:37 dac.x1 go-librespot[2499]: time="2025-03-01T18:17:37+08:00" level=debug msg="new websocket client" Mar 01 18:17:37 dac.x1 go-librespot[2499]: time="2025-03-01T18:17:37+08:00" level=debug msg="obtained new client token: AABkaWAp2vsG5g6F5lilLiltg5o1QcZ4bJGrFMgxYhR3xB8vxmuIfMG2N0j+qyWJ11D5DTIKaRD23UrPW8njcm3dPFVST/1YYrXDG9QWnJeQkC14m8Z22he50ELF1TZOfYByROfwZaQpQ87n/RUIyMxG1njGLnfK/ZE75N7npLQzFWZfduJiUaSTOpPuO8nlTnASMLNg8gPkfCIkPT/CuajlY0QdLXjIeSGqDk3TMTtY+DJ/89VP4r4=" Mar 01 18:17:37 dac.x1 go-librespot[2499]: time="2025-03-01T18:17:37+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 18:17:38 dac.x1 go-librespot[2499]: time="2025-03-01T18:17:38+08:00" level=debug msg="completed keyexchange" Mar 01 18:17:38 dac.x1 go-librespot[2499]: time="2025-03-01T18:17:38+08:00" level=debug msg="completed challenge" Mar 01 18:17:38 dac.x1 go-librespot[2499]: time="2025-03-01T18:17:38+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 18:17:38 dac.x1 volumio[1146]: info: Connection to go-librespot Websocket closed Mar 01 18:17:38 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 18:17:38 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 18:17:40 dac.x1 volumio[1146]: info: Getting Spotify volume Mar 01 18:17:40 dac.x1 volumio[1146]: (node:1146) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 18:17:40 dac.x1 volumio[1146]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 01 18:17:40 dac.x1 volumio[1146]: (node:1146) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 14) Mar 01 18:17:40 dac.x1 volumio[1146]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Mar 01 18:17:40 dac.x1 volumio[1146]: info: CoreCommandRouter::volumioGetState Mar 01 18:17:40 dac.x1 volumio[1146]: info: CorePlayQueue::getTrack 0 Mar 01 18:17:41 dac.x1 volumio[1146]: info: Initializing connection to go-librespot Websocket Mar 01 18:17:41 dac.x1 volumio[1146]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 18:17:41 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 18:17:41 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Mar 01 18:17:41 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 18:17:41 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 18:17:41 dac.x1 go-librespot[2524]: go-librespot daemon starting... Mar 01 18:17:41 dac.x1 go-librespot[2524]: time="2025-03-01T18:17:41+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 18:17:41 dac.x1 go-librespot[2524]: time="2025-03-01T18:17:41+08:00" level=debug msg="app state loaded" Mar 01 18:17:41 dac.x1 go-librespot[2524]: time="2025-03-01T18:17:41+08:00" level=debug msg="stored credentials not found" Mar 01 18:17:41 dac.x1 go-librespot[2524]: time="2025-03-01T18:17:41+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 18:17:41 dac.x1 volumio[1146]: info: CALLMETHOD: user_interface peppymeterbasic savepeppy1 [object Object] Mar 01 18:17:41 dac.x1 volumio[1146]: info: CoreCommandRouter::executeOnPlugin: peppymeterbasic , savepeppy1 Mar 01 18:17:41 dac.x1 volumio[1146]: error: Failed callmethod call: TypeError: Cannot read property 'then' of undefined Mar 01 18:17:41 dac.x1 volumio[1146]: info: PeppyMeterBasic -----------------------meter83G5_Realistic Mar 01 18:17:41 dac.x1 volumio[1146]: info: PeppyMeterBasic -----------------------$basefolder/data/INTERNAL/PeppyMeterBasic/Templates Mar 01 18:17:41 dac.x1 volumio[1146]: info: PeppyMeterBasic -----------------------screensize1280x400_Gelo5 00-99 Skin_200 Mar 01 18:17:41 dac.x1 volumio[1146]: info: PeppyMeterBasic -----------------------screenwidth1280 Mar 01 18:17:41 dac.x1 volumio[1146]: info: PeppyMeterBasic -----------------------screenheight400 Mar 01 18:17:41 dac.x1 volumio[1146]: info: PeppyMeterBasic -----------------------metersize30 Mar 01 18:17:41 dac.x1 volumio[1146]: error: PeppyMeterBasic ---Error writing config null Mar 01 18:17:41 dac.x1 volumio[1146]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 01 18:17:41 dac.x1 volumio[1146]: info: CoreCommandRouter::Close All Modals sent Mar 01 18:17:41 dac.x1 sudo[2536]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart peppymeterbasic.service Mar 01 18:17:41 dac.x1 sudo[2536]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 01 18:17:41 dac.x1 go-librespot[2524]: time="2025-03-01T18:17:41+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 18:17:41 dac.x1 go-librespot[2524]: time="2025-03-01T18:17:41+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 18:17:41 dac.x1 go-librespot[2524]: time="2025-03-01T18:17:41+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 18:17:41 dac.x1 go-librespot[2524]: time="2025-03-01T18:17:41+08:00" level=info msg="zeroconf server listening on port 34075" Mar 01 18:17:42 dac.x1 volumio[1146]: info: PeppyMeterBasic ---list is random,01G5_Naim,02G5_Naim 2,03G5_McIntosh,04G5_Accuphase,05G5_Luxman,06G5_Technics TX30,07G5_Technics_silver,08G5_Technics_Black,09G5_Advence,10G5_Advance2,11G5_Adv_X220,12G5_Sony TA-N77,13G5_Onkyo 5570,14G5_Krell KAS,15G5_T+A 3000HV,16G5_Turnable Black B,17G5_TurnOld,18G5_Turnable Black,19G5_Turnable Green,20G5_Turnable Blue,21G5_Audio Research,22G5_BlackBlur,23G5_BlueSea_Black,24G5_Bocatech,25G5_Classe,26G5_Dagostino,27G5_Kenwood Rev,28G5_Kenwood Single,29G5_Klanghelm,30G5_Caltec,31G5_Alvin,32G5_Magnetcord,33G5_NAD C3050,34G5_Onvi,35G5_Onvi centre,36G5_Old Braun,37G5_PeppyP Bang,38G5_WestonHouse,39G5_Weston,40G5_Retro,41G5_Abrahamsen,42G5_Casette Full,43G5_Cayin,44G5_CD Cover,45G5_SACD Cover,46G5_Disco,47G5_Dorrough Vertical,48G5_Dorrough crooked,49G5_Dorrought horizon,50G5_Led Strips,51G5_Loudspeaker IN,52G5_MarantzCD,53G5_Sansui,54G5_Unison Research,55G5_Rose3 Line,56G5_Rose IN,57G5_Rose OUT,58G5_TechnicsLed,59G5_Winamp,60G5_Eher,61G5_Old Accuphase Only,62G5_Caltec Blue,63G5_Caltec Red,64G5_Berlant Only,65G5_BlackBlur only meters,66G5_Dark Spotify Only meters,67G5_Denon Only,68G5_Deviation Only,69G5_DF202 Only meters,70G5_Gemonti ONLY meters,71G5_Hartman Only,72G5_Hitachi7500 ONLY meters,73G5_Hitachi7500 Purple,74G5_Kenwood Rev only meters,75G5_Line Magnetic,76G5_NAD M10 only,77G5_Namson Only meters,78G5_Philmore Only,79G5_Teletronix Only,80G5_VU Peak Only,81G5_SG Only meters,82G5_Weston ONLY meters,83G5_Realistic,84G5_Rudeer Only,85G5_R55 Only,87G5_Yamaha S3000 Only,88G5_WestonHouse Only,89G5_OnkyoM508,90G5_Yamaha MX2000,91G5_Teac,92G5_SG,93G5_BOSS Orange,94G5_Tascam,95G5_LED Out ONLY,96G5_Bose Rev,97G5_Sharp,98G5_TCD Deck,99G5_Round 180 Mar 01 18:17:42 dac.x1 volumio[1146]: info: PeppyMeterBasic ---800x480-test Mar 01 18:17:42 dac.x1 volumio[1146]: info: PeppyMeterBasic ---800x480-balbuze Mar 01 18:17:42 dac.x1 volumio[1146]: info: PeppyMeterBasic ---1600x720-balbuze Mar 01 18:17:42 dac.x1 volumio[1146]: info: PeppyMeterBasic ---1920x1080-balbuze Mar 01 18:17:42 dac.x1 volumio[1146]: info: PeppyMeterBasic --- Mar 01 18:17:42 dac.x1 systemd[1]: Started peppymeterbasic Daemon. Mar 01 18:17:42 dac.x1 sudo[2536]: pam_unix(sudo:session): session closed for user root Mar 01 18:17:42 dac.x1 volumio[1146]: info: peppymeterbasic Daemon Started Mar 01 18:17:42 dac.x1 wpa_supplicant[865]: wlan0: Failed to initiate sched scan Mar 01 18:17:42 dac.x1 go-librespot[2524]: time="2025-03-01T18:17:42+08:00" level=debug msg="obtained new client token: AADU4EasQ59vEcmnMt9pgFR0XPPoCE9H8swZcLyKxIvrRik1tWQp/234YZjxE8n+0fp0aVQ8MzehK1QBxvOrH2zRIYKUN0mSNngzaUhOLQblus60nDW1kYv1XptF/HAYPRutn0+0xAMjP1zIMg8spkDFlZHkxy/kE0b1LxH4Glek+H7T36KmHIaUst9mdbNwdt69sBsWicnyDk2hZ4laSM1o4ckSNQVzzoKjRp1zg4VHGXcycySH4Qc=" Mar 01 18:17:42 dac.x1 go-librespot[2524]: time="2025-03-01T18:17:42+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 18:17:42 dac.x1 go-librespot[2524]: time="2025-03-01T18:17:42+08:00" level=debug msg="completed keyexchange" Mar 01 18:17:42 dac.x1 go-librespot[2524]: time="2025-03-01T18:17:42+08:00" level=debug msg="completed challenge" Mar 01 18:17:42 dac.x1 go-librespot[2524]: time="2025-03-01T18:17:42+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 18:17:42 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 18:17:42 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 18:17:44 dac.x1 volumio[1146]: info: Initializing connection to go-librespot Websocket Mar 01 18:17:44 dac.x1 volumio[1146]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 18:17:45 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 18:17:45 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Mar 01 18:17:45 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 18:17:45 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 18:17:45 dac.x1 go-librespot[2543]: go-librespot daemon starting... Mar 01 18:17:45 dac.x1 go-librespot[2543]: time="2025-03-01T18:17:45+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 18:17:45 dac.x1 go-librespot[2543]: time="2025-03-01T18:17:45+08:00" level=debug msg="app state loaded" Mar 01 18:17:45 dac.x1 go-librespot[2543]: time="2025-03-01T18:17:45+08:00" level=debug msg="stored credentials not found" Mar 01 18:17:45 dac.x1 go-librespot[2543]: time="2025-03-01T18:17:45+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 18:17:46 dac.x1 go-librespot[2543]: time="2025-03-01T18:17:46+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 18:17:46 dac.x1 go-librespot[2543]: time="2025-03-01T18:17:46+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 18:17:46 dac.x1 go-librespot[2543]: time="2025-03-01T18:17:46+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 18:17:46 dac.x1 go-librespot[2543]: time="2025-03-01T18:17:46+08:00" level=info msg="zeroconf server listening on port 42273" Mar 01 18:17:47 dac.x1 volumio[1146]: info: Initializing connection to go-librespot Websocket Mar 01 18:17:47 dac.x1 go-librespot[2543]: time="2025-03-01T18:17:47+08:00" level=debug msg="new websocket client" Mar 01 18:17:47 dac.x1 volumio[1146]: info: Connection to go-librespot Websocket established Mar 01 18:17:47 dac.x1 go-librespot[2543]: time="2025-03-01T18:17:47+08:00" level=debug msg="obtained new client token: AAAzJtG1k0FA5+29suflomsW1UcmHYLIFoL/DzdskxU1L8w8POr3zZb2xrWY61Uu0OuqXYUOo28P42VHsfdFglSc9sRihjOdbde5OvYv51LCZC1i98VpKwQWBR2cXhMw3N+bCca+4mrpXbKVhd/1jLnEddZo1zxSGNHqdUW7uI7AGfyMMyXITWU8BzVyd3opLpct1M8ECvZppZ7pJZtR5bJaQ2FlkZzW6lJOBYj/dxc2JE84+dsF" Mar 01 18:17:47 dac.x1 go-librespot[2543]: time="2025-03-01T18:17:47+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 18:17:47 dac.x1 go-librespot[2543]: time="2025-03-01T18:17:47+08:00" level=debug msg="completed keyexchange" Mar 01 18:17:47 dac.x1 go-librespot[2543]: time="2025-03-01T18:17:47+08:00" level=debug msg="completed challenge" Mar 01 18:17:47 dac.x1 go-librespot[2543]: time="2025-03-01T18:17:47+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 18:17:47 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 18:17:47 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 18:17:47 dac.x1 volumio[1146]: info: Connection to go-librespot Websocket closed Mar 01 18:17:50 dac.x1 systemd[1]: peppymeterbasic.service: Succeeded. Mar 01 18:17:50 dac.x1 volumio[1146]: info: Getting Spotify volume Mar 01 18:17:50 dac.x1 volumio[1146]: (node:1146) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 18:17:50 dac.x1 volumio[1146]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 01 18:17:50 dac.x1 volumio[1146]: (node:1146) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 15) Mar 01 18:17:50 dac.x1 volumio[1146]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Mar 01 18:17:50 dac.x1 volumio[1146]: info: CoreCommandRouter::volumioGetState Mar 01 18:17:50 dac.x1 volumio[1146]: info: CorePlayQueue::getTrack 0 Mar 01 18:17:50 dac.x1 volumio[1146]: info: Initializing connection to go-librespot Websocket Mar 01 18:17:50 dac.x1 volumio[1146]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 18:17:50 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 18:17:50 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Mar 01 18:17:50 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 18:17:50 dac.x1 wpa_supplicant[865]: wlan0: Failed to initiate sched scan Mar 01 18:17:50 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 18:17:50 dac.x1 go-librespot[2565]: go-librespot daemon starting... Mar 01 18:17:50 dac.x1 go-librespot[2565]: time="2025-03-01T18:17:50+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 18:17:50 dac.x1 go-librespot[2565]: time="2025-03-01T18:17:50+08:00" level=debug msg="app state loaded" Mar 01 18:17:50 dac.x1 go-librespot[2565]: time="2025-03-01T18:17:50+08:00" level=debug msg="stored credentials not found" Mar 01 18:17:50 dac.x1 go-librespot[2565]: time="2025-03-01T18:17:50+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 18:17:51 dac.x1 go-librespot[2565]: time="2025-03-01T18:17:51+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 18:17:51 dac.x1 go-librespot[2565]: time="2025-03-01T18:17:51+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 18:17:51 dac.x1 go-librespot[2565]: time="2025-03-01T18:17:51+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 18:17:51 dac.x1 go-librespot[2565]: time="2025-03-01T18:17:51+08:00" level=info msg="zeroconf server listening on port 42887" Mar 01 18:17:52 dac.x1 go-librespot[2565]: time="2025-03-01T18:17:52+08:00" level=debug msg="obtained new client token: AAB6F5pqufbiL1qvnbnzUcb6JVlF0eses8//jAwbaWYPwKRUyUUqHO3VEVM0nJSENJO71cwEdlIfGxP4+hYG2uJ0v9hB518N0WkgDIumRUPE/THyA+gohetwblQB47X8BhT5rzpRgtKZIX8VAIEMFb7H5al5EHayRDU/dFpe6smHkQiWmLZrpmUr8swvsZK1TMI+gJRUni7AIv1gdrOOaPtcLTO2J4taj1EpQXZ/XyZKwf+8n9FGpAA=" Mar 01 18:17:52 dac.x1 go-librespot[2565]: time="2025-03-01T18:17:52+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 18:17:52 dac.x1 go-librespot[2565]: time="2025-03-01T18:17:52+08:00" level=debug msg="completed keyexchange" Mar 01 18:17:52 dac.x1 go-librespot[2565]: time="2025-03-01T18:17:52+08:00" level=debug msg="completed challenge" Mar 01 18:17:52 dac.x1 go-librespot[2565]: time="2025-03-01T18:17:52+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 18:17:52 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 18:17:52 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 18:17:53 dac.x1 volumio[1146]: info: Initializing connection to go-librespot Websocket Mar 01 18:17:53 dac.x1 volumio[1146]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 18:17:55 dac.x1 volumio[1146]: info: CoreCommandRouter::volumioGetQueue Mar 01 18:17:55 dac.x1 volumio[1146]: info: CoreStateMachine::getQueue Mar 01 18:17:55 dac.x1 volumio[1146]: info: CorePlayQueue::getQueue Mar 01 18:17:55 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 18:17:55 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Mar 01 18:17:55 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 18:17:55 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 18:17:55 dac.x1 go-librespot[2576]: go-librespot daemon starting... Mar 01 18:17:55 dac.x1 go-librespot[2576]: time="2025-03-01T18:17:55+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 18:17:55 dac.x1 go-librespot[2576]: time="2025-03-01T18:17:55+08:00" level=debug msg="app state loaded" Mar 01 18:17:55 dac.x1 go-librespot[2576]: time="2025-03-01T18:17:55+08:00" level=debug msg="stored credentials not found" Mar 01 18:17:55 dac.x1 go-librespot[2576]: time="2025-03-01T18:17:55+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 18:17:56 dac.x1 volumio[1146]: info: Initializing connection to go-librespot Websocket Mar 01 18:17:56 dac.x1 go-librespot[2576]: time="2025-03-01T18:17:56+08:00" level=debug msg="new websocket client" Mar 01 18:17:56 dac.x1 volumio[1146]: info: Connection to go-librespot Websocket established Mar 01 18:17:59 dac.x1 wpa_supplicant[865]: wlan0: Failed to initiate sched scan Mar 01 18:17:59 dac.x1 volumio[1146]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 01 18:17:59 dac.x1 volumio[1146]: Error: connect ETIMEDOUT 128.242.240.189:443 Mar 01 18:17:59 dac.x1 volumio[1146]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Mar 01 18:17:59 dac.x1 volumio[1146]: errno: -110, Mar 01 18:17:59 dac.x1 volumio[1146]: code: 'ETIMEDOUT', Mar 01 18:17:59 dac.x1 volumio[1146]: syscall: 'connect', Mar 01 18:17:59 dac.x1 volumio[1146]: address: '128.242.240.189', Mar 01 18:17:59 dac.x1 volumio[1146]: port: 443 Mar 01 18:17:59 dac.x1 volumio[1146]: } Mar 01 18:17:59 dac.x1 volumio[1146]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 01 18:18:01 dac.x1 sudo[2612]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-01 18:17 Mar 01 18:18:01 dac.x1 sudo[2612]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"