-- Logs begin at Thu 2019-02-14 18:11:58 HKT, end at Sat 2025-03-01 11:00:44 HKT. -- Mar 01 10:59:02 volumio-macmini volumio[1083]: info: Getting Spotify volume Mar 01 10:59:02 volumio-macmini volumio[1083]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Mar 01 10:59:02 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioGetState Mar 01 10:59:02 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:02 volumio-macmini volumio[1083]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 01 10:59:05 volumio-macmini wpa_supplicant[990]: wlan0: CTRL-EVENT-BEACON-LOSS Mar 01 10:59:06 volumio-macmini dhcpcd[759]: wlan0: carrier lost Mar 01 10:59:06 volumio-macmini avahi-daemon[712]: Withdrawing address record for 192.168.0.179 on wlan0. Mar 01 10:59:06 volumio-macmini avahi-daemon[712]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.179. Mar 01 10:59:06 volumio-macmini wpa_supplicant[990]: wlan0: CTRL-EVENT-DISCONNECTED bssid=b0:be:76:2b:c3:f6 reason=4 locally_generated=1 Mar 01 10:59:06 volumio-macmini avahi-daemon[712]: Interface wlan0.IPv4 no longer relevant for mDNS. Mar 01 10:59:06 volumio-macmini wpa_supplicant[990]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Mar 01 10:59:06 volumio-macmini wpa_supplicant[990]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US Mar 01 10:59:06 volumio-macmini volumio[1083]: info: Discovery: A device disappeared from network Mar 01 10:59:06 volumio-macmini volumio[1083]: info: Discovery: Device volumio-macmini disappeared from network Mar 01 10:59:06 volumio-macmini dhcpcd[759]: wlan0: deleting route to 192.168.0.0/24 Mar 01 10:59:06 volumio-macmini dhcpcd[759]: wlan0: deleting default route via 192.168.0.1 Mar 01 10:59:07 volumio-macmini wpa_supplicant[990]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN Mar 01 10:59:07 volumio-macmini ntpd[1913]: Deleting interface #3 wlan0, 192.168.0.179#123, interface stats: received=6, sent=12, dropped=0, active_time=29 secs Mar 01 10:59:07 volumio-macmini ntpd[1913]: 118.143.17.83 local addr 192.168.0.179 -> Mar 01 10:59:07 volumio-macmini ntpd[1913]: 118.143.17.82 local addr 192.168.0.179 -> Mar 01 10:59:07 volumio-macmini ntpd[1913]: 119.28.230.190 local addr 192.168.0.179 -> Mar 01 10:59:07 volumio-macmini ntpd[1913]: 209.58.185.100 local addr 192.168.0.179 -> Mar 01 10:59:07 volumio-macmini ntpd[1913]: 223.255.185.2 local addr 192.168.0.179 -> Mar 01 10:59:07 volumio-macmini ntpd[1913]: 162.159.200.1 local addr 192.168.0.179 -> Mar 01 10:59:09 volumio-macmini wpa_supplicant[990]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN Mar 01 10:59:09 volumio-macmini wpa_supplicant[990]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN Mar 01 10:59:09 volumio-macmini wpa_supplicant[990]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN Mar 01 10:59:09 volumio-macmini wpa_supplicant[990]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN Mar 01 10:59:09 volumio-macmini wpa_supplicant[990]: wlan0: SME: Trying to authenticate with b0:be:76:2b:c3:f6 (SSID='WAHKING17D_5G' freq=5180 MHz) Mar 01 10:59:09 volumio-macmini kernel: wlan0: authenticate with b0:be:76:2b:c3:f6 Mar 01 10:59:09 volumio-macmini wpa_supplicant[990]: wlan0: Trying to associate with b0:be:76:2b:c3:f6 (SSID='WAHKING17D_5G' freq=5180 MHz) Mar 01 10:59:09 volumio-macmini kernel: wlan0: send auth to b0:be:76:2b:c3:f6 (try 1/3) Mar 01 10:59:09 volumio-macmini kernel: wlan0: authenticated Mar 01 10:59:09 volumio-macmini kernel: wlan0: associate with b0:be:76:2b:c3:f6 (try 1/3) Mar 01 10:59:09 volumio-macmini wpa_supplicant[990]: wlan0: Associated with b0:be:76:2b:c3:f6 Mar 01 10:59:09 volumio-macmini wpa_supplicant[990]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Mar 01 10:59:09 volumio-macmini kernel: wlan0: RX AssocResp from b0:be:76:2b:c3:f6 (capab=0x411 status=0 aid=1) Mar 01 10:59:09 volumio-macmini kernel: wlan0: associated Mar 01 10:59:09 volumio-macmini wpa_supplicant[990]: wlan0: WPA: Key negotiation completed with b0:be:76:2b:c3:f6 [PTK=CCMP GTK=TKIP] Mar 01 10:59:09 volumio-macmini wpa_supplicant[990]: wlan0: CTRL-EVENT-CONNECTED - Connection to b0:be:76:2b:c3:f6 completed [id=0 id_str=] Mar 01 10:59:09 volumio-macmini dhcpcd[759]: wlan0: carrier acquired Mar 01 10:59:09 volumio-macmini dhcpcd[759]: wlan0: IAID cb:05:a9:76 Mar 01 10:59:10 volumio-macmini dhcpcd[759]: wlan0: rebinding lease of 192.168.0.179 Mar 01 10:59:10 volumio-macmini dhcpcd[759]: wlan0: probing address 192.168.0.179/24 Mar 01 10:59:10 volumio-macmini dhcpcd[759]: wlan0: soliciting an IPv6 router Mar 01 10:59:12 volumio-macmini volumio[1083]: info: Volumio Network Manager: Network status updated: 0 Mar 01 10:59:15 volumio-macmini dhcpcd[759]: wlan0: leased 192.168.0.179 for 7200 seconds Mar 01 10:59:15 volumio-macmini dhcpcd[759]: wlan0: adding route to 192.168.0.0/24 Mar 01 10:59:15 volumio-macmini dhcpcd[759]: wlan0: adding default route via 192.168.0.1 Mar 01 10:59:15 volumio-macmini avahi-daemon[712]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.179. Mar 01 10:59:15 volumio-macmini avahi-daemon[712]: New relevant interface wlan0.IPv4 for mDNS. Mar 01 10:59:15 volumio-macmini avahi-daemon[712]: Registering new address record for 192.168.0.179 on wlan0.IPv4. Mar 01 10:59:15 volumio-macmini ntpd[1913]: ntpd exiting on signal 15 (Terminated) Mar 01 10:59:15 volumio-macmini systemd[1]: Stopping Network Time Service... Mar 01 10:59:15 volumio-macmini systemd[1]: ntp.service: Succeeded. Mar 01 10:59:15 volumio-macmini systemd[1]: Stopped Network Time Service. Mar 01 10:59:15 volumio-macmini systemd[1]: Starting Network Time Service... Mar 01 10:59:15 volumio-macmini ntpd[2103]: ntpd 4.2.8p12@1.3728-o (1): Starting Mar 01 10:59:15 volumio-macmini ntpd[2103]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Mar 01 10:59:15 volumio-macmini systemd[1]: Started Network Time Service. Mar 01 10:59:15 volumio-macmini ntpd[2109]: proto: precision = 0.120 usec (-23) Mar 01 10:59:15 volumio-macmini ntpd[2109]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Mar 01 10:59:15 volumio-macmini ntpd[2109]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Mar 01 10:59:15 volumio-macmini ntpd[2109]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 795 days ago Mar 01 10:59:15 volumio-macmini ntpd[2109]: Listen and drop on 0 v6wildcard [::]:123 Mar 01 10:59:15 volumio-macmini ntpd[2109]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Mar 01 10:59:15 volumio-macmini ntpd[2109]: Listen normally on 2 lo 127.0.0.1:123 Mar 01 10:59:15 volumio-macmini ntpd[2109]: Listen normally on 3 wlan0 192.168.0.179:123 Mar 01 10:59:15 volumio-macmini ntpd[2109]: Listening on routing socket on fd #20 for interface updates Mar 01 10:59:15 volumio-macmini ntpd[2109]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Mar 01 10:59:15 volumio-macmini ntpd[2109]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Mar 01 10:59:15 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 01 10:59:15 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 01 10:59:15 volumio-macmini volumio[1083]: info: Discovery: Getting this device information Mar 01 10:59:15 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioGetState Mar 01 10:59:15 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:15 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 01 10:59:15 volumio-macmini volumio[1083]: verbose: New Socket.io Connection to 192.168.0.179 from 192.168.0.188 UA: unknown Engine version: 3 Transport: websocket Total Clients: 5 Mar 01 10:59:15 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioGetState Mar 01 10:59:15 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:15 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 01 10:59:15 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 01 10:59:16 volumio-macmini volumio[1083]: info: Discovery: adding 2463ba91-3fc7-4135-a06f-7b038542497f Mar 01 10:59:16 volumio-macmini volumio[1083]: info: Discovery: Found device Volumio-MacMini Mar 01 10:59:16 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioGetState Mar 01 10:59:16 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:16 volumio-macmini ntpd[2109]: Soliciting pool server 162.159.200.1 Mar 01 10:59:17 volumio-macmini ntpd[2109]: Soliciting pool server 223.255.185.2 Mar 01 10:59:17 volumio-macmini ntpd[2109]: Soliciting pool server 209.58.185.100 Mar 01 10:59:18 volumio-macmini volumio[1083]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E8%94%A1%E7%90%B4/%E8%80%81%E6%AD%8C/0e438fff-1402-4914-9da3-3bb0e51d4682.jpg' Mar 01 10:59:18 volumio-macmini sudo[2116]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 01 10:59:18 volumio-macmini sudo[2116]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 01 10:59:18 volumio-macmini sudo[2116]: pam_unix(sudo:session): session closed for user root Mar 01 10:59:18 volumio-macmini sudo[2119]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 01 10:59:18 volumio-macmini sudo[2119]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 01 10:59:18 volumio-macmini sudo[2119]: pam_unix(sudo:session): session closed for user root Mar 01 10:59:18 volumio-macmini volumio[1083]: verbose: New Socket.io Connection to 192.168.0.179 from 192.168.0.188 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 6 Mar 01 10:59:18 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 01 10:59:18 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioGetVisibleSources Mar 01 10:59:18 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 01 10:59:18 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioGetState Mar 01 10:59:18 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:18 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 01 10:59:18 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 01 10:59:18 volumio-macmini volumio[1083]: info: Received Get System Info Mar 01 10:59:18 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 01 10:59:18 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 01 10:59:18 volumio-macmini volumio[1083]: info: Discovery: Getting this device information Mar 01 10:59:18 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioGetState Mar 01 10:59:18 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:18 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 01 10:59:18 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioGetState Mar 01 10:59:18 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:18 volumio-macmini volumio[1083]: info: Listing playlists Mar 01 10:59:18 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 01 10:59:18 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 01 10:59:18 volumio-macmini ntpd[2109]: Soliciting pool server 119.28.230.190 Mar 01 10:59:18 volumio-macmini ntpd[2109]: Soliciting pool server 118.143.17.82 Mar 01 10:59:18 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 01 10:59:19 volumio-macmini ntpd[2109]: Soliciting pool server 2606:4700:f1::123 Mar 01 10:59:19 volumio-macmini ntpd[2109]: Soliciting pool server 118.143.17.83 Mar 01 10:59:20 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Mar 01 10:59:20 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 01 10:59:20 volumio-macmini volumio[1083]: info: Received Get System Info Mar 01 10:59:20 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 01 10:59:20 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 01 10:59:20 volumio-macmini volumio[1083]: info: Discovery: Getting this device information Mar 01 10:59:20 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioGetState Mar 01 10:59:20 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:20 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 01 10:59:20 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioGetQueue Mar 01 10:59:20 volumio-macmini volumio[1083]: info: CoreStateMachine::getQueue Mar 01 10:59:20 volumio-macmini volumio[1083]: info: CorePlayQueue::getQueue Mar 01 10:59:22 volumio-macmini volumio[1083]: info: Volumio Network Manager: Network status updated: 2 Mar 01 10:59:22 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 01 10:59:22 volumio-macmini volumio[1083]: info: CURURI: music-library Mar 01 10:59:22 volumio-macmini volumio[1083]: info: Preload queue cleared Mar 01 10:59:24 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 01 10:59:24 volumio-macmini volumio[1083]: info: CURURI: music-library/USB Mar 01 10:59:24 volumio-macmini volumio[1083]: info: Preload queue cleared Mar 01 10:59:26 volumio-macmini ntpd[2109]: receive: Unexpected origin timestamp 0xeb6cf68c.c9ab2d02 does not match aorg 0000000000.00000000 from server@119.28.230.190 xmt 0xeb6cf68e.0bd31ae8 Mar 01 10:59:26 volumio-macmini ntpd[2109]: receive: Unexpected origin timestamp 0xeb6cf68c.c9afc15c does not match aorg 0000000000.00000000 from server@209.58.185.100 xmt 0xeb6cf68e.106089b2 Mar 01 10:59:27 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 01 10:59:27 volumio-macmini volumio[1083]: info: CURURI: music-library/USB/8D3C-BD02 Mar 01 10:59:27 volumio-macmini volumio[1083]: info: Preload queue cleared Mar 01 10:59:29 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 01 10:59:30 volumio-macmini go-librespot[1970]: time="2025-03-01T10:59:30+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 10:59:30 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 10:59:30 volumio-macmini volumio[1083]: (node:1083) UnhandledPromiseRejectionWarning: Error: socket hang up Mar 01 10:59:30 volumio-macmini volumio[1083]: at connResetException (internal/errors.js:639:14) Mar 01 10:59:30 volumio-macmini volumio[1083]: at Socket.socketOnEnd (_http_client.js:499:23) Mar 01 10:59:30 volumio-macmini volumio[1083]: at Socket.emit (events.js:412:35) Mar 01 10:59:30 volumio-macmini volumio[1083]: at endReadableNT (internal/streams/readable.js:1333:12) Mar 01 10:59:30 volumio-macmini volumio[1083]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Mar 01 10:59:30 volumio-macmini volumio[1083]: (node:1083) 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: 5) Mar 01 10:59:30 volumio-macmini volumio[1083]: info: Connection to go-librespot Websocket closed Mar 01 10:59:30 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 10:59:32 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 01 10:59:32 volumio-macmini volumio[1083]: info: CURURI: music-library/USB/8D3C-BD02/Hi-Res Mar 01 10:59:32 volumio-macmini volumio[1083]: info: Preload queue cleared Mar 01 10:59:32 volumio-macmini volumio[1083]: info: Preloading song: music-library/USB/8D3C-BD02/Hi-Res/Recording_20230805150238.dsf Mar 01 10:59:32 volumio-macmini volumio[1083]: info: Exploding uri music-library/USB/8D3C-BD02/Hi-Res/Recording_20230805150238.dsf in service mpd Mar 01 10:59:32 volumio-macmini volumio[1083]: error: scanFolder - failure to stat '/mnt/USB/8D3C-BD02/Hi-Res/Recording_20230805150238.dsf' Mar 01 10:59:33 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 10:59:33 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 10:59:33 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 10:59:33 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 01 10:59:33 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 10:59:33 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 10:59:33 volumio-macmini go-librespot[2138]: Librespot-go daemon starting... Mar 01 10:59:33 volumio-macmini go-librespot[2138]: time="2025-03-01T10:59:33+08:00" level=info msg="generated new device id: df306956decb7f871c349a6bb4b322056adc0b5f" Mar 01 10:59:33 volumio-macmini go-librespot[2138]: time="2025-03-01T10:59:33+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 10:59:33 volumio-macmini go-librespot[2138]: time="2025-03-01T10:59:33+08:00" level=debug msg="obtained new client token: AABXOkZ+mBFv1Boa1yoMAcFx3WaTnteS9vjCWTY9k9Pv/6o4Ijdn5WwlZmhydJTrKMUETdyJ9eQqoMbqkgeUgml3Q1y5T9IrcF+upXPTB9yX7TzTr92xr2cFItXmE50UYWf3Vgj+qf7iU9I+PoXGTu09zf5u+0ntMjM7qtlCtbpp9Fl6105yYzViPlqJ9OXsvm85Xq6b4yUPTmktQo0qQKX1/yJGgeuQl/iRhlCOz5Ga5Qxt0wjoJyjwsfhoJAo=" Mar 01 10:59:33 volumio-macmini go-librespot[2138]: time="2025-03-01T10:59:33+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 10:59:33 volumio-macmini go-librespot[2138]: time="2025-03-01T10:59:33+08:00" level=debug msg="completed keyexchange" Mar 01 10:59:34 volumio-macmini go-librespot[2138]: time="2025-03-01T10:59:34+08:00" level=debug msg="completed challenge" Mar 01 10:59:34 volumio-macmini go-librespot[2138]: time="2025-03-01T10:59:34+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 10:59:34 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 10:59:34 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 10:59:36 volumio-macmini volumio[1083]: info: Preload queue cleared Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CoreStateMachine::ClearQueue Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CoreStateMachine::stop Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CorePlayQueue::clearPlayQueue Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CorePlayQueue::saveQueue Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioPushQueue Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CoreStateMachine::addQueueItems Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CorePlayQueue::addQueueItems Mar 01 10:59:36 volumio-macmini volumio[1083]: info: Preload queue cleared Mar 01 10:59:36 volumio-macmini volumio[1083]: info: Adding Item to queue: music-library/USB/8D3C-BD02/Hi-Res/劉美君 Mar 01 10:59:36 volumio-macmini volumio[1083]: info: Exploding uri music-library/USB/8D3C-BD02/Hi-Res/劉美君 in service mpd Mar 01 10:59:36 volumio-macmini volumio[1083]: error: scanFolder - failure to stat '/mnt/USB/8D3C-BD02/Hi-Res/劉美君' Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioPushQueue Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CorePlayQueue::saveQueue Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CoreStateMachine::updateTrackBlock Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrackBlock Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioPlay Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CoreStateMachine::play index 0 Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CoreStateMachine::stop Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CoreStateMachine::play index undefined Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 01 10:59:36 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:36 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 10:59:36 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 10:59:37 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 10:59:37 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 01 10:59:37 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 10:59:37 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 10:59:37 volumio-macmini go-librespot[2159]: Librespot-go daemon starting... Mar 01 10:59:37 volumio-macmini go-librespot[2159]: time="2025-03-01T10:59:37+08:00" level=info msg="generated new device id: b9b8ac054ed11fac7d6641e162b162489fadbda6" Mar 01 10:59:37 volumio-macmini go-librespot[2159]: time="2025-03-01T10:59:37+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 10:59:37 volumio-macmini go-librespot[2159]: time="2025-03-01T10:59:37+08:00" level=debug msg="obtained new client token: AAAoK2iQWPoxCpEYX3UIERlJLAQmZhapMxeMxnnRrECgD5lfUTM5rWcx8W4K/O42VkHk6t/pzdI1J6IJlsDxatwjmxmMBhJsddLawjyoCUWduFuEDon/BDfzAjSuBsf6QNpLMAnw13HodirHkW+Ca/L9AyCu0VPb8+aDZT5Fw0Zat7sWSy5LW24/jjB8CvD6dc8B+X9NrmPVHIVK5mjC5yzjDWUTCkYMe/GaREjQBbkBnlZp3wDN3AujxeEKYpg=" Mar 01 10:59:37 volumio-macmini go-librespot[2159]: time="2025-03-01T10:59: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-gew4.spotify.com:80]" Mar 01 10:59:37 volumio-macmini go-librespot[2159]: time="2025-03-01T10:59:37+08:00" level=debug msg="completed keyexchange" Mar 01 10:59:38 volumio-macmini go-librespot[2159]: time="2025-03-01T10:59:38+08:00" level=debug msg="completed challenge" Mar 01 10:59:38 volumio-macmini go-librespot[2159]: time="2025-03-01T10:59:38+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 10:59:38 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 10:59:38 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 10:59:39 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 01 10:59:39 volumio-macmini volumio[1083]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Mar 01 10:59:39 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Mar 01 10:59:39 volumio-macmini volumio[1083]: info: Received Get System Version Mar 01 10:59:39 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 01 10:59:39 volumio-macmini volumio[1083]: info: Received Get System Info Mar 01 10:59:39 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 01 10:59:39 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 01 10:59:39 volumio-macmini volumio[1083]: info: Discovery: Getting this device information Mar 01 10:59:39 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioGetState Mar 01 10:59:39 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:39 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 01 10:59:39 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 10:59:39 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 10:59:41 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 10:59:41 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Mar 01 10:59:41 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 10:59:41 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 10:59:41 volumio-macmini go-librespot[2169]: Librespot-go daemon starting... Mar 01 10:59:41 volumio-macmini go-librespot[2169]: time="2025-03-01T10:59:41+08:00" level=info msg="generated new device id: 1d2b5c341c6465c40f67a04b536627630ccaac3a" Mar 01 10:59:41 volumio-macmini go-librespot[2169]: time="2025-03-01T10:59:41+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 10:59:41 volumio-macmini go-librespot[2169]: time="2025-03-01T10:59:41+08:00" level=debug msg="obtained new client token: AAD08cgVi7c+4qOkuENcRldM2krYyFpd4ecDB5heASThJHJPBlS/t6Nco/wItXCX9XNv4HtlyWzgi0Q5E6KaK/3HApVTsRJnKzp46VYV65ag59DnINdZPqn7K8QE5xaMLJVRbbxtP6Yji037Qp+xygHmrFptDvRAxAtSidNRE0Li9Qw5O4cSceWLRsA3Jihbk0XDXMDcadZg72HMF76nimXI8GbOV195F4jBmLV6LhEGQI1UMxV6C4wRuxeG" Mar 01 10:59:41 volumio-macmini go-librespot[2169]: time="2025-03-01T10:59: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 10:59:41 volumio-macmini go-librespot[2169]: time="2025-03-01T10:59:41+08:00" level=debug msg="completed keyexchange" Mar 01 10:59:41 volumio-macmini go-librespot[2169]: time="2025-03-01T10:59:41+08:00" level=debug msg="completed challenge" Mar 01 10:59:41 volumio-macmini go-librespot[2169]: time="2025-03-01T10:59:41+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 10:59:41 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 10:59:41 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 10:59:42 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 10:59:42 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 10:59:44 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 10:59:44 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Mar 01 10:59:44 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 10:59:44 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 10:59:44 volumio-macmini go-librespot[2190]: Librespot-go daemon starting... Mar 01 10:59:44 volumio-macmini go-librespot[2190]: time="2025-03-01T10:59:44+08:00" level=info msg="generated new device id: ba2d974bae9b07f5824761b9e24fcb13ada335d8" Mar 01 10:59:44 volumio-macmini go-librespot[2190]: time="2025-03-01T10:59:44+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 10:59:45 volumio-macmini go-librespot[2190]: time="2025-03-01T10:59:45+08:00" level=debug msg="obtained new client token: AAC0ozAhU18opoGhs5kc5GQDIzKGE6vIwuGZlGA6rGfcr3uIl7xbcHgPqa/nxMaZLfGH/DPOiY6bq+Pu1DesM5UUkgOADROKDh+UKS68wHNEsh4ugUVXOt5y165Anfkm3cqG8rRG9a7iVj/b1OaJGJYVezXsMowd+5n7AeSP4iVq2b0GRkvG8CkGgfrthS8gDqu3fGYDPeyfKUqFYDNCr3wbyXVmzwvd2C7Pvbcgrqm49hCLLz3cd/vx8axX" Mar 01 10:59:45 volumio-macmini go-librespot[2190]: time="2025-03-01T10:59:45+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 10:59:45 volumio-macmini go-librespot[2190]: time="2025-03-01T10:59:45+08:00" level=debug msg="completed keyexchange" Mar 01 10:59:45 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 10:59:45 volumio-macmini go-librespot[2190]: time="2025-03-01T10:59:45+08:00" level=debug msg="new websocket client" Mar 01 10:59:45 volumio-macmini volumio[1083]: info: Connection to go-librespot Websocket established Mar 01 10:59:45 volumio-macmini go-librespot[2190]: time="2025-03-01T10:59:45+08:00" level=debug msg="completed challenge" Mar 01 10:59:45 volumio-macmini go-librespot[2190]: time="2025-03-01T10:59:45+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 10:59:45 volumio-macmini volumio[1083]: info: Connection to go-librespot Websocket closed Mar 01 10:59:45 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 10:59:45 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 01 10:59:47 volumio-macmini volumio[1083]: info: Retrieving Cloud Streaming UI Mar 01 10:59:47 volumio-macmini volumio[1083]: info: Getting Tidal Cloud Configuration Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 01 10:59:47 volumio-macmini volumio[1083]: info: Getting Qobuz Cloud Configuration Mar 01 10:59:47 volumio-macmini volumio[1083]: info: Asking plugin for UI Config Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 01 10:59:47 volumio-macmini volumio[1083]: info: Getting Spotify Cloud Configuration Mar 01 10:59:47 volumio-macmini volumio[1083]: info: Asking plugin for UI Config Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 01 10:59:47 volumio-macmini volumio[1083]: info: Saving Spotify Acccount Mar 01 10:59:47 volumio-macmini volumio[1083]: info: Got Tidal Cloud Configuration Mar 01 10:59:47 volumio-macmini volumio[1083]: info: Got it Mar 01 10:59:47 volumio-macmini volumio[1083]: info: Got it Mar 01 10:59:47 volumio-macmini volumio[1083]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 01 10:59:47 volumio-macmini volumio[1083]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioGetBrowseSources Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioGetBrowseSources Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioGetBrowseSources Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 01 10:59:47 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Mar 01 10:59:48 volumio-macmini volumio[1083]: info: Getting Spotify volume Mar 01 10:59:48 volumio-macmini volumio[1083]: (node:1083) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 10:59:48 volumio-macmini volumio[1083]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Mar 01 10:59:48 volumio-macmini volumio[1083]: (node:1083) 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: 6) Mar 01 10:59:48 volumio-macmini volumio[1083]: 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 01 10:59:48 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioGetState Mar 01 10:59:48 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:48 volumio-macmini volumio[1083]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 01 10:59:48 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 10:59:48 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 10:59:48 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 10:59:48 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Mar 01 10:59:48 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 10:59:48 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 10:59:48 volumio-macmini go-librespot[2200]: Librespot-go daemon starting... Mar 01 10:59:48 volumio-macmini go-librespot[2200]: time="2025-03-01T10:59:48+08:00" level=info msg="generated new device id: 06a1c52d3546eb0e2a8493acad527ed3e0d21bb3" Mar 01 10:59:48 volumio-macmini go-librespot[2200]: time="2025-03-01T10:59:48+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 10:59:48 volumio-macmini go-librespot[2200]: time="2025-03-01T10:59:48+08:00" level=debug msg="obtained new client token: AADFODTkih9OfrMKEItSqyEGMwB4EZdm66+lc6LQv2IE/Nm4k6KM8bCfPpzKH8OMhbVlHlxXRjJebIPoxOtat9qpzXr2l5gm+ITj7hH3FzOLc9vSI+rE4VAz/xirKwPwN6AsvA3QhhGgoSEBDue9VlPMCXLgyq9gvSyoHYjl2j8rWvSSt2vCMP1/LgYdP2101haJJDD/Tv+7GyfVhgJRkDG/QZhlvA2k7eGYF4tjbiqYDvr+a+PUYoo9otg3BmE=" Mar 01 10:59:48 volumio-macmini go-librespot[2200]: time="2025-03-01T10:59:48+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 10:59:48 volumio-macmini go-librespot[2200]: time="2025-03-01T10:59:48+08:00" level=debug msg="completed keyexchange" Mar 01 10:59:49 volumio-macmini go-librespot[2200]: time="2025-03-01T10:59:49+08:00" level=debug msg="completed challenge" Mar 01 10:59:49 volumio-macmini go-librespot[2200]: time="2025-03-01T10:59:49+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 10:59:49 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 10:59:49 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: ControllerMpd::sendMpdCommand rescan Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: ControllerMpd::sendMpdCommand status Mar 01 10:59:50 volumio-macmini volumio[1083]: info: Mar 01 10:59:50 volumio-macmini volumio[1083]: ---------------------------- MPD announces state update: update Mar 01 10:59:50 volumio-macmini volumio[1083]: info: sendMpdCommand rescan took 3 milliseconds Mar 01 10:59:50 volumio-macmini volumio[1083]: info: ControllerMpd::getState Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: ControllerMpd::sendMpdCommand status Mar 01 10:59:50 volumio-macmini volumio[1083]: info: sendMpdCommand status took 2 milliseconds Mar 01 10:59:50 volumio-macmini volumio[1083]: info: sendMpdCommand status took 1 milliseconds Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: ControllerMpd::parseState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: Command Router : Notfying DB Updatetrue Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: ControllerMpd::parseState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: ControllerMpd::pushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreCommandRouter::servicePushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreStateMachine::pushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioPushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: CURRENT POSITION 0 Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreStateMachine::syncState stateService stop Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreStateMachine::syncState currentStatus stop Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreStateMachine::pushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioPushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: No code Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreStateMachine::pushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioPushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: ------------------------------ 102ms Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: ControllerMpd::sendMpdCommand status Mar 01 10:59:50 volumio-macmini volumio[1083]: info: Mar 01 10:59:50 volumio-macmini volumio[1083]: ---------------------------- MPD announces state update: update Mar 01 10:59:50 volumio-macmini volumio[1083]: info: ControllerMpd::getState Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: ControllerMpd::sendMpdCommand status Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: ControllerMpd::sendMpdCommand status Mar 01 10:59:50 volumio-macmini volumio[1083]: info: Mar 01 10:59:50 volumio-macmini volumio[1083]: ---------------------------- MPD announces state update: update Mar 01 10:59:50 volumio-macmini volumio[1083]: info: ControllerMpd::getState Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: ControllerMpd::sendMpdCommand status Mar 01 10:59:50 volumio-macmini volumio[1083]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 01 10:59:50 volumio-macmini volumio[1083]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 01 10:59:50 volumio-macmini volumio[1083]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 01 10:59:50 volumio-macmini volumio[1083]: info: sendMpdCommand status took 41 milliseconds Mar 01 10:59:50 volumio-macmini volumio[1083]: info: sendMpdCommand status took 40 milliseconds Mar 01 10:59:50 volumio-macmini volumio[1083]: info: sendMpdCommand status took 41 milliseconds Mar 01 10:59:50 volumio-macmini volumio[1083]: info: sendMpdCommand status took 40 milliseconds Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: ControllerMpd::parseState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: Command Router : Notfying DB Updatetrue Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreCommandRouter::Close All Modals sent Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: ControllerMpd::parseState Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: ControllerMpd::parseState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: Command Router : Notfying DB Updatetrue Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreCommandRouter::Close All Modals sent Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: ControllerMpd::parseState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: ControllerMpd::pushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreCommandRouter::servicePushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreStateMachine::pushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioPushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: CURRENT POSITION 0 Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreStateMachine::syncState stateService stop Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreStateMachine::syncState currentStatus stop Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreStateMachine::pushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioPushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: No code Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreStateMachine::pushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioPushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: ControllerMpd::pushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreCommandRouter::servicePushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreStateMachine::pushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioPushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Mar 01 10:59:50 volumio-macmini volumio[1083]: verbose: CURRENT POSITION 0 Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreStateMachine::syncState stateService stop Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreStateMachine::syncState currentStatus stop Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreStateMachine::pushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioPushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: No code Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreStateMachine::pushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 10:59:50 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioPushState Mar 01 10:59:50 volumio-macmini volumio[1083]: info: ------------------------------ 119ms Mar 01 10:59:50 volumio-macmini volumio[1083]: info: ------------------------------ 118ms Mar 01 10:59:50 volumio-macmini volumio[1083]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 01 10:59:50 volumio-macmini volumio[1083]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 01 10:59:50 volumio-macmini volumio[1083]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 01 10:59:50 volumio-macmini volumio[1083]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 01 10:59:50 volumio-macmini volumio[1083]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 01 10:59:50 volumio-macmini volumio[1083]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 01 10:59:51 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 01 10:59:51 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 10:59:51 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 10:59:52 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 10:59:52 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Mar 01 10:59:52 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 10:59:52 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 10:59:52 volumio-macmini go-librespot[2214]: Librespot-go daemon starting... Mar 01 10:59:52 volumio-macmini go-librespot[2214]: time="2025-03-01T10:59:52+08:00" level=info msg="generated new device id: 22d6c250f15612c6242ebc4345c8012ba53fc4c6" Mar 01 10:59:52 volumio-macmini go-librespot[2214]: time="2025-03-01T10:59:52+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 10:59:52 volumio-macmini go-librespot[2214]: time="2025-03-01T10:59:52+08:00" level=debug msg="obtained new client token: AACTLL85tX8BSwpsXHQPmt0Nu5HAxQgAI52iiQvs5UudbC2N1M1nxsrie5PBcPa7ILxJX7gRbjdJr6JYhnQkjkNaa2zon/BI0/8PySgalFw0c55LoxTRD3iMWgp95xlghPP5eJb/j0TKMF47oeT9Q+c1MiKUv7J7h0/1eTvw3joih0z+QeoWREc4w/1iw2hgEyxmvLQV4winHrNOuMFk19rbalKsQRqJ2brc3yCg5iK6lvpzduXcGiXypOoNSIk=" Mar 01 10:59:52 volumio-macmini go-librespot[2214]: time="2025-03-01T10:59:52+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 10:59:52 volumio-macmini go-librespot[2214]: time="2025-03-01T10:59:52+08:00" level=debug msg="completed keyexchange" Mar 01 10:59:53 volumio-macmini go-librespot[2214]: time="2025-03-01T10:59:53+08:00" level=debug msg="completed challenge" Mar 01 10:59:53 volumio-macmini go-librespot[2214]: time="2025-03-01T10:59:53+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 10:59:53 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 10:59:53 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 10:59:54 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 10:59:54 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 10:59:55 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 01 10:59:56 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 10:59:56 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Mar 01 10:59:56 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 10:59:56 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 10:59:56 volumio-macmini go-librespot[2235]: Librespot-go daemon starting... Mar 01 10:59:56 volumio-macmini go-librespot[2235]: time="2025-03-01T10:59:56+08:00" level=info msg="generated new device id: a8027bb322054f78d1e0da4309d7c8726f071762" Mar 01 10:59:56 volumio-macmini go-librespot[2235]: time="2025-03-01T10:59:56+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 10:59:56 volumio-macmini go-librespot[2235]: time="2025-03-01T10:59:56+08:00" level=debug msg="obtained new client token: AACSNuUZh4qxVfjxj9gU7XkEETmwh44W1FpGHnMeHDfz2cv7s6ph60DuGGBEmWW25uqzPZb7DX9HWntVleCkX18UF9O1X2zdrxnLweQbKL/jVTU38Lo2jWCOJJ3cwTGq5+lRp+bOiwkTSoPLC4qCjkh7k5tdWGk5uxWS33kGc75uVbHkHYWq1boqSsj+bFpEqAKK0TFd8j5X8ii2+8djxXqLzLVZJHLADIzBcJBnKDcd7swpmqzzxmMhT6jg" Mar 01 10:59:56 volumio-macmini go-librespot[2235]: time="2025-03-01T10:59:56+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 10:59:56 volumio-macmini go-librespot[2235]: time="2025-03-01T10:59:56+08:00" level=debug msg="completed keyexchange" Mar 01 10:59:56 volumio-macmini go-librespot[2235]: time="2025-03-01T10:59:56+08:00" level=debug msg="completed challenge" Mar 01 10:59:56 volumio-macmini go-librespot[2235]: time="2025-03-01T10:59:56+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 10:59:56 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 10:59:56 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 10:59:57 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 10:59:57 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 10:59:59 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 01 10:59:59 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 10:59:59 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Mar 01 10:59:59 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 10:59:59 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 10:59:59 volumio-macmini go-librespot[2245]: Librespot-go daemon starting... Mar 01 10:59:59 volumio-macmini go-librespot[2245]: time="2025-03-01T10:59:59+08:00" level=info msg="generated new device id: 4398213cf9e60113d03326d374ee8de0597fc17b" Mar 01 10:59:59 volumio-macmini go-librespot[2245]: time="2025-03-01T10:59:59+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 11:00:00 volumio-macmini go-librespot[2245]: time="2025-03-01T11:00:00+08:00" level=debug msg="obtained new client token: AACOmf/uXs5mMQ2dpDf0sSDPfwcOwzrIfeSKpJLkBa+L+a4geaxlMhZ+9U/KqBNRHTlDZbaFQNH+iA5WvXz4RAF3VQlTGxpUX5nqAloABJ6E3RiShBi0jqsJDF5Qsq9pYXSoA6onNoBAUDcnV0nyL0FDuazMQBo6OYP6nuPG+bcMB5/m+X2umva0Y9/+FIM7QNZWe029GER2pKNh5dB5KmCHjs4cshymhZxhMLx4rltp2oGi+1MbfHHfpYtW" Mar 01 11:00:00 volumio-macmini go-librespot[2245]: time="2025-03-01T11:00:00+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 11:00:00 volumio-macmini go-librespot[2245]: time="2025-03-01T11:00:00+08:00" level=debug msg="completed keyexchange" Mar 01 11:00:00 volumio-macmini go-librespot[2245]: time="2025-03-01T11:00:00+08:00" level=debug msg="completed challenge" Mar 01 11:00:00 volumio-macmini go-librespot[2245]: time="2025-03-01T11:00:00+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 11:00:00 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 11:00:00 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 11:00:00 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 11:00:00 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 11:00:01 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Mar 01 11:00:01 volumio-macmini volumio[1083]: verbose: ControllerMpd::sendMpdCommand update Mar 01 11:00:01 volumio-macmini volumio[1083]: info: sendMpdCommand update took 1 milliseconds Mar 01 11:00:03 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 01 11:00:03 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 11:00:03 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Mar 01 11:00:03 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 11:00:03 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 11:00:03 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 11:00:03 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 11:00:03 volumio-macmini go-librespot[2252]: Librespot-go daemon starting... Mar 01 11:00:03 volumio-macmini go-librespot[2252]: time="2025-03-01T11:00:03+08:00" level=info msg="generated new device id: b8320fdcff526d457de9eb208e058f967ca4e19f" Mar 01 11:00:03 volumio-macmini go-librespot[2252]: time="2025-03-01T11:00:03+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 11:00:03 volumio-macmini go-librespot[2252]: time="2025-03-01T11:00:03+08:00" level=debug msg="obtained new client token: AADPXuzDHLCIYMAiKruJIQ0PHwo8hVcXueZ9utUI9dRsMCrmhnD/HRxTDHas0ciCbB6HooRq5w1eE+i1T4f+b0cqEF/uiqFpeomTjtQVPAInCzttnO068rGMqHZM4a77b9HaXiQyCwlhgwLIG6VS3WQD0v4QshPsqDYw4D/ixux21C9eX2ac5cYHLdoiM2EnIlenyiwiQoy7CQq7KSDZhYdf6kkxiVq59FpTuRwrswTdm7Pjb+dChJv61jxoGd8=" Mar 01 11:00:03 volumio-macmini go-librespot[2252]: time="2025-03-01T11:00:03+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 11:00:03 volumio-macmini go-librespot[2252]: time="2025-03-01T11:00:03+08:00" level=debug msg="completed keyexchange" Mar 01 11:00:04 volumio-macmini go-librespot[2252]: time="2025-03-01T11:00:04+08:00" level=debug msg="completed challenge" Mar 01 11:00:04 volumio-macmini go-librespot[2252]: time="2025-03-01T11:00:04+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 11:00:04 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 11:00:04 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 11:00:06 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 11:00:06 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 11:00:07 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 11:00:07 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Mar 01 11:00:07 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 11:00:07 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 11:00:07 volumio-macmini go-librespot[2273]: Librespot-go daemon starting... Mar 01 11:00:07 volumio-macmini go-librespot[2273]: time="2025-03-01T11:00:07+08:00" level=info msg="generated new device id: 67990ee6d8064536fe4400005a698fb9e2854ca8" Mar 01 11:00:07 volumio-macmini go-librespot[2273]: time="2025-03-01T11:00:07+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 11:00:07 volumio-macmini go-librespot[2273]: time="2025-03-01T11:00:07+08:00" level=debug msg="obtained new client token: AADdmta4H722rmbrpHecDD0cWUDY1Dj6uhhieQvJBzswNBoWV2FbhggFkR7wCKYPEiQinT0xmlQZijKfUbuLkO8r4Yp/EGSps2b1teRj3B5Ql7CjW1Eb/JiJJAn6EJueOXYfNwZH0aHUMa/geDi3G1UV/eJ7grDKC0G4qGPc1HPqQ+pzqPaq6E4ydzAaTTNnC2zgiNYy8OV4Y2MAKXdskLX6mzqD0CQQARu9M+2SDz1/NI90T7wlE1x4wQfeDLk=" Mar 01 11:00:07 volumio-macmini go-librespot[2273]: time="2025-03-01T11:00:07+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 11:00:07 volumio-macmini go-librespot[2273]: time="2025-03-01T11:00:07+08:00" level=debug msg="completed keyexchange" Mar 01 11:00:08 volumio-macmini go-librespot[2273]: time="2025-03-01T11:00:08+08:00" level=debug msg="completed challenge" Mar 01 11:00:08 volumio-macmini go-librespot[2273]: time="2025-03-01T11:00:08+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 11:00:08 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 11:00:08 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 11:00:09 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 11:00:09 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 11:00:11 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 11:00:11 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Mar 01 11:00:11 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 11:00:11 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 11:00:11 volumio-macmini go-librespot[2284]: Librespot-go daemon starting... Mar 01 11:00:11 volumio-macmini go-librespot[2284]: time="2025-03-01T11:00:11+08:00" level=info msg="generated new device id: 725c06403e17041aee47b15c748adb4ec3350201" Mar 01 11:00:11 volumio-macmini go-librespot[2284]: time="2025-03-01T11:00:11+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 11:00:11 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 01 11:00:11 volumio-macmini volumio[1083]: info: CURURI: music-library Mar 01 11:00:11 volumio-macmini go-librespot[2284]: time="2025-03-01T11:00:11+08:00" level=debug msg="obtained new client token: AAByZygBJhg3ax3q7Li/AAugH+hlAUlcESrVt2RrzMhDgOjo9ULFY60rZPz+UsAPvQ0KW2lNHjIJeYqTDAFnnsmIEP1G7wFQqgvG3+wpWG8byCVywBQbb1un2fwgUjyNdvExXk+unCIYPSde8MBPdLQWl1UgJm/0IwL/AoMugtk5GskEoQ75W+3IpCnil13PHaUx7DgXN6hwckzPT24p7Y3QQcwqOVJvQHLZeuJU69GiSxCqXQa7yrXrEeX/" Mar 01 11:00:11 volumio-macmini go-librespot[2284]: time="2025-03-01T11:00:11+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 11:00:11 volumio-macmini volumio[1083]: info: Preload queue cleared Mar 01 11:00:11 volumio-macmini go-librespot[2284]: time="2025-03-01T11:00:11+08:00" level=debug msg="completed keyexchange" Mar 01 11:00:11 volumio-macmini go-librespot[2284]: time="2025-03-01T11:00:11+08:00" level=debug msg="completed challenge" Mar 01 11:00:11 volumio-macmini go-librespot[2284]: time="2025-03-01T11:00:11+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 11:00:11 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 11:00:11 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 11:00:12 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 11:00:12 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 11:00:13 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 01 11:00:13 volumio-macmini volumio[1083]: info: CURURI: music-library/USB Mar 01 11:00:13 volumio-macmini volumio[1083]: info: Preload queue cleared Mar 01 11:00:15 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 11:00:15 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Mar 01 11:00:15 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 11:00:15 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 11:00:15 volumio-macmini go-librespot[2305]: Librespot-go daemon starting... Mar 01 11:00:15 volumio-macmini go-librespot[2305]: time="2025-03-01T11:00:15+08:00" level=info msg="generated new device id: d785222315857d3a88566a06b071c4f263be6cbb" Mar 01 11:00:15 volumio-macmini go-librespot[2305]: time="2025-03-01T11:00:15+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 11:00:15 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 01 11:00:15 volumio-macmini volumio[1083]: info: CURURI: music-library/NAS Mar 01 11:00:15 volumio-macmini volumio[1083]: error: Failed LSINFO: null Mar 01 11:00:15 volumio-macmini go-librespot[2305]: time="2025-03-01T11:00:15+08:00" level=debug msg="obtained new client token: AABrKUlk8nkTTZETLLWEVsWJyprr27UhXP+Bl/aZGxfNabHv6Wn1EWTLX5hcVyR8S4JPuxoySpMLqhFCJLMW+7q5p7EanR8+B/h2nR5phNikEEUqCbTKjGn1VG6xi5XQPGfxtl7ZyTzv6xMK3OZ0R2YBgjwMQ4+nosUymMeif9Gnz07x9vCTKK42HpwXu6y5k0b7nWNpo2Xro1rnwAi3uf5/i3xEdIVogo3Y7CHbMLs2kABZx0U+IrLONqYXQd8=" Mar 01 11:00:15 volumio-macmini go-librespot[2305]: time="2025-03-01T11:00:15+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 11:00:15 volumio-macmini volumio[1083]: info: Preload queue cleared Mar 01 11:00:15 volumio-macmini go-librespot[2305]: time="2025-03-01T11:00:15+08:00" level=debug msg="completed keyexchange" Mar 01 11:00:15 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 11:00:15 volumio-macmini go-librespot[2305]: time="2025-03-01T11:00:15+08:00" level=debug msg="new websocket client" Mar 01 11:00:15 volumio-macmini volumio[1083]: info: Connection to go-librespot Websocket established Mar 01 11:00:15 volumio-macmini go-librespot[2305]: time="2025-03-01T11:00:15+08:00" level=debug msg="completed challenge" Mar 01 11:00:15 volumio-macmini go-librespot[2305]: time="2025-03-01T11:00:15+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 11:00:15 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 11:00:15 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 11:00:15 volumio-macmini volumio[1083]: info: Connection to go-librespot Websocket closed Mar 01 11:00:17 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 01 11:00:17 volumio-macmini volumio[1083]: info: CURURI: music-library/INTERNAL Mar 01 11:00:17 volumio-macmini volumio[1083]: error: Failed LSINFO: null Mar 01 11:00:17 volumio-macmini volumio[1083]: info: Preload queue cleared Mar 01 11:00:18 volumio-macmini volumio[1083]: info: Getting Spotify volume Mar 01 11:00:18 volumio-macmini volumio[1083]: (node:1083) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 11:00:18 volumio-macmini volumio[1083]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Mar 01 11:00:18 volumio-macmini volumio[1083]: (node:1083) 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: 7) Mar 01 11:00:18 volumio-macmini volumio[1083]: 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 01 11:00:18 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioGetState Mar 01 11:00:18 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 11:00:18 volumio-macmini volumio[1083]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 01 11:00:18 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 11:00:18 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 11:00:19 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 11:00:19 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Mar 01 11:00:19 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 11:00:19 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 11:00:19 volumio-macmini go-librespot[2353]: Librespot-go daemon starting... Mar 01 11:00:19 volumio-macmini go-librespot[2353]: time="2025-03-01T11:00:19+08:00" level=info msg="generated new device id: 4735e3c7c8cf339031ff01c023b98074c0dcfb81" Mar 01 11:00:19 volumio-macmini go-librespot[2353]: time="2025-03-01T11:00:19+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 11:00:19 volumio-macmini go-librespot[2353]: time="2025-03-01T11:00:19+08:00" level=debug msg="obtained new client token: AABiqHvMVkLVlFgMQA2R8M698/dAcMO3CfEsJ8AJvFnm5xIm8L1ToBnLvD6L89ZO9hJ/bkCR1Ld7DDhOQ4QityaO9cDP5WzjxSnIrrzc6HJzM2zFqvC92ek4V24vhMU/kGwPbNvx0Ywjv/vfsL+gRrP7YZPSJpEwNI6bjGZqE/fRBo2G/9e1gCOttT5DzD1aAc6b3WCYsPeiL0Ml0yPe0uaTtrBou+XQ4OIES81VgDGIQvGoU66qs2zq90PN" Mar 01 11:00:19 volumio-macmini go-librespot[2353]: time="2025-03-01T11:00:19+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 11:00:19 volumio-macmini go-librespot[2353]: time="2025-03-01T11:00:19+08:00" level=debug msg="completed keyexchange" Mar 01 11:00:19 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 01 11:00:19 volumio-macmini volumio[1083]: info: CURURI: music-library/USB Mar 01 11:00:19 volumio-macmini volumio[1083]: info: Preload queue cleared Mar 01 11:00:19 volumio-macmini go-librespot[2353]: time="2025-03-01T11:00:19+08:00" level=debug msg="completed challenge" Mar 01 11:00:19 volumio-macmini go-librespot[2353]: time="2025-03-01T11:00:19+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 11:00:19 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 11:00:19 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 11:00:21 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 11:00:21 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 11:00:22 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 01 11:00:22 volumio-macmini volumio[1083]: info: CURURI: music-library/USB/8D3C-BD02 Mar 01 11:00:22 volumio-macmini volumio[1083]: error: Failed LSINFO: null Mar 01 11:00:22 volumio-macmini volumio[1083]: info: Preload queue cleared Mar 01 11:00:22 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 11:00:22 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Mar 01 11:00:22 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 11:00:22 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 11:00:22 volumio-macmini go-librespot[2360]: Librespot-go daemon starting... Mar 01 11:00:22 volumio-macmini go-librespot[2360]: time="2025-03-01T11:00:22+08:00" level=info msg="generated new device id: 954be47d268e0656c0081bfcacc394f5e35d72b1" Mar 01 11:00:22 volumio-macmini go-librespot[2360]: time="2025-03-01T11:00:22+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 11:00:23 volumio-macmini go-librespot[2360]: time="2025-03-01T11:00:23+08:00" level=debug msg="obtained new client token: AACobVwgRHbDRlDh6Xi8kOswaRR62eiu4CcSwHpW1/LuXIGIyLR8vUkodzmyWQniYxBFHExTAJVWclwO4uBDoVMTxkIcK0BLWNDK6i3MdJjyDDIGQ54QhnzrVoY1F9UWx/I5aDQcy8D4D5IwmHhdy5QMCZYrrAzGroKV38DmGHVKx7M0qBf/Vu9vX098YAsYWYABIQOw9SHardOzKYBut5AqkauRCuFNYaTm4RPHVEcSrO7Y/rTzUdN5Ig==" Mar 01 11:00:23 volumio-macmini go-librespot[2360]: time="2025-03-01T11:00:23+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 11:00:23 volumio-macmini go-librespot[2360]: time="2025-03-01T11:00:23+08:00" level=debug msg="completed keyexchange" Mar 01 11:00:23 volumio-macmini go-librespot[2360]: time="2025-03-01T11:00:23+08:00" level=debug msg="completed challenge" Mar 01 11:00:23 volumio-macmini go-librespot[2360]: time="2025-03-01T11:00:23+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 11:00:23 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 11:00:23 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 11:00:24 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 11:00:24 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 11:00:26 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 01 11:00:26 volumio-macmini volumio[1083]: info: CURURI: music-library/USB/ACFB-F40E Mar 01 11:00:26 volumio-macmini volumio[1083]: info: Preload queue cleared Mar 01 11:00:26 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 11:00:26 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Mar 01 11:00:26 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 11:00:26 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 11:00:26 volumio-macmini go-librespot[2381]: Librespot-go daemon starting... Mar 01 11:00:26 volumio-macmini go-librespot[2381]: time="2025-03-01T11:00:26+08:00" level=info msg="generated new device id: cf4b04fb9f10a7ef76a54a2ba03e32de6d7a112b" Mar 01 11:00:26 volumio-macmini go-librespot[2381]: time="2025-03-01T11:00:26+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 11:00:26 volumio-macmini go-librespot[2381]: time="2025-03-01T11:00:26+08:00" level=debug msg="obtained new client token: AAASszKHXRj1b6GVgxwBOp4mIAYo6wmb3r8oR01Gv5v6JlSdOv4PBU7XVNzuWgH05sMwP5WN7HnqJyUVx8kIXetcxiqOfueGry4dghJoXcWmQOnikhv9pj7o/qn8y+h/bMQzdSG2a/j8/GaqMlQtuVSswgI8094eFXWPoRL6Rzwbu60WgN9kwXDtAw3RKjch5IXiBKir+dsIM0HNiVFqt906nY3yThhYq/mJmRbDa5QK7EScl1ZmUUZnqQ6mMu4=" Mar 01 11:00:26 volumio-macmini go-librespot[2381]: time="2025-03-01T11:00:26+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 11:00:26 volumio-macmini go-librespot[2381]: time="2025-03-01T11:00:26+08:00" level=debug msg="completed keyexchange" Mar 01 11:00:27 volumio-macmini go-librespot[2381]: time="2025-03-01T11:00:27+08:00" level=debug msg="completed challenge" Mar 01 11:00:27 volumio-macmini go-librespot[2381]: time="2025-03-01T11:00:27+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 11:00:27 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 11:00:27 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 11:00:27 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 11:00:27 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 11:00:30 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 11:00:30 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Mar 01 11:00:30 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 11:00:30 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 11:00:30 volumio-macmini go-librespot[2392]: Librespot-go daemon starting... Mar 01 11:00:30 volumio-macmini go-librespot[2392]: time="2025-03-01T11:00:30+08:00" level=info msg="generated new device id: 7e16fae16996cc3d6a60fe790d4f9d20d83d9077" Mar 01 11:00:30 volumio-macmini go-librespot[2392]: time="2025-03-01T11:00:30+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 11:00:30 volumio-macmini go-librespot[2392]: time="2025-03-01T11:00:30+08:00" level=debug msg="obtained new client token: AABYrZueNwrqedWe4VMCn/DkfSY7nIY71S01226R59ZNjdntVOwklm0F37B0o8KoeDquiPnBgTvAJM76+xrGFD8kvWyw8PveHrw9zJV7m6MOVJ0NDDSDYfk03p7qYAzueYLjLGH9XpoYxc3dEn9rNhwp3HFyrtoGRcmfc+hKMTUonQkPA1rO+lVoWueJ0rIND7KPymKB34Rwa2hWp3H/n0RRCayoF4mSljWgXAYfF9Tq30n2a+QToiB10BeEAxw=" Mar 01 11:00:30 volumio-macmini go-librespot[2392]: time="2025-03-01T11:00:30+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 11:00:30 volumio-macmini go-librespot[2392]: time="2025-03-01T11:00:30+08:00" level=debug msg="completed keyexchange" Mar 01 11:00:30 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 11:00:30 volumio-macmini go-librespot[2392]: time="2025-03-01T11:00:30+08:00" level=debug msg="new websocket client" Mar 01 11:00:30 volumio-macmini volumio[1083]: info: Connection to go-librespot Websocket established Mar 01 11:00:31 volumio-macmini go-librespot[2392]: time="2025-03-01T11:00:31+08:00" level=debug msg="completed challenge" Mar 01 11:00:31 volumio-macmini go-librespot[2392]: time="2025-03-01T11:00:31+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 11:00:31 volumio-macmini volumio[1083]: info: Connection to go-librespot Websocket closed Mar 01 11:00:31 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 11:00:31 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 11:00:33 volumio-macmini volumio[1083]: info: Getting Spotify volume Mar 01 11:00:33 volumio-macmini volumio[1083]: (node:1083) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 11:00:33 volumio-macmini volumio[1083]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Mar 01 11:00:33 volumio-macmini volumio[1083]: (node:1083) 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: 8) Mar 01 11:00:33 volumio-macmini volumio[1083]: 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 01 11:00:33 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioGetState Mar 01 11:00:33 volumio-macmini volumio[1083]: info: CorePlayQueue::getTrack 0 Mar 01 11:00:33 volumio-macmini volumio[1083]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 01 11:00:34 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 11:00:34 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 11:00:34 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 11:00:34 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Mar 01 11:00:34 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 11:00:34 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 11:00:34 volumio-macmini go-librespot[2413]: Librespot-go daemon starting... Mar 01 11:00:34 volumio-macmini go-librespot[2413]: time="2025-03-01T11:00:34+08:00" level=info msg="generated new device id: 7756284b68e5aa6ff0e5c1933f5f33894d526efc" Mar 01 11:00:34 volumio-macmini go-librespot[2413]: time="2025-03-01T11:00:34+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 11:00:34 volumio-macmini go-librespot[2413]: time="2025-03-01T11:00:34+08:00" level=debug msg="obtained new client token: AAAHtu4KzVpuWuTysExoOoph2bQL0b0TrlSZ5Qde9k/LWeFxL+oMWVWeZfneVlq4w18vq34WeBXytIv+qYK/aB4zqzTc/uRFKUoldoH7r5qcdYmPkID28V/BIkwCSUKIkNxiEbbUJ6GeuNeNh5Yon/ju6SE4kFo8NX4zBqacNrwOQp79CDKtsDpTfXb0zOG0MmjXvYOQA9rmwkDdt5SCQ5bBn5Jl/tUhKlg48J6blJKQWjQXI9Ldw7hSDXbs" Mar 01 11:00:34 volumio-macmini go-librespot[2413]: time="2025-03-01T11:00:34+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 11:00:34 volumio-macmini go-librespot[2413]: time="2025-03-01T11:00:34+08:00" level=debug msg="completed keyexchange" Mar 01 11:00:34 volumio-macmini go-librespot[2413]: time="2025-03-01T11:00:34+08:00" level=debug msg="completed challenge" Mar 01 11:00:34 volumio-macmini go-librespot[2413]: time="2025-03-01T11:00:34+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 11:00:34 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 11:00:34 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 11:00:37 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 01 11:00:37 volumio-macmini volumio[1083]: info: CURURI: music-library/USB/0E3084AB30849AFB Mar 01 11:00:37 volumio-macmini volumio[1083]: error: Failed LSINFO: null Mar 01 11:00:37 volumio-macmini volumio[1083]: info: Preload queue cleared Mar 01 11:00:37 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 11:00:37 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 11:00:37 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 11:00:37 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Mar 01 11:00:37 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 11:00:37 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 11:00:37 volumio-macmini go-librespot[2423]: Librespot-go daemon starting... Mar 01 11:00:37 volumio-macmini go-librespot[2423]: time="2025-03-01T11:00:37+08:00" level=info msg="generated new device id: 6f7d373184850f8c65f33628d9549367628ea086" Mar 01 11:00:37 volumio-macmini go-librespot[2423]: time="2025-03-01T11:00:37+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 11:00:39 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 01 11:00:39 volumio-macmini volumio[1083]: info: CURURI: music-library/USB/ACFB-F40E Mar 01 11:00:39 volumio-macmini volumio[1083]: info: Preload queue cleared Mar 01 11:00:39 volumio-macmini go-librespot[2423]: time="2025-03-01T11:00:39+08:00" level=debug msg="obtained new client token: AAB9813AJONHThMHcxXr9wDFrcksJK6znLrw3pjtFWtRfp6GRdXyfvN9185y9gHjvpnHJM4IkUARHNlCdg16stwHYKJb1qaA6rOV8sgdC0w1insyXTQ9ypKM/RTx95GKFDwyVOxBuDtl353yFOCzL/kCUYfUESy+FulrwHVuYZZibmri1Vhlt6fd195ibj9l7/mg30sc94vmKryvGcO0WetKm6gmyChG/z3fPPqKlOCpX5yUb8/KwsTuF5Uv" Mar 01 11:00:39 volumio-macmini go-librespot[2423]: time="2025-03-01T11:00:39+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 11:00:39 volumio-macmini go-librespot[2423]: time="2025-03-01T11:00:39+08:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.241.202:4070: connect: connection refused" Mar 01 11:00:39 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 11:00:39 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 11:00:40 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 11:00:40 volumio-macmini volumio[1083]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 11:00:40 volumio-macmini volumio[1083]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 01 11:00:40 volumio-macmini volumio[1083]: info: CURURI: music-library/USB/ACFB-F40E/日本流行曲 Mar 01 11:00:40 volumio-macmini volumio[1083]: info: Preload queue cleared Mar 01 11:00:42 volumio-macmini systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 11:00:42 volumio-macmini systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Mar 01 11:00:42 volumio-macmini systemd[1]: Stopped go-librespot Daemon. Mar 01 11:00:42 volumio-macmini systemd[1]: Started go-librespot Daemon. Mar 01 11:00:42 volumio-macmini go-librespot[2430]: Librespot-go daemon starting... Mar 01 11:00:42 volumio-macmini go-librespot[2430]: time="2025-03-01T11:00:42+08:00" level=info msg="generated new device id: 5f9cc6e4c7e980da71768c02deb34ecd2a4d2b94" Mar 01 11:00:42 volumio-macmini go-librespot[2430]: time="2025-03-01T11:00:42+08:00" level=debug msg="stored credentials found for 31dt6ww5xxklnfw5lpznmk4l43au" Mar 01 11:00:42 volumio-macmini go-librespot[2430]: time="2025-03-01T11:00:42+08:00" level=debug msg="obtained new client token: AABhcfj0KanrP5wNMb5XrKPKNirTI/BAOuihdhsl2g+t8BkByigQY6UAYpvXa57sLMW6RF4/J7mYJCTh19xsEFDip7n/0I6vFMVWEdZPe1iEoqgqsqyLiUHbillP9+qwchsYIyVnwdgAJcSdksaKrfWS+amwwCKXDy5mf9wGji8KFvl/C+AKLhEImJfqJZpYHueH5D2AQLYK0yAg9xNQdOJoNIcFtV5c2gdhWvl26XfPVdc0uXFLfKfzaxc6GrE=" Mar 01 11:00:42 volumio-macmini go-librespot[2430]: time="2025-03-01T11:00:42+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 11:00:42 volumio-macmini go-librespot[2430]: time="2025-03-01T11:00:42+08:00" level=debug msg="completed keyexchange" Mar 01 11:00:43 volumio-macmini go-librespot[2430]: time="2025-03-01T11:00:43+08:00" level=debug msg="completed challenge" Mar 01 11:00:43 volumio-macmini volumio[1083]: info: Initializing connection to go-librespot Websocket Mar 01 11:00:43 volumio-macmini go-librespot[2430]: time="2025-03-01T11:00:43+08:00" level=debug msg="new websocket client" Mar 01 11:00:43 volumio-macmini volumio[1083]: info: Connection to go-librespot Websocket established Mar 01 11:00:43 volumio-macmini go-librespot[2430]: time="2025-03-01T11:00:43+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 01 11:00:43 volumio-macmini systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 11:00:43 volumio-macmini volumio[1083]: info: Connection to go-librespot Websocket closed Mar 01 11:00:43 volumio-macmini systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 11:00:43 volumio-macmini volumio[1083]: info: Preload queue cleared Mar 01 11:00:43 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 01 11:00:43 volumio-macmini volumio[1083]: info: CoreStateMachine::ClearQueue Mar 01 11:00:43 volumio-macmini volumio[1083]: info: CoreStateMachine::stop Mar 01 11:00:43 volumio-macmini volumio[1083]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 01 11:00:43 volumio-macmini volumio[1083]: info: CorePlayQueue::clearPlayQueue Mar 01 11:00:43 volumio-macmini volumio[1083]: info: CorePlayQueue::saveQueue Mar 01 11:00:43 volumio-macmini volumio[1083]: info: CoreCommandRouter::volumioPushQueue Mar 01 11:00:43 volumio-macmini volumio[1083]: info: CoreStateMachine::addQueueItems Mar 01 11:00:43 volumio-macmini volumio[1083]: info: CorePlayQueue::addQueueItems Mar 01 11:00:43 volumio-macmini volumio[1083]: info: Preload queue cleared Mar 01 11:00:43 volumio-macmini volumio[1083]: info: Adding Item to queue: music-library/USB/ACFB-F40E/日本流行曲/日本群星 Mar 01 11:00:43 volumio-macmini volumio[1083]: info: Exploding uri music-library/USB/ACFB-F40E/日本流行曲/日本群星 in service mpd Mar 01 11:00:44 volumio-macmini volumio[1083]: info: ALBUMART /albumart?cacheid=396&web=%E4%BA%94%E8%BD%AE%E7%9C%9F%E5%BC%93%20-%20%E5%A5%BD%E6%97%B6%E4%BB%A3%E7%8F%8D%E8%97%8F%E7%B3%BB%E5%88%97-%E5%9B%9E%E5%BF%86%E5%BD%95%20DSD//extralarge&path=%2Fmnt%2FUSB%2FACFB-F40E%2F%E6%97%A5%E6%9C%AC%E6%B5%81%E8%A1%8C%E6%9B%B2%2F%E6%97%A5%E6%9C%AC%E7%BE%A4%E6%98%9F%2F%E4%BA%94%E8%BD%AE%E7%9C%9F%E5%BC%93%20-%20%E5%A5%BD%E6%97%B6%E4%BB%A3%E7%8F%8D%E8%97%8F%E7%B3%BB%E5%88%97-%E5%9B%9E%E5%BF%86%E5%BD%95%20DSD.zip&metadata=false Mar 01 11:00:44 volumio-macmini volumio[1083]: info: URI /mnt/USB/ACFB-F40E/日本流行曲/日本群星/五轮真弓 - 好时代珍藏系列-回忆录 DSD.zip Mar 01 11:00:44 volumio-macmini volumio[1083]: info: ALBUMART /albumart?cacheid=396&web=%E4%BA%94%E8%BD%AE%E7%9C%9F%E5%BC%93%20-%20%E5%A5%BD%E6%97%B6%E4%BB%A3%E7%8F%8D%E8%97%8F%E7%B3%BB%E5%88%97-%E5%9B%9E%E5%BF%86%E5%BD%95%20DSD//extralarge&path=%2Fmnt%2FUSB%2FACFB-F40E%2F%E6%97%A5%E6%9C%AC%E6%B5%81%E8%A1%8C%E6%9B%B2%2F%E6%97%A5%E6%9C%AC%E7%BE%A4%E6%98%9F%2F%E4%BA%94%E8%BD%AE%E7%9C%9F%E5%BC%93%20-%20%E5%A5%BD%E6%97%B6%E4%BB%A3%E7%8F%8D%E8%97%8F%E7%B3%BB%E5%88%97-%E5%9B%9E%E5%BF%86%E5%BD%95%20DSD.zip&metadata=false Mar 01 11:00:44 volumio-macmini volumio[1083]: info: URI /mnt/USB/ACFB-F40E/日本流行曲/日本群星/五轮真弓 - 好时代珍藏系列-回忆录 DSD.zip Mar 01 11:00:44 volumio-macmini volumio[1083]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 01 11:00:44 volumio-macmini volumio[1083]: Error: Unable to resolve or reject the same promise twice Mar 01 11:00:44 volumio-macmini volumio[1083]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Mar 01 11:00:44 volumio-macmini volumio[1083]: at /volumio/app/plugins/music_service/mpd/index.js:2569:21 Mar 01 11:00:44 volumio-macmini volumio[1083]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Mar 01 11:00:44 volumio-macmini volumio[1083]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Mar 01 11:00:44 volumio-macmini volumio[1083]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Mar 01 11:00:44 volumio-macmini volumio[1083]: at Socket.emit (events.js:400:28) Mar 01 11:00:44 volumio-macmini volumio[1083]: at addChunk (internal/streams/readable.js:293:12) Mar 01 11:00:44 volumio-macmini volumio[1083]: at readableAddChunk (internal/streams/readable.js:263:11) Mar 01 11:00:44 volumio-macmini volumio[1083]: at Socket.Readable.push (internal/streams/readable.js:206:10) Mar 01 11:00:44 volumio-macmini volumio[1083]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) Mar 01 11:00:44 volumio-macmini volumio[1083]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 01 11:00:44 volumio-macmini sudo[2460]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-01 10:59 Mar 01 11:00:44 volumio-macmini sudo[2460]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:25:16 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="66c567362bdbb3dc1644a18f7879afe7"