-- Logs begin at Thu 2019-02-14 17:11:59 +07, end at Sun 2025-12-07 17:36:56 +07. -- Dec 07 17:35:00 volumio-vietv volumio[3317]: info: Remote SSH Stopped Dec 07 17:35:00 volumio-vietv volumio[3317]: error: Cannot start Volumio Streaming Daemon Dec 07 17:35:00 volumio-vietv volumio[3317]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 07 17:35:00 volumio-vietv volumio[3317]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 07 17:35:00 volumio-vietv volumio[3317]: verbose: New Socket.io Connection to 192.168.1.9 from 192.168.1.23 UA: Mozilla/5.0 (Linux; Android 16; SM-S928B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.171 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Dec 07 17:35:00 volumio-vietv volumio[3317]: info: Received Get System Info Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:35:00 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:00 volumio-vietv volumio[3317]: info: Received Get System Info Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:35:00 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetVisibleSources Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 07 17:35:00 volumio-vietv volumio[3317]: info: Received Get System Info Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:35:00 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:00 volumio-vietv volumio[3317]: info: Listing playlists Dec 07 17:35:00 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:35:00 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 102. Dec 07 17:35:00 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetQueue Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreStateMachine::getQueue Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CorePlayQueue::getQueue Dec 07 17:35:00 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:35:00 volumio-vietv volumio[3317]: info: Received Get System Info Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:35:00 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:00 volumio-vietv go-librespot[3772]: go-librespot daemon starting... Dec 07 17:35:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 07 17:35:01 volumio-vietv ntpd[654]: Soliciting pool server 103.121.88.11 Dec 07 17:35:01 volumio-vietv go-librespot[3772]: time="2025-12-07T17:35:01+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:35:01 volumio-vietv go-librespot[3772]: time="2025-12-07T17:35:01+07:00" level=debug msg="app state loaded" Dec 07 17:35:01 volumio-vietv go-librespot[3772]: time="2025-12-07T17:35:01+07:00" level=debug msg="stored credentials not found" Dec 07 17:35:01 volumio-vietv go-librespot[3772]: time="2025-12-07T17:35:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:35:01 volumio-vietv volumio[3317]: info: Updating MyVolumio device info Dec 07 17:35:01 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 17:35:01 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 17:35:01 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 17:35:01 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 17:35:01 volumio-vietv volumio[3317]: info: Successfully Added MyVolumio device Dec 07 17:35:01 volumio-vietv go-librespot[3772]: time="2025-12-07T17:35:01+07: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]" Dec 07 17:35:01 volumio-vietv go-librespot[3772]: time="2025-12-07T17:35:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 17:35:01 volumio-vietv go-librespot[3772]: time="2025-12-07T17:35:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 17:35:01 volumio-vietv go-librespot[3772]: time="2025-12-07T17:35:01+07:00" level=info msg="zeroconf server listening on port 36961" Dec 07 17:35:01 volumio-vietv sudo[3781]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 07 17:35:01 volumio-vietv sudo[3781]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 07 17:35:01 volumio-vietv sudo[3781]: pam_unix(sudo:session): session closed for user root Dec 07 17:35:01 volumio-vietv sudo[3785]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 07 17:35:02 volumio-vietv sudo[3785]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 07 17:35:02 volumio-vietv sudo[3785]: pam_unix(sudo:session): session closed for user root Dec 07 17:35:02 volumio-vietv volumio[3317]: info: Received Get System Info Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:35:02 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:35:02 volumio-vietv volumio[3317]: verbose: New Socket.io Connection to 192.168.1.9 from 192.168.1.23 UA: Mozilla/5.0 (Linux; Android 16; SM-S928B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.171 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Dec 07 17:35:02 volumio-vietv volumio[3317]: info: Received Get System Info Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:35:02 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:02 volumio-vietv volumio[3317]: info: Received Get System Info Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:35:02 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetVisibleSources Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 07 17:35:02 volumio-vietv volumio[3317]: info: Received Get System Info Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:35:02 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:02 volumio-vietv volumio[3317]: info: Listing playlists Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetQueue Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreStateMachine::getQueue Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CorePlayQueue::getQueue Dec 07 17:35:02 volumio-vietv go-librespot[3772]: time="2025-12-07T17:35:02+07:00" level=debug msg="obtained new client token: AACCcOZEeknNrx848CqzvkV+A/YMKjM0Mzc06lzq0OrLYJsq639kUWk6CIj7VIxW+CVCosCiYWetteTbj/SZgrD5dCwZDBB8z+yVIiCT9C09a2sJBveg7FS7U/r+iJX3i45Ub7W25bbHH9y9lYYAVgSUH0l2ZKpqRiFkFKnYjBBMXCcia1toUBrdWJHvCakzh38lQzaKfdQ5w1acC9Gl1958//sak48yAF2npzkmzt5SgwiJztZ0" Dec 07 17:35:02 volumio-vietv go-librespot[3772]: time="2025-12-07T17:35:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 07 17:35:02 volumio-vietv volumio[3317]: info: Received Get System Info Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:35:02 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:02 volumio-vietv volumio[3317]: info: Received Get System Info Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:35:02 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:02 volumio-vietv volumio[3317]: info: Successfully Updated MyVolumio device Dec 07 17:35:02 volumio-vietv go-librespot[3772]: time="2025-12-07T17:35:02+07:00" level=debug msg="completed keyexchange" Dec 07 17:35:02 volumio-vietv go-librespot[3772]: time="2025-12-07T17:35:02+07:00" level=debug msg="completed challenge" Dec 07 17:35:02 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 07 17:35:02 volumio-vietv go-librespot[3772]: time="2025-12-07T17:35:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:35:02 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:35:02 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:35:02 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:35:02 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:35:04 volumio-vietv ntpd[654]: Soliciting pool server 103.221.223.185 Dec 07 17:35:04 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 07 17:35:04 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 07 17:35:05 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:35:05 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 103. Dec 07 17:35:05 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:35:05 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:35:05 volumio-vietv go-librespot[3788]: go-librespot daemon starting... Dec 07 17:35:05 volumio-vietv go-librespot[3788]: time="2025-12-07T17:35:05+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:35:05 volumio-vietv go-librespot[3788]: time="2025-12-07T17:35:05+07:00" level=debug msg="app state loaded" Dec 07 17:35:05 volumio-vietv go-librespot[3788]: time="2025-12-07T17:35:05+07:00" level=debug msg="stored credentials not found" Dec 07 17:35:05 volumio-vietv go-librespot[3788]: time="2025-12-07T17:35:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:35:05 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:35:06 volumio-vietv go-librespot[3788]: time="2025-12-07T17:35:06+07:00" level=debug msg="new websocket client" Dec 07 17:35:06 volumio-vietv volumio[3317]: info: Connection to go-librespot Websocket established Dec 07 17:35:06 volumio-vietv ntpd[654]: Soliciting pool server 160.187.147.197 Dec 07 17:35:06 volumio-vietv go-librespot[3788]: time="2025-12-07T17:35:06+07: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]" Dec 07 17:35:06 volumio-vietv go-librespot[3788]: time="2025-12-07T17:35:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 17:35:06 volumio-vietv go-librespot[3788]: time="2025-12-07T17:35:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 17:35:06 volumio-vietv go-librespot[3788]: time="2025-12-07T17:35:06+07:00" level=info msg="zeroconf server listening on port 39219" Dec 07 17:35:06 volumio-vietv go-librespot[3788]: time="2025-12-07T17:35:06+07:00" level=debug msg="obtained new client token: AAC7gIkJZlrP8sry6PiohPSB8Z2aERsojZLfFBIrG3iUvM6JCcAHMFJQKsBWYGDFa1+2/BBy/IY+6VhP9mbEPe7iT9P9+/IvFa8fPdBlo/QAAyxkso9D4plO17M/B1Q0Y3IKNXzVuVSjGaQF/Ihf76o0sK5pU91xQ4gJEsnF0b79p8I2IMkIQbn+FcA3dxMDgsufJF2f9bu00sKoD70u7BU/yJvbwB+0x7LlZoTMXE1pv5vxUQ1c0fs=" Dec 07 17:35:06 volumio-vietv go-librespot[3788]: time="2025-12-07T17:35:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 07 17:35:06 volumio-vietv go-librespot[3788]: time="2025-12-07T17:35:06+07:00" level=debug msg="completed keyexchange" Dec 07 17:35:06 volumio-vietv go-librespot[3788]: time="2025-12-07T17:35:06+07:00" level=debug msg="completed challenge" Dec 07 17:35:06 volumio-vietv go-librespot[3788]: time="2025-12-07T17:35:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:35:06 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:35:06 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:35:06 volumio-vietv volumio[3317]: info: Connection to go-librespot Websocket closed Dec 07 17:35:07 volumio-vietv ntpd[654]: Soliciting pool server 160.187.147.197 Dec 07 17:35:08 volumio-vietv volumio[3317]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Dec 07 17:35:08 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 17:35:08 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 17:35:08 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 17:35:08 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 07 17:35:08 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 07 17:35:08 volumio-vietv volumio[3317]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 07 17:35:08 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:08 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:08 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 07 17:35:08 volumio-vietv volumio-remote-updater[498]: No test mode Dec 07 17:35:08 volumio-vietv volumio-remote-updater[498]: No alpha test mode Dec 07 17:35:08 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 07 17:35:09 volumio-vietv volumio[3317]: info: Getting Spotify volume Dec 07 17:35:09 volumio-vietv volumio[3317]: (node:3317) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:35:09 volumio-vietv volumio[3317]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 07 17:35:09 volumio-vietv volumio[3317]: (node:3317) 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: 2) Dec 07 17:35:09 volumio-vietv volumio[3317]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 07 17:35:09 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:09 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:09 volumio-vietv volumio[3317]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 07 17:35:09 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 07 17:35:09 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:35:09 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:35:09 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:35:09 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 104. Dec 07 17:35:09 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:35:09 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:35:09 volumio-vietv go-librespot[3816]: go-librespot daemon starting... Dec 07 17:35:09 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 07 17:35:09 volumio-vietv go-librespot[3816]: time="2025-12-07T17:35:09+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:35:09 volumio-vietv go-librespot[3816]: time="2025-12-07T17:35:09+07:00" level=debug msg="app state loaded" Dec 07 17:35:09 volumio-vietv go-librespot[3816]: time="2025-12-07T17:35:09+07:00" level=debug msg="stored credentials not found" Dec 07 17:35:09 volumio-vietv go-librespot[3816]: time="2025-12-07T17:35:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:35:10 volumio-vietv go-librespot[3816]: time="2025-12-07T17:35:10+07: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]" Dec 07 17:35:10 volumio-vietv go-librespot[3816]: time="2025-12-07T17:35:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 07 17:35:10 volumio-vietv go-librespot[3816]: time="2025-12-07T17:35:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 07 17:35:10 volumio-vietv go-librespot[3816]: time="2025-12-07T17:35:10+07:00" level=info msg="zeroconf server listening on port 46743" Dec 07 17:35:10 volumio-vietv go-librespot[3816]: time="2025-12-07T17:35:10+07:00" level=debug msg="obtained new client token: AABmlGR05KyWX6d78Ifdb4ERQibfHBHz9GzQOGC/fllJV4ZG/CFTRjiQhZSZDJcjAo7mAwMUv8GywB16D8FiwWJqkD/Pz1bJtCDwd7X7m6cv7i1OFtk/aBdIdbh96NgvhaGJr7Zy+v2KP5TrVvnABhxeRgWinAz/4gUQ5j/jYqXVsVnfVXAGxK5LEUvlk14TQ+30i0tWlbcbxo6bDkutxXoqPUxtx5i0vWO4QhHCWI3JXt1pc35AnVo=" Dec 07 17:35:10 volumio-vietv go-librespot[3816]: time="2025-12-07T17:35:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 07 17:35:10 volumio-vietv go-librespot[3816]: time="2025-12-07T17:35:10+07:00" level=debug msg="completed keyexchange" Dec 07 17:35:10 volumio-vietv go-librespot[3816]: time="2025-12-07T17:35:10+07:00" level=debug msg="completed challenge" Dec 07 17:35:10 volumio-vietv go-librespot[3816]: time="2025-12-07T17:35:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:35:11 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:35:11 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:35:12 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 07 17:35:12 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:35:12 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:35:13 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 17:35:13 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 17:35:13 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 07 17:35:13 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 07 17:35:13 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 07 17:35:13 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 07 17:35:13 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetBrowseSources Dec 07 17:35:13 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 17:35:14 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:35:14 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 105. Dec 07 17:35:14 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:35:14 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:35:14 volumio-vietv go-librespot[3825]: go-librespot daemon starting... Dec 07 17:35:14 volumio-vietv go-librespot[3825]: time="2025-12-07T17:35:14+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:35:14 volumio-vietv go-librespot[3825]: time="2025-12-07T17:35:14+07:00" level=debug msg="app state loaded" Dec 07 17:35:14 volumio-vietv go-librespot[3825]: time="2025-12-07T17:35:14+07:00" level=debug msg="stored credentials not found" Dec 07 17:35:14 volumio-vietv go-librespot[3825]: time="2025-12-07T17:35:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:35:14 volumio-vietv go-librespot[3825]: time="2025-12-07T17:35:14+07: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]" Dec 07 17:35:14 volumio-vietv go-librespot[3825]: time="2025-12-07T17:35:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 17:35:14 volumio-vietv go-librespot[3825]: time="2025-12-07T17:35:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 17:35:14 volumio-vietv go-librespot[3825]: time="2025-12-07T17:35:14+07:00" level=info msg="zeroconf server listening on port 45999" Dec 07 17:35:15 volumio-vietv go-librespot[3825]: time="2025-12-07T17:35:15+07:00" level=debug msg="obtained new client token: AAALXB+2gH2i7OVjmB5dUymaT69qGOFy7oa4Dx/yWzwasJVexw5Jx98ElkDSBgslWPYm101ewQNPUiw/Hcyqi0cREQF85I2jz0NHMWU5elZOujdq9ImdJ18Q3R4jxtJsdrML04YbMo4kTwNH1NDaI7I1Rn2k1vCm4J695WT/Wha0WRyRQjXuz6TaIiUJg466hf25WiCqKa7eBFmw9zSTzDMgWKr8RKKgnKqDyjTC6ZqqUBCI956hztg=" Dec 07 17:35:15 volumio-vietv go-librespot[3825]: time="2025-12-07T17:35:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 07 17:35:15 volumio-vietv go-librespot[3825]: time="2025-12-07T17:35:15+07:00" level=debug msg="completed keyexchange" Dec 07 17:35:15 volumio-vietv go-librespot[3825]: time="2025-12-07T17:35:15+07:00" level=debug msg="completed challenge" Dec 07 17:35:15 volumio-vietv go-librespot[3825]: time="2025-12-07T17:35:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:35:15 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:35:15 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:35:15 volumio-vietv volumio[3317]: error: MyVolumio Plugin failed to authenticate in a timely fashion Dec 07 17:35:15 volumio-vietv volumio[3317]: info: Completed starting MyVolumio Plugin Dec 07 17:35:15 volumio-vietv volumio[3317]: [Metrics] CommandRouter: 61s 272.49ms Dec 07 17:35:15 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumiosetStartupVolume Dec 07 17:35:15 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 17:35:15 volumio-vietv volumio[3317]: info: VolumeController:: Setting startup Volume 30 Dec 07 17:35:15 volumio-vietv volumio[3317]: info: VolumeController::SetAlsaVolume30 Dec 07 17:35:15 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 17:35:15 volumio-vietv volumio[3317]: info: CoreCommandRouter::Close All Modals sent Dec 07 17:35:15 volumio-vietv volumio[3317]: info: CoreCommandRouter::Close All Modals sent Dec 07 17:35:15 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:15 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:15 volumio-vietv volumio[3317]: info: CoreStateMachine::pushState Dec 07 17:35:15 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:15 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 17:35:15 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioPushState Dec 07 17:35:15 volumio-vietv volumio[3317]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Dec 07 17:35:15 volumio-vietv volumio[3317]: SPOTIFY: SPOTIFY VOLUME undefined Dec 07 17:35:15 volumio-vietv volumio[3317]: SPOTIFY: VOLUMIO VOLUME 30 Dec 07 17:35:15 volumio-vietv volumio[3317]: info: Aligning Spotify Volume to Volumio Volume Dec 07 17:35:15 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:15 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:15 volumio-vietv volumio[3317]: info: Setting Spotify Volume from Volumio: 30 Dec 07 17:35:15 volumio-vietv volumio[3317]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 07 17:35:15 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:35:15 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:35:16 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 07 17:35:16 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 07 17:35:16 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 07 17:35:17 volumio-vietv volumio[3317]: SPOTIFY: SETTING SPOTIFY VOLUME 30 Dec 07 17:35:17 volumio-vietv volumio[3317]: info: Sending Spotify command with payload to local API: /player/volume Dec 07 17:35:17 volumio-vietv volumio[3317]: error: Failed to send command to Spotify local API: /player/volume: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:35:18 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:35:18 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 106. Dec 07 17:35:18 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:35:18 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:35:18 volumio-vietv go-librespot[3850]: go-librespot daemon starting... Dec 07 17:35:18 volumio-vietv go-librespot[3850]: time="2025-12-07T17:35:18+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:35:18 volumio-vietv go-librespot[3850]: time="2025-12-07T17:35:18+07:00" level=debug msg="app state loaded" Dec 07 17:35:18 volumio-vietv go-librespot[3850]: time="2025-12-07T17:35:18+07:00" level=debug msg="stored credentials not found" Dec 07 17:35:18 volumio-vietv go-librespot[3850]: time="2025-12-07T17:35:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:35:18 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:35:18 volumio-vietv go-librespot[3850]: time="2025-12-07T17:35:18+07:00" level=debug msg="new websocket client" Dec 07 17:35:18 volumio-vietv volumio[3317]: info: Connection to go-librespot Websocket established Dec 07 17:35:18 volumio-vietv go-librespot[3850]: time="2025-12-07T17:35:18+07: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]" Dec 07 17:35:18 volumio-vietv go-librespot[3850]: time="2025-12-07T17:35:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 07 17:35:18 volumio-vietv go-librespot[3850]: time="2025-12-07T17:35:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 07 17:35:18 volumio-vietv go-librespot[3850]: time="2025-12-07T17:35:18+07:00" level=info msg="zeroconf server listening on port 36649" Dec 07 17:35:19 volumio-vietv go-librespot[3850]: time="2025-12-07T17:35:19+07:00" level=debug msg="obtained new client token: AAAIalNTP8wT3rNRYOqJ1TE/AZ6FYYbAJM5/f5yu5mkfOsXmotP92nh0LZZojcTl5XIrjN0jnVcKolvhHyktg4jlW/TacPs88LfiFlqoELtoQY5Mi5QX/rtFm+i7Dr3hWvR1RwMQE/8WrlHogA+r6ckihzwOPONNGpRE4F8EvMxW5bd1mlejD48Ljdq8C4vhmh4RVaqDacvvh4nSOSg0MyRBmKkUds55ZvGwZIOePYrnNHj+PpZn" Dec 07 17:35:19 volumio-vietv go-librespot[3850]: time="2025-12-07T17:35:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 07 17:35:19 volumio-vietv go-librespot[3850]: time="2025-12-07T17:35:19+07:00" level=debug msg="completed keyexchange" Dec 07 17:35:19 volumio-vietv go-librespot[3850]: time="2025-12-07T17:35:19+07:00" level=debug msg="completed challenge" Dec 07 17:35:19 volumio-vietv go-librespot[3850]: time="2025-12-07T17:35:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:35:19 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:35:19 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:35:19 volumio-vietv volumio[3317]: info: Connection to go-librespot Websocket closed Dec 07 17:35:21 volumio-vietv volumio[3317]: info: Getting Spotify volume Dec 07 17:35:21 volumio-vietv volumio[3317]: (node:3317) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:35:21 volumio-vietv volumio[3317]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 07 17:35:21 volumio-vietv volumio[3317]: (node:3317) 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: 3) Dec 07 17:35:21 volumio-vietv volumio[3317]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 07 17:35:21 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:21 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:21 volumio-vietv volumio[3317]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Dec 07 17:35:22 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:35:22 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:35:22 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:35:22 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 107. Dec 07 17:35:22 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:35:22 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:35:22 volumio-vietv go-librespot[3858]: go-librespot daemon starting... Dec 07 17:35:22 volumio-vietv go-librespot[3858]: time="2025-12-07T17:35:22+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:35:22 volumio-vietv go-librespot[3858]: time="2025-12-07T17:35:22+07:00" level=debug msg="app state loaded" Dec 07 17:35:22 volumio-vietv go-librespot[3858]: time="2025-12-07T17:35:22+07:00" level=debug msg="stored credentials not found" Dec 07 17:35:22 volumio-vietv go-librespot[3858]: time="2025-12-07T17:35:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:35:22 volumio-vietv volumio[3317]: info: BOOT COMPLETED Dec 07 17:35:23 volumio-vietv go-librespot[3858]: time="2025-12-07T17:35:23+07: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]" Dec 07 17:35:23 volumio-vietv go-librespot[3858]: time="2025-12-07T17:35:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 07 17:35:23 volumio-vietv go-librespot[3858]: time="2025-12-07T17:35:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 07 17:35:23 volumio-vietv go-librespot[3858]: time="2025-12-07T17:35:23+07:00" level=info msg="zeroconf server listening on port 46665" Dec 07 17:35:23 volumio-vietv go-librespot[3858]: time="2025-12-07T17:35:23+07:00" level=debug msg="obtained new client token: AAAg7USwYtOeH61BRKZZIfzESSPJtynyVclM1kID3vIkUL52QnpJL1YArS+yxDegImJvI4nTTeLEgmQpp3P8+wO2VOW+HIqR9ysufApnepW/1Oo0pUlk3KECBADHkwpuNb23TjD49IiHVamx140OS/e5etrH0Mpwai5RbrYJi8kXHsXg0Qz4UzabpfdCh07HWxlX09wqOnPMKaup6H/MXDTraTYD75Z8jhx6iqNslgOrJkc+1S5le4I=" Dec 07 17:35:23 volumio-vietv go-librespot[3858]: time="2025-12-07T17:35:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 07 17:35:23 volumio-vietv go-librespot[3858]: time="2025-12-07T17:35:23+07:00" level=debug msg="completed keyexchange" Dec 07 17:35:23 volumio-vietv go-librespot[3858]: time="2025-12-07T17:35:23+07:00" level=debug msg="completed challenge" Dec 07 17:35:23 volumio-vietv go-librespot[3858]: time="2025-12-07T17:35:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:35:23 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:35:23 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:35:24 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:35:24 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:35:24 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:35:24 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:24 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:24 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:35:24 volumio-vietv volumio[3317]: verbose: New Socket.io Connection to 192.168.1.9:3000 from 192.168.1.23 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Dec 07 17:35:24 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:24 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:24 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 07 17:35:24 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 07 17:35:25 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:35:25 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:35:26 volumio-vietv sudo[3871]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 07 17:35:26 volumio-vietv sudo[3871]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 07 17:35:26 volumio-vietv sudo[3871]: pam_unix(sudo:session): session closed for user root Dec 07 17:35:26 volumio-vietv sudo[3875]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 07 17:35:26 volumio-vietv sudo[3875]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 07 17:35:26 volumio-vietv sudo[3875]: pam_unix(sudo:session): session closed for user root Dec 07 17:35:26 volumio-vietv volumio[3317]: verbose: New Socket.io Connection to 192.168.1.9 from 192.168.1.23 UA: Mozilla/5.0 (Linux; Android 16; SM-S928B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.171 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Dec 07 17:35:26 volumio-vietv sudo[3879]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 07 17:35:26 volumio-vietv sudo[3879]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 07 17:35:26 volumio-vietv sudo[3879]: pam_unix(sudo:session): session closed for user root Dec 07 17:35:26 volumio-vietv sudo[3883]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 07 17:35:26 volumio-vietv sudo[3883]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 07 17:35:26 volumio-vietv sudo[3883]: pam_unix(sudo:session): session closed for user root Dec 07 17:35:26 volumio-vietv volumio[3317]: verbose: New Socket.io Connection to 192.168.1.9 from 192.168.1.23 UA: Mozilla/5.0 (Linux; Android 16; SM-S928B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.171 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Dec 07 17:35:26 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 07 17:35:26 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetVisibleSources Dec 07 17:35:26 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 17:35:26 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:26 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:26 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 07 17:35:26 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 07 17:35:26 volumio-vietv volumio[3317]: info: Received Get System Info Dec 07 17:35:26 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:35:26 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:35:26 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:35:26 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:26 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:26 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:35:26 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:26 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:26 volumio-vietv volumio[3317]: info: Listing playlists Dec 07 17:35:26 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 07 17:35:26 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 07 17:35:26 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:35:26 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 108. Dec 07 17:35:26 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:35:26 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 07 17:35:26 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:35:26 volumio-vietv go-librespot[3886]: go-librespot daemon starting... Dec 07 17:35:27 volumio-vietv go-librespot[3886]: time="2025-12-07T17:35:27+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:35:27 volumio-vietv go-librespot[3886]: time="2025-12-07T17:35:27+07:00" level=debug msg="app state loaded" Dec 07 17:35:27 volumio-vietv go-librespot[3886]: time="2025-12-07T17:35:27+07:00" level=debug msg="stored credentials not found" Dec 07 17:35:27 volumio-vietv go-librespot[3886]: time="2025-12-07T17:35:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:35:27 volumio-vietv go-librespot[3886]: time="2025-12-07T17:35:27+07: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]" Dec 07 17:35:27 volumio-vietv go-librespot[3886]: time="2025-12-07T17:35:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 17:35:27 volumio-vietv go-librespot[3886]: time="2025-12-07T17:35:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 17:35:27 volumio-vietv go-librespot[3886]: time="2025-12-07T17:35:27+07:00" level=info msg="zeroconf server listening on port 42025" Dec 07 17:35:27 volumio-vietv go-librespot[3886]: time="2025-12-07T17:35:27+07:00" level=debug msg="obtained new client token: AADORMK317pP36gS5w0QK2sabQlM8r3EVuU9pL/6Wt6vCGf2/YmngnoAOkhtdF3k4bcy7pzz8AglkzVBEdfDKdoq19IsAIgTcXutSFtbOLV1TbbI8uFqrGaM+vfz+xw6hfox6LdFA3rMs+pIVDWvRpiipUFzkTI2Tux6zo9k/O8vHZvTj2qec2RsWwD2UgapdJ4VjuC4wvbxBfvb3pfotkNRr1GqOHh99sWZNTgKnjiX84uwufTgH+I=" Dec 07 17:35:27 volumio-vietv go-librespot[3886]: time="2025-12-07T17:35:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 07 17:35:27 volumio-vietv go-librespot[3886]: time="2025-12-07T17:35:27+07:00" level=debug msg="completed keyexchange" Dec 07 17:35:27 volumio-vietv go-librespot[3886]: time="2025-12-07T17:35:27+07:00" level=debug msg="completed challenge" Dec 07 17:35:28 volumio-vietv go-librespot[3886]: time="2025-12-07T17:35:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:35:28 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:35:28 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:35:28 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 07 17:35:28 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:35:28 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:35:28 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 07 17:35:28 volumio-vietv volumio[3317]: info: Received Get System Info Dec 07 17:35:28 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:35:28 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:35:28 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:35:28 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:28 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:28 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:35:29 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 07 17:35:29 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 07 17:35:29 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 07 17:35:29 volumio-vietv volumio[3317]: info: Received Get System Info Dec 07 17:35:29 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:35:29 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:35:29 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:35:29 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:29 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:29 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:35:31 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:35:31 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 109. Dec 07 17:35:31 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:35:31 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:35:31 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:35:31 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:35:31 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:31 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:31 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:35:31 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:35:31 volumio-vietv go-librespot[3909]: go-librespot daemon starting... Dec 07 17:35:31 volumio-vietv go-librespot[3909]: time="2025-12-07T17:35:31+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:35:31 volumio-vietv go-librespot[3909]: time="2025-12-07T17:35:31+07:00" level=debug msg="app state loaded" Dec 07 17:35:31 volumio-vietv go-librespot[3909]: time="2025-12-07T17:35:31+07:00" level=debug msg="stored credentials not found" Dec 07 17:35:31 volumio-vietv go-librespot[3909]: time="2025-12-07T17:35:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:35:31 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:35:31 volumio-vietv go-librespot[3909]: time="2025-12-07T17:35:31+07:00" level=debug msg="new websocket client" Dec 07 17:35:31 volumio-vietv volumio[3317]: info: Connection to go-librespot Websocket established Dec 07 17:35:31 volumio-vietv go-librespot[3909]: time="2025-12-07T17:35:31+07: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]" Dec 07 17:35:31 volumio-vietv go-librespot[3909]: time="2025-12-07T17:35:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 17:35:31 volumio-vietv go-librespot[3909]: time="2025-12-07T17:35:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 17:35:31 volumio-vietv go-librespot[3909]: time="2025-12-07T17:35:31+07:00" level=info msg="zeroconf server listening on port 35497" Dec 07 17:35:31 volumio-vietv go-librespot[3909]: time="2025-12-07T17:35:31+07:00" level=debug msg="obtained new client token: AACzId3cNi7YdSMa59fEcwRqb3GOeQ61co+/f353lMcIRsWKZdIv9x2k/bbei1//63C5nVkvCoj3iuGgI9hyz6GjGPEPXn7ZoN81QU8OzwAz816UY0PF4MZdkUc9kXFehnk42xAebSp1NkCdL8L7Rhee6j7PX9XnpxyLQUzele4sDVPTQj283DVIgQecSyFyvVb2Wg693nJqUxuFdXjTPrmF5AbyvcdKDckzHwSNm2o2Mu0Ltnxc5+0=" Dec 07 17:35:32 volumio-vietv go-librespot[3909]: time="2025-12-07T17:35:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 07 17:35:32 volumio-vietv go-librespot[3909]: time="2025-12-07T17:35:32+07:00" level=debug msg="completed keyexchange" Dec 07 17:35:32 volumio-vietv go-librespot[3909]: time="2025-12-07T17:35:32+07:00" level=debug msg="completed challenge" Dec 07 17:35:32 volumio-vietv go-librespot[3909]: time="2025-12-07T17:35:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:35:32 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:35:32 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:35:32 volumio-vietv volumio[3317]: info: Connection to go-librespot Websocket closed Dec 07 17:35:34 volumio-vietv volumio[3317]: info: Getting Spotify volume Dec 07 17:35:34 volumio-vietv volumio[3317]: (node:3317) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:35:34 volumio-vietv volumio[3317]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 07 17:35:34 volumio-vietv volumio[3317]: (node:3317) 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: 4) Dec 07 17:35:34 volumio-vietv volumio[3317]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 07 17:35:34 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:34 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:34 volumio-vietv volumio[3317]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Dec 07 17:35:35 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:35:35 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:35:35 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:35:35 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 110. Dec 07 17:35:35 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:35:35 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:35:35 volumio-vietv go-librespot[3917]: go-librespot daemon starting... Dec 07 17:35:35 volumio-vietv go-librespot[3917]: time="2025-12-07T17:35:35+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:35:35 volumio-vietv go-librespot[3917]: time="2025-12-07T17:35:35+07:00" level=debug msg="app state loaded" Dec 07 17:35:35 volumio-vietv go-librespot[3917]: time="2025-12-07T17:35:35+07:00" level=debug msg="stored credentials not found" Dec 07 17:35:35 volumio-vietv go-librespot[3917]: time="2025-12-07T17:35:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:35:35 volumio-vietv go-librespot[3917]: time="2025-12-07T17:35:35+07: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]" Dec 07 17:35:35 volumio-vietv go-librespot[3917]: time="2025-12-07T17:35:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 17:35:35 volumio-vietv go-librespot[3917]: time="2025-12-07T17:35:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 17:35:35 volumio-vietv go-librespot[3917]: time="2025-12-07T17:35:35+07:00" level=info msg="zeroconf server listening on port 40399" Dec 07 17:35:36 volumio-vietv go-librespot[3917]: time="2025-12-07T17:35:36+07:00" level=debug msg="obtained new client token: AAD97UzDJi+yrEhxC7dHo0s4sGY88dDE6HeAxfOjIVzyta90VBQwtqQXQ5WV6s2p2oK9eV7HNnyPlwvqGjT2Vs3H+sgF/m9KTBJT+hb1MQGvveflYfQN2pS7uPwKcZt69g2Z3zdIKl+FWqwegTr6si4XEck0tmJdUnfteDY5y7v2qBZR+ji4PN8MGopHAH+pamq719/pOGvV6k/lnau6iMBIpRpiGXVbF3o7I/hIygEu8tniZixq" Dec 07 17:35:36 volumio-vietv go-librespot[3917]: time="2025-12-07T17:35:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 07 17:35:36 volumio-vietv go-librespot[3917]: time="2025-12-07T17:35:36+07:00" level=debug msg="completed keyexchange" Dec 07 17:35:36 volumio-vietv go-librespot[3917]: time="2025-12-07T17:35:36+07:00" level=debug msg="completed challenge" Dec 07 17:35:36 volumio-vietv go-librespot[3917]: time="2025-12-07T17:35:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:35:36 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:35:36 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:35:36 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 07 17:35:38 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:35:38 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:35:39 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:35:39 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 111. Dec 07 17:35:39 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:35:39 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:35:39 volumio-vietv go-librespot[3978]: go-librespot daemon starting... Dec 07 17:35:39 volumio-vietv go-librespot[3978]: time="2025-12-07T17:35:39+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:35:39 volumio-vietv go-librespot[3978]: time="2025-12-07T17:35:39+07:00" level=debug msg="app state loaded" Dec 07 17:35:39 volumio-vietv go-librespot[3978]: time="2025-12-07T17:35:39+07:00" level=debug msg="stored credentials not found" Dec 07 17:35:39 volumio-vietv go-librespot[3978]: time="2025-12-07T17:35:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:35:40 volumio-vietv go-librespot[3978]: time="2025-12-07T17:35:40+07: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]" Dec 07 17:35:40 volumio-vietv go-librespot[3978]: time="2025-12-07T17:35:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 17:35:40 volumio-vietv go-librespot[3978]: time="2025-12-07T17:35:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 17:35:40 volumio-vietv go-librespot[3978]: time="2025-12-07T17:35:40+07:00" level=info msg="zeroconf server listening on port 34011" Dec 07 17:35:40 volumio-vietv go-librespot[3978]: time="2025-12-07T17:35:40+07:00" level=debug msg="obtained new client token: AAD3jLYLALK6w0wC0uj2sWR3hhLDcE3QC3TsBNJB0KVEw0VyyCLzh9W+q1pqTokOXoUBY4HXdC1neuDAeWBLCpOjVgulkbT70g9CigdnrU5VCKFy2+YBIeKJyxf4SfU9voEmLZ4tDGR/PHPKmcNpe2o1+A5EjmO+6YoZz960O78NgtXyex+p+JSUBrOUsjmrZYR0dcXFFYrII4ekG5qcybX29eGwxxaEpDwKPBlxD1zfSfutQ4mnQm8=" Dec 07 17:35:40 volumio-vietv go-librespot[3978]: time="2025-12-07T17:35:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 07 17:35:40 volumio-vietv go-librespot[3978]: time="2025-12-07T17:35:40+07:00" level=debug msg="completed keyexchange" Dec 07 17:35:40 volumio-vietv go-librespot[3978]: time="2025-12-07T17:35:40+07:00" level=debug msg="completed challenge" Dec 07 17:35:40 volumio-vietv go-librespot[3978]: time="2025-12-07T17:35:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:35:40 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:35:40 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:35:41 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:35:41 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:35:43 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:35:43 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 112. Dec 07 17:35:43 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:35:43 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:35:43 volumio-vietv go-librespot[3986]: go-librespot daemon starting... Dec 07 17:35:43 volumio-vietv go-librespot[3986]: time="2025-12-07T17:35:43+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:35:44 volumio-vietv go-librespot[3986]: time="2025-12-07T17:35:44+07:00" level=debug msg="app state loaded" Dec 07 17:35:44 volumio-vietv go-librespot[3986]: time="2025-12-07T17:35:44+07:00" level=debug msg="stored credentials not found" Dec 07 17:35:44 volumio-vietv go-librespot[3986]: time="2025-12-07T17:35:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:35:44 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:35:44 volumio-vietv go-librespot[3986]: time="2025-12-07T17:35:44+07:00" level=debug msg="new websocket client" Dec 07 17:35:44 volumio-vietv volumio[3317]: info: Connection to go-librespot Websocket established Dec 07 17:35:44 volumio-vietv go-librespot[3986]: time="2025-12-07T17:35:44+07: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]" Dec 07 17:35:44 volumio-vietv go-librespot[3986]: time="2025-12-07T17:35:44+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 17:35:44 volumio-vietv go-librespot[3986]: time="2025-12-07T17:35:44+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 17:35:44 volumio-vietv go-librespot[3986]: time="2025-12-07T17:35:44+07:00" level=info msg="zeroconf server listening on port 46205" Dec 07 17:35:44 volumio-vietv go-librespot[3986]: time="2025-12-07T17:35:44+07:00" level=debug msg="obtained new client token: AAB2Ly3dKrXoPJ0/5qDjA3ZoL/uMlFH838n9Z3ypk3HeJV2nlBeFPDuX88jVHykUwQs5ySSKp09OZ6XXJwZcUgFOUmgvVDIcPQsm/Lxz6gzDS+SI4bnwRzQeLE7Mkp1m88OvQWiTXor36CAjXR0GKOJuzGD320vog5xNOYQ/zrfPT8fpQoTI2F3jqriMvC4h8cj7HiqNZFL++cmOUyLjm9pHOW5+SGUTdfXMupQ+WXt5q9YT7hqeV4I=" Dec 07 17:35:44 volumio-vietv go-librespot[3986]: time="2025-12-07T17:35:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 07 17:35:44 volumio-vietv go-librespot[3986]: time="2025-12-07T17:35:44+07:00" level=debug msg="completed keyexchange" Dec 07 17:35:44 volumio-vietv go-librespot[3986]: time="2025-12-07T17:35:44+07:00" level=debug msg="completed challenge" Dec 07 17:35:45 volumio-vietv go-librespot[3986]: time="2025-12-07T17:35:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:35:45 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:35:45 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:35:45 volumio-vietv volumio[3317]: info: Connection to go-librespot Websocket closed Dec 07 17:35:45 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 07 17:35:45 volumio-vietv volumio[3317]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 07 17:35:45 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 07 17:35:45 volumio-vietv volumio[3317]: info: Received Get System Version Dec 07 17:35:45 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 17:35:45 volumio-vietv volumio[3317]: info: Received Get System Info Dec 07 17:35:45 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:35:45 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:35:45 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:35:45 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:45 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:45 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:35:47 volumio-vietv volumio[3317]: info: Getting Spotify volume Dec 07 17:35:47 volumio-vietv volumio[3317]: (node:3317) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:35:47 volumio-vietv volumio[3317]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 07 17:35:47 volumio-vietv volumio[3317]: (node:3317) 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) Dec 07 17:35:47 volumio-vietv volumio[3317]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 07 17:35:47 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:35:47 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:35:47 volumio-vietv volumio[3317]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Dec 07 17:35:48 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:35:48 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:35:48 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:35:48 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 113. Dec 07 17:35:48 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:35:48 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:35:48 volumio-vietv go-librespot[4011]: go-librespot daemon starting... Dec 07 17:35:48 volumio-vietv go-librespot[4011]: time="2025-12-07T17:35:48+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:35:48 volumio-vietv go-librespot[4011]: time="2025-12-07T17:35:48+07:00" level=debug msg="app state loaded" Dec 07 17:35:48 volumio-vietv go-librespot[4011]: time="2025-12-07T17:35:48+07:00" level=debug msg="stored credentials not found" Dec 07 17:35:48 volumio-vietv go-librespot[4011]: time="2025-12-07T17:35:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:35:48 volumio-vietv go-librespot[4011]: time="2025-12-07T17:35:48+07: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]" Dec 07 17:35:48 volumio-vietv go-librespot[4011]: time="2025-12-07T17:35:48+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 17:35:48 volumio-vietv go-librespot[4011]: time="2025-12-07T17:35:48+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 17:35:48 volumio-vietv go-librespot[4011]: time="2025-12-07T17:35:48+07:00" level=info msg="zeroconf server listening on port 45339" Dec 07 17:35:48 volumio-vietv go-librespot[4011]: time="2025-12-07T17:35:48+07:00" level=debug msg="obtained new client token: AAAbvJ4rVrqc2R1v2SHvccDIrHzBT2R6dJ4HCTDI+pE+PWnilrNiox4sWh4v3xYLgZWUziDFw1Ze3ULsC8wmh9X/9npvS3z1eQ9jUYvVzTPBAnaZR9d8NFdlF8AiKS41iqREtX4Rvm4J9NhyN6Sz6+ghmDCaMq7kXnxCV+RkzTmb/Std7h4Wqaan1RrrQm4FOUyuPeaFayDr90yHGB+1WYMhyYk0np+gY/lKFWnumaCy1XsstXhx9cc=" Dec 07 17:35:49 volumio-vietv go-librespot[4011]: time="2025-12-07T17:35:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 07 17:35:49 volumio-vietv go-librespot[4011]: time="2025-12-07T17:35:49+07:00" level=debug msg="completed keyexchange" Dec 07 17:35:49 volumio-vietv go-librespot[4011]: time="2025-12-07T17:35:49+07:00" level=debug msg="completed challenge" Dec 07 17:35:49 volumio-vietv go-librespot[4011]: time="2025-12-07T17:35:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:35:49 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:35:49 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:35:51 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:35:51 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:35:52 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:35:52 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 114. Dec 07 17:35:52 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:35:52 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:35:52 volumio-vietv go-librespot[4019]: go-librespot daemon starting... Dec 07 17:35:52 volumio-vietv go-librespot[4019]: time="2025-12-07T17:35:52+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:35:52 volumio-vietv go-librespot[4019]: time="2025-12-07T17:35:52+07:00" level=debug msg="app state loaded" Dec 07 17:35:52 volumio-vietv go-librespot[4019]: time="2025-12-07T17:35:52+07:00" level=debug msg="stored credentials not found" Dec 07 17:35:52 volumio-vietv go-librespot[4019]: time="2025-12-07T17:35:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:35:52 volumio-vietv go-librespot[4019]: time="2025-12-07T17:35:52+07: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]" Dec 07 17:35:52 volumio-vietv go-librespot[4019]: time="2025-12-07T17:35:52+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 17:35:52 volumio-vietv go-librespot[4019]: time="2025-12-07T17:35:52+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 17:35:52 volumio-vietv go-librespot[4019]: time="2025-12-07T17:35:52+07:00" level=info msg="zeroconf server listening on port 34583" Dec 07 17:35:53 volumio-vietv go-librespot[4019]: time="2025-12-07T17:35:53+07:00" level=debug msg="obtained new client token: AAAxxRWI60i5XhW3rX4TNsUrz8Exs5qd1OuUTLycQsCdetdkYTvmhW2YyPkOzlAEn6sG53fik90OBocV6VTjILr7DLut0qNjOONKd9llSGTuCDiVNJwREiGbn8odgcHsu4Z6HvRbmJ6CL08YCmVsYWNkZ4un7qH+sWSjD4HMfPnKvW7MHTqQ/EpovIum57zTc+LlnxfSwUg8jhmDGVfzUUsQQaex748AWLBVZ0pW4tC8LYtVLA3A" Dec 07 17:35:53 volumio-vietv go-librespot[4019]: time="2025-12-07T17:35:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 07 17:35:53 volumio-vietv go-librespot[4019]: time="2025-12-07T17:35:53+07:00" level=debug msg="completed keyexchange" Dec 07 17:35:53 volumio-vietv go-librespot[4019]: time="2025-12-07T17:35:53+07:00" level=debug msg="completed challenge" Dec 07 17:35:53 volumio-vietv go-librespot[4019]: time="2025-12-07T17:35:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:35:53 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:35:53 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:35:54 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:35:54 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:35:56 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:35:56 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 115. Dec 07 17:35:56 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:35:56 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:35:56 volumio-vietv go-librespot[4028]: go-librespot daemon starting... Dec 07 17:35:56 volumio-vietv go-librespot[4028]: time="2025-12-07T17:35:56+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:35:56 volumio-vietv go-librespot[4028]: time="2025-12-07T17:35:56+07:00" level=debug msg="app state loaded" Dec 07 17:35:56 volumio-vietv go-librespot[4028]: time="2025-12-07T17:35:56+07:00" level=debug msg="stored credentials not found" Dec 07 17:35:56 volumio-vietv go-librespot[4028]: time="2025-12-07T17:35:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:35:57 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:35:57 volumio-vietv go-librespot[4028]: time="2025-12-07T17:35:57+07:00" level=debug msg="new websocket client" Dec 07 17:35:57 volumio-vietv volumio[3317]: info: Connection to go-librespot Websocket established Dec 07 17:35:57 volumio-vietv go-librespot[4028]: time="2025-12-07T17:35:57+07: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]" Dec 07 17:35:57 volumio-vietv go-librespot[4028]: time="2025-12-07T17:35:57+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 17:35:57 volumio-vietv go-librespot[4028]: time="2025-12-07T17:35:57+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 17:35:57 volumio-vietv go-librespot[4028]: time="2025-12-07T17:35:57+07:00" level=info msg="zeroconf server listening on port 42213" Dec 07 17:35:57 volumio-vietv go-librespot[4028]: time="2025-12-07T17:35:57+07:00" level=debug msg="obtained new client token: AACvo5XqrqHV8iruFdnxRclv/PQcDmwrI+G1zGykINlSGEp8neSN8zs0BugGjIa29DFudPagrN1TzhcpIOdVRwtlSe+YQ4UFakYJu2x902bV6Xl8i+BBeZfMAHlq7MtUC+zURp5KsTGKT0TCLlX3Af+EMfVsweerroGwn+AD8RLvX+yd/qxZTYKXKzEf+B68FmDjfmJEfiUjjKiSjcBky5Q9WFGQQo0w+iANNIKKXWjvIz02Ys4BqwM=" Dec 07 17:35:57 volumio-vietv go-librespot[4028]: time="2025-12-07T17:35:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 07 17:35:57 volumio-vietv go-librespot[4028]: time="2025-12-07T17:35:57+07:00" level=debug msg="completed keyexchange" Dec 07 17:35:57 volumio-vietv go-librespot[4028]: time="2025-12-07T17:35:57+07:00" level=debug msg="completed challenge" Dec 07 17:35:57 volumio-vietv go-librespot[4028]: time="2025-12-07T17:35:57+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:35:57 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:35:57 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:35:57 volumio-vietv volumio[3317]: info: Connection to go-librespot Websocket closed Dec 07 17:36:00 volumio-vietv volumio[3317]: info: Getting Spotify volume Dec 07 17:36:00 volumio-vietv volumio[3317]: (node:3317) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:36:00 volumio-vietv volumio[3317]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 07 17:36:00 volumio-vietv volumio[3317]: (node:3317) 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) Dec 07 17:36:00 volumio-vietv volumio[3317]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 07 17:36:00 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:36:00 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:36:00 volumio-vietv volumio[3317]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Dec 07 17:36:00 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:36:00 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:36:00 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:36:00 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 116. Dec 07 17:36:00 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:36:00 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:36:00 volumio-vietv go-librespot[4051]: go-librespot daemon starting... Dec 07 17:36:00 volumio-vietv go-librespot[4051]: time="2025-12-07T17:36:00+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:36:00 volumio-vietv go-librespot[4051]: time="2025-12-07T17:36:00+07:00" level=debug msg="app state loaded" Dec 07 17:36:00 volumio-vietv go-librespot[4051]: time="2025-12-07T17:36:00+07:00" level=debug msg="stored credentials not found" Dec 07 17:36:00 volumio-vietv go-librespot[4051]: time="2025-12-07T17:36:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:36:01 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:36:01 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:36:01 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:36:01 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:36:01 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:36:01 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:36:01 volumio-vietv go-librespot[4051]: time="2025-12-07T17:36:01+07: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]" Dec 07 17:36:01 volumio-vietv go-librespot[4051]: time="2025-12-07T17:36:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 17:36:01 volumio-vietv go-librespot[4051]: time="2025-12-07T17:36:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 17:36:01 volumio-vietv go-librespot[4051]: time="2025-12-07T17:36:01+07:00" level=info msg="zeroconf server listening on port 32881" Dec 07 17:36:01 volumio-vietv go-librespot[4051]: time="2025-12-07T17:36:01+07:00" level=debug msg="obtained new client token: AAA3rc36tlE2wr3DCErvWmQCg35OoIF0gGGkvAJzUHr4fa87yGLOMi7S/LzWNsXatY4jEQswTCNGKYGgFxiV8Al2/JFg4zg1Uqz2q0w+zgIzw7+mmeEnfBjqmzDLjd+h7Cj6vV+epd+qmwNt7/C4fTnMdbk1Os6fSeYQoqNKC/BeNkKTmHkSX09w6DHNjPgIDzf+l8MYJoHchfhFlVuoUnHG6Mze6uCPbFZ+Ef0Tv7UxjDuPfS7l1gA=" Dec 07 17:36:01 volumio-vietv go-librespot[4051]: time="2025-12-07T17:36:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 07 17:36:01 volumio-vietv go-librespot[4051]: time="2025-12-07T17:36:01+07:00" level=debug msg="completed keyexchange" Dec 07 17:36:01 volumio-vietv go-librespot[4051]: time="2025-12-07T17:36:01+07:00" level=debug msg="completed challenge" Dec 07 17:36:02 volumio-vietv go-librespot[4051]: time="2025-12-07T17:36:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:36:02 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:36:02 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:36:03 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:36:03 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:36:05 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:36:05 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 117. Dec 07 17:36:05 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:36:05 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:36:05 volumio-vietv go-librespot[4060]: go-librespot daemon starting... Dec 07 17:36:05 volumio-vietv go-librespot[4060]: time="2025-12-07T17:36:05+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:36:05 volumio-vietv go-librespot[4060]: time="2025-12-07T17:36:05+07:00" level=debug msg="app state loaded" Dec 07 17:36:05 volumio-vietv go-librespot[4060]: time="2025-12-07T17:36:05+07:00" level=debug msg="stored credentials not found" Dec 07 17:36:05 volumio-vietv go-librespot[4060]: time="2025-12-07T17:36:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:36:05 volumio-vietv go-librespot[4060]: time="2025-12-07T17:36:05+07: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]" Dec 07 17:36:05 volumio-vietv go-librespot[4060]: time="2025-12-07T17:36:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 07 17:36:05 volumio-vietv go-librespot[4060]: time="2025-12-07T17:36:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 07 17:36:05 volumio-vietv go-librespot[4060]: time="2025-12-07T17:36:05+07:00" level=info msg="zeroconf server listening on port 44697" Dec 07 17:36:06 volumio-vietv go-librespot[4060]: time="2025-12-07T17:36:06+07:00" level=debug msg="obtained new client token: AABtxfRYw4DKe6otETGDKTHHemLVGRLylja59Ug/03e0/JY0r6LcieVEKqe8GPAdXRdGeo9qXTenxnJa5cDoul/B+PdpSRFRurOMHcmWnz3FjDyzj5nhudefl/1w8+P4rFk+qbjqBx8anpN98EQJwNlXzMI1ekhitQcuQLQHHlqQRAqH/MGlbAV5fzHfi/9xUP7UQw7Hh1CRjpbucwzawZYHVQPkScIkrpOYfhDIBCztAQEt79xtQq8=" Dec 07 17:36:06 volumio-vietv ntpd[654]: Soliciting pool server 45.252.250.189 Dec 07 17:36:06 volumio-vietv go-librespot[4060]: time="2025-12-07T17:36:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 07 17:36:06 volumio-vietv go-librespot[4060]: time="2025-12-07T17:36:06+07:00" level=debug msg="completed keyexchange" Dec 07 17:36:06 volumio-vietv go-librespot[4060]: time="2025-12-07T17:36:06+07:00" level=debug msg="completed challenge" Dec 07 17:36:06 volumio-vietv go-librespot[4060]: time="2025-12-07T17:36:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:36:06 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:36:06 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:36:06 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:36:06 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:36:09 volumio-vietv ntpd[654]: Soliciting pool server 103.221.223.143 Dec 07 17:36:09 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:36:09 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 118. Dec 07 17:36:09 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:36:09 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:36:09 volumio-vietv go-librespot[4085]: go-librespot daemon starting... Dec 07 17:36:09 volumio-vietv go-librespot[4085]: time="2025-12-07T17:36:09+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:36:09 volumio-vietv go-librespot[4085]: time="2025-12-07T17:36:09+07:00" level=debug msg="app state loaded" Dec 07 17:36:09 volumio-vietv go-librespot[4085]: time="2025-12-07T17:36:09+07:00" level=debug msg="stored credentials not found" Dec 07 17:36:09 volumio-vietv go-librespot[4085]: time="2025-12-07T17:36:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:36:09 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:36:09 volumio-vietv go-librespot[4085]: time="2025-12-07T17:36:09+07:00" level=debug msg="new websocket client" Dec 07 17:36:09 volumio-vietv volumio[3317]: info: Connection to go-librespot Websocket established Dec 07 17:36:09 volumio-vietv go-librespot[4085]: time="2025-12-07T17:36:09+07: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]" Dec 07 17:36:09 volumio-vietv go-librespot[4085]: time="2025-12-07T17:36:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 17:36:09 volumio-vietv go-librespot[4085]: time="2025-12-07T17:36:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 17:36:09 volumio-vietv go-librespot[4085]: time="2025-12-07T17:36:09+07:00" level=info msg="zeroconf server listening on port 42559" Dec 07 17:36:10 volumio-vietv go-librespot[4085]: time="2025-12-07T17:36:10+07:00" level=debug msg="obtained new client token: AADtWn3H9v05V+ZEQFpIknogWMUzUVMTpoUB/1IKmvdbPPAExxLMz6a/cZDC/Knmaqly5jn8djgZmQUcoDelyd8ZQ+w52fd7nZX4RCpGN8Rpjc42X1zkKckjABBzhi6ECqpUDr+ZA5Q+zE+gwVnKFgNA9omaKumBLQL7SpBEncAB7i6UE7dCBqf0MjQsqxt9Ue0fCfB6zwMYQZqLt3APpW9A2VxM3ONiAmKxIrRkhq/fl0f0fpEq" Dec 07 17:36:10 volumio-vietv go-librespot[4085]: time="2025-12-07T17:36:10+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Dec 07 17:36:10 volumio-vietv go-librespot[4085]: time="2025-12-07T17:36:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Dec 07 17:36:10 volumio-vietv go-librespot[4085]: time="2025-12-07T17:36:10+07:00" level=debug msg="completed keyexchange" Dec 07 17:36:10 volumio-vietv go-librespot[4085]: time="2025-12-07T17:36:10+07:00" level=debug msg="completed challenge" Dec 07 17:36:10 volumio-vietv go-librespot[4085]: time="2025-12-07T17:36:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:36:10 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:36:10 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:36:10 volumio-vietv volumio[3317]: info: Connection to go-librespot Websocket closed Dec 07 17:36:10 volumio-vietv volumio[3317]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/youtube2/volumio/buster/armhf Dec 07 17:36:12 volumio-vietv ntpd[654]: Soliciting pool server 103.129.126.242 Dec 07 17:36:12 volumio-vietv volumio[3317]: info: Getting Spotify volume Dec 07 17:36:12 volumio-vietv volumio[3317]: (node:3317) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:36:12 volumio-vietv volumio[3317]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 07 17:36:12 volumio-vietv volumio[3317]: (node:3317) 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) Dec 07 17:36:12 volumio-vietv volumio[3317]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 07 17:36:12 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:36:12 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:36:12 volumio-vietv volumio[3317]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Dec 07 17:36:13 volumio-vietv ntpd[654]: Soliciting pool server 160.25.232.6 Dec 07 17:36:13 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:36:13 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:36:13 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:36:13 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 119. Dec 07 17:36:13 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:36:13 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:36:13 volumio-vietv go-librespot[4095]: go-librespot daemon starting... Dec 07 17:36:13 volumio-vietv go-librespot[4095]: time="2025-12-07T17:36:13+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:36:13 volumio-vietv go-librespot[4095]: time="2025-12-07T17:36:13+07:00" level=debug msg="app state loaded" Dec 07 17:36:13 volumio-vietv go-librespot[4095]: time="2025-12-07T17:36:13+07:00" level=debug msg="stored credentials not found" Dec 07 17:36:13 volumio-vietv go-librespot[4095]: time="2025-12-07T17:36:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:36:14 volumio-vietv go-librespot[4095]: time="2025-12-07T17:36:14+07: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]" Dec 07 17:36:14 volumio-vietv go-librespot[4095]: time="2025-12-07T17:36:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 17:36:14 volumio-vietv go-librespot[4095]: time="2025-12-07T17:36:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 17:36:14 volumio-vietv go-librespot[4095]: time="2025-12-07T17:36:14+07:00" level=info msg="zeroconf server listening on port 35179" Dec 07 17:36:15 volumio-vietv go-librespot[4095]: time="2025-12-07T17:36:15+07:00" level=debug msg="obtained new client token: AABtNQgjOp3H2g9O1U6IcSOPMQh28B/x/vlBbi71HuhFiLBEDN4S/D7731f+tNpNH7Qt673FkL1F2DqW7rZi/jUyo0GGbBaTDRu9u5y9KgcR959T78ooA1SopCXsyMa2QoBdGSjIWqB7OWiFA64UCRk8UbBxrNITmGn7Vr/DYgd9T6vBlo4we3mmUXao/42MO6oomtKPbfsGVJ/GUETmLbHt6KaYiioA+MHYVooC9+dIkWCRWeTU" Dec 07 17:36:15 volumio-vietv go-librespot[4095]: time="2025-12-07T17:36:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 07 17:36:16 volumio-vietv volumio[3317]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/youtube2/volumio/buster/armhf Dec 07 17:36:16 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesYouTube2 Dec 07 17:36:16 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 17:36:16 volumio-vietv go-librespot[4095]: time="2025-12-07T17:36:16+07:00" level=debug msg="completed keyexchange" Dec 07 17:36:16 volumio-vietv go-librespot[4095]: time="2025-12-07T17:36:16+07:00" level=debug msg="completed challenge" Dec 07 17:36:16 volumio-vietv go-librespot[4095]: time="2025-12-07T17:36:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:36:16 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:36:16 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:36:16 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:36:16 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:36:19 volumio-vietv systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 07 17:36:19 volumio-vietv systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 120. Dec 07 17:36:19 volumio-vietv systemd[1]: Stopped go-librespot Daemon. Dec 07 17:36:19 volumio-vietv systemd[1]: Started go-librespot Daemon. Dec 07 17:36:22 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:36:22 volumio-vietv volumio[3317]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 17:36:22 volumio-vietv volumio[3317]: info: Check plugin dependencies Dec 07 17:36:31 volumio-vietv volumio-remote-updater[498]: [2025-12-07 17:36:31] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] Dec 07 17:36:36 volumio-vietv volumio-remote-updater[498]: [2025-12-07 17:36:36] [connect] Successful connection Dec 07 17:36:38 volumio-vietv go-librespot[4111]: go-librespot daemon starting... Dec 07 17:36:48 volumio-vietv volumio-remote-updater[498]: [2025-12-07 17:36:48] [connect] Successful connection Dec 07 17:36:55 volumio-vietv go-librespot[4111]: time="2025-12-07T17:36:55+07:00" level=info msg="running go-librespot 0.4.0" Dec 07 17:36:55 volumio-vietv go-librespot[4111]: time="2025-12-07T17:36:55+07:00" level=debug msg="app state loaded" Dec 07 17:36:55 volumio-vietv go-librespot[4111]: time="2025-12-07T17:36:55+07:00" level=debug msg="stored credentials not found" Dec 07 17:36:55 volumio-vietv go-librespot[4111]: time="2025-12-07T17:36:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 17:36:55 volumio-vietv volumio[3317]: info: Rename folder Dec 07 17:36:55 volumio-vietv volumio[3317]: info: Initializing connection to go-librespot Websocket Dec 07 17:36:55 volumio-vietv volumio[3317]: info: Move to category Dec 07 17:36:55 volumio-vietv volumio[3317]: info: Folder /tmp/downloaded_plugin.zip removed Dec 07 17:36:55 volumio-vietv go-librespot[4111]: time="2025-12-07T17:36:55+07:00" level=debug msg="new websocket client" Dec 07 17:36:55 volumio-vietv volumio[3317]: verbose: New Socket.io Connection to 192.168.1.9 from 192.168.1.23 UA: Mozilla/5.0 (Linux; Android 16; SM-S928B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.171 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Dec 07 17:36:55 volumio-vietv volumio[3317]: verbose: New Socket.io Connection to 192.168.1.9 from 192.168.1.23 UA: Mozilla/5.0 (Linux; Android 16; SM-S928B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.171 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Dec 07 17:36:55 volumio-vietv volumio[3317]: verbose: New Socket.io Connection to 192.168.1.9 from 192.168.1.23 UA: Mozilla/5.0 (Linux; Android 16; SM-S928B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.171 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:36:55 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:36:55 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:36:55 volumio-vietv volumio[3317]: info: Connection to go-librespot Websocket established Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetVisibleSources Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 07 17:36:55 volumio-vietv volumio[3317]: info: Received Get System Info Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 17:36:55 volumio-vietv volumio[3317]: info: Discovery: Getting this device information Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CoreCommandRouter::volumioGetState Dec 07 17:36:55 volumio-vietv volumio[3317]: info: CorePlayQueue::getTrack 0 Dec 07 17:36:55 volumio-vietv volumio[3317]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 17:36:55 volumio-vietv volumio[3317]: TypeError: Cannot read property 'plugin_type' of undefined Dec 07 17:36:55 volumio-vietv volumio[3317]: at PluginManager.getInstalledPlugins (/volumio/app/pluginmanager.js:1644:56) Dec 07 17:36:55 volumio-vietv volumio[3317]: at CoreCommandRouter.getInstalledPlugins (/volumio/app/index.js:1540:29) Dec 07 17:36:55 volumio-vietv volumio[3317]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1353:45) Dec 07 17:36:55 volumio-vietv volumio[3317]: at Socket.emit (events.js:315:20) Dec 07 17:36:55 volumio-vietv volumio[3317]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Dec 07 17:36:55 volumio-vietv volumio[3317]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Dec 07 17:36:55 volumio-vietv volumio[3317]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 17:36:55 volumio-vietv go-librespot[4111]: time="2025-12-07T17:36:55+07: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]" Dec 07 17:36:55 volumio-vietv go-librespot[4111]: time="2025-12-07T17:36:55+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 07 17:36:55 volumio-vietv go-librespot[4111]: time="2025-12-07T17:36:55+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 07 17:36:55 volumio-vietv go-librespot[4111]: time="2025-12-07T17:36:55+07:00" level=info msg="zeroconf server listening on port 42369" Dec 07 17:36:56 volumio-vietv go-librespot[4111]: time="2025-12-07T17:36:56+07:00" level=debug msg="obtained new client token: AAC6zcKJMmjwY1CO+ciW+UWKCcitXKu9z9fcpMZeSR2HPT+c6KYCFMAMRx7FRx3uFniKfTSpydHN2LQkceO436VQzxDJeiV64GNVs3kNrf2tjiCjg6Qm+21SAShDQHju7KEwRvJgvBJEerAsinwD53ciQd2G1N4sIrhvzCy8vvr/UzwhipZhbV+AlsDvezU6euBrAPYC9FPCxDrD2pWTi0HuXr6ppx4Sj2dVHJdGqMpBynimCqugVDo=" Dec 07 17:36:56 volumio-vietv go-librespot[4111]: time="2025-12-07T17:36:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 07 17:36:56 volumio-vietv go-librespot[4111]: time="2025-12-07T17:36:56+07:00" level=debug msg="completed keyexchange" Dec 07 17:36:56 volumio-vietv go-librespot[4111]: time="2025-12-07T17:36:56+07:00" level=debug msg="completed challenge" Dec 07 17:36:56 volumio-vietv go-librespot[4111]: time="2025-12-07T17:36:56+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 17:36:56 volumio-vietv systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 17:36:56 volumio-vietv systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 17:36:56 volumio-vietv sudo[4185]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-07 17:35 Dec 07 17:36:56 volumio-vietv sudo[4185]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cc50ad4a2058d01de272214eb33827883bd2b7d8" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="502750e5d54ecf269d25125b622bfabc030fb553" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 12 Nov 2025 06:58:02 PM CET" VOLUMIO_VERSION="3.874" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4ae6504ed6f22e44c01a6e93b16badbd"