-- Logs begin at Tue 2025-05-27 21:31:08 +07, end at Tue 2025-05-27 21:34:05 +07. -- May 27 21:33:09 nhutnhut go-librespot[2026]: time="2025-05-27T21:33:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 27 21:33:09 nhutnhut systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 27 21:33:09 nhutnhut systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 27 21:33:12 nhutnhut systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 27 21:33:12 nhutnhut systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. May 27 21:33:12 nhutnhut systemd[1]: Stopped go-librespot Daemon. May 27 21:33:12 nhutnhut systemd[1]: Started go-librespot Daemon. May 27 21:33:12 nhutnhut go-librespot[2114]: go-librespot daemon starting... May 27 21:33:12 nhutnhut go-librespot[2114]: time="2025-05-27T21:33:12+07:00" level=info msg="running go-librespot 0.2.0" May 27 21:33:12 nhutnhut go-librespot[2114]: time="2025-05-27T21:33:12+07:00" level=debug msg="app state loaded" May 27 21:33:12 nhutnhut go-librespot[2114]: time="2025-05-27T21:33:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" May 27 21:33:13 nhutnhut ntpd[1388]: error resolving pool 1.debian.pool.ntp.org: System error (-11) May 27 21:33:15 nhutnhut volumio-time-update[638]: volumio-time-update-util: Date not found in response May 27 21:33:15 nhutnhut volumio-time-update[638]: volumio-time-update-util: Retrying in 5 seconds... May 27 21:33:20 nhutnhut volumio-time-update[638]: volumio-time-update-util: Fetching time from Volumio... May 27 21:33:30 nhutnhut go-librespot[2114]: time="2025-05-27T21:33:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 27 21:33:30 nhutnhut systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 27 21:33:30 nhutnhut systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 27 21:33:31 nhutnhut ntpd[1388]: error resolving pool 2.debian.pool.ntp.org: System error (-11) May 27 21:33:32 nhutnhut volumio[921]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 May 27 21:33:32 nhutnhut volumio[921]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 May 27 21:33:33 nhutnhut systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 27 21:33:33 nhutnhut systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. May 27 21:33:33 nhutnhut systemd[1]: Stopped go-librespot Daemon. May 27 21:33:33 nhutnhut systemd[1]: Started go-librespot Daemon. May 27 21:33:33 nhutnhut go-librespot[2160]: go-librespot daemon starting... May 27 21:33:33 nhutnhut go-librespot[2160]: time="2025-05-27T21:33:33+07:00" level=info msg="running go-librespot 0.2.0" May 27 21:33:33 nhutnhut go-librespot[2160]: time="2025-05-27T21:33:33+07:00" level=debug msg="app state loaded" May 27 21:33:33 nhutnhut go-librespot[2160]: time="2025-05-27T21:33:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" May 27 21:33:38 nhutnhut volumio-time-update[638]: volumio-time-update-util: Date not found in response May 27 21:33:38 nhutnhut volumio-time-update[638]: volumio-time-update-util: Retrying in 5 seconds... May 27 21:33:43 nhutnhut volumio-time-update[638]: volumio-time-update-util: Fetching time from Volumio... May 27 21:33:49 nhutnhut ntpd[1388]: error resolving pool 3.debian.pool.ntp.org: System error (-11) May 27 21:33:50 nhutnhut go-librespot[2160]: time="2025-05-27T21:33:50+07:00" level=debug msg="new websocket client" May 27 21:33:50 nhutnhut volumio[921]: info: Connection to go-librespot Websocket established May 27 21:33:51 nhutnhut go-librespot[2160]: time="2025-05-27T21:33:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 27 21:33:51 nhutnhut systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 27 21:33:51 nhutnhut systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 27 21:33:51 nhutnhut volumio[921]: info: Connection to go-librespot Websocket closed May 27 21:33:53 nhutnhut volumio[921]: info: Getting Spotify volume May 27 21:33:53 nhutnhut volumio[921]: (node:921) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 27 21:33:53 nhutnhut volumio[921]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 27 21:33:53 nhutnhut volumio[921]: (node:921) 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) May 27 21:33:54 nhutnhut volumio[921]: info: Initializing connection to go-librespot Websocket May 27 21:33:55 nhutnhut systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 27 21:33:55 nhutnhut systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. May 27 21:33:55 nhutnhut systemd[1]: Stopped go-librespot Daemon. May 27 21:33:55 nhutnhut systemd[1]: Started go-librespot Daemon. May 27 21:33:55 nhutnhut go-librespot[2204]: go-librespot daemon starting... May 27 21:33:55 nhutnhut go-librespot[2204]: time="2025-05-27T21:33:55+07:00" level=info msg="running go-librespot 0.2.0" May 27 21:33:55 nhutnhut go-librespot[2204]: time="2025-05-27T21:33:55+07:00" level=debug msg="app state loaded" May 27 21:33:55 nhutnhut go-librespot[2204]: time="2025-05-27T21:33:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" May 27 21:33:58 nhutnhut ntpd[1388]: Soliciting pool server 103.199.19.135 May 27 21:33:58 nhutnhut ntpd[1388]: Soliciting pool server 27.71.27.209 May 27 21:33:59 nhutnhut ntpd[1388]: Soliciting pool server 103.70.115.65 May 27 21:33:59 nhutnhut ntpd[1388]: Soliciting pool server 115.165.161.155 May 27 21:33:59 nhutnhut volumio[921]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 May 27 21:33:59 nhutnhut volumio[921]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 May 27 21:33:59 nhutnhut volumio[921]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 May 27 21:33:59 nhutnhut volumio[921]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 May 27 21:33:59 nhutnhut volumio[921]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 27 21:33:59 nhutnhut volumio[921]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 May 27 21:33:59 nhutnhut volumio[921]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 May 27 21:33:59 nhutnhut volumio[921]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 May 27 21:33:59 nhutnhut go-librespot[2204]: time="2025-05-27T21:33:59+07:00" level=debug msg="new websocket client" May 27 21:33:59 nhutnhut volumio[921]: info: Connection to go-librespot Websocket established May 27 21:33:59 nhutnhut volumio[921]: info: CoreCommandRouter::volumioGetState May 27 21:33:59 nhutnhut volumio[921]: info: CorePlayQueue::getTrack 0 May 27 21:33:59 nhutnhut volumio[921]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 May 27 21:33:59 nhutnhut volumio[921]: SPOTIFY: SPOTIFY VOLUME undefined May 27 21:33:59 nhutnhut volumio[921]: SPOTIFY: VOLUMIO VOLUME 65 May 27 21:33:59 nhutnhut volumio[921]: info: Aligning Spotify Volume to Volumio Volume May 27 21:33:59 nhutnhut volumio[921]: info: CoreCommandRouter::volumioGetState May 27 21:33:59 nhutnhut volumio[921]: info: CorePlayQueue::getTrack 0 May 27 21:33:59 nhutnhut volumio[921]: info: Setting Spotify Volume from Volumio: 65 May 27 21:33:59 nhutnhut ntpd[1388]: Soliciting pool server 115.165.161.155 May 27 21:33:59 nhutnhut ntpd[1388]: Soliciting pool server 115.165.161.155 May 27 21:33:59 nhutnhut ntpd[1388]: Soliciting pool server 115.165.161.155 May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso May 27 21:34:00 nhutnhut volumio[921]: info: Adding plugin bluetooth to MyMusic Plugins May 27 21:34:00 nhutnhut volumio[921]: info: Adding plugin multiroom to MyMusic Plugins May 27 21:34:00 nhutnhut volumio[921]: info: Adding plugin metavolumio to MyMusic Plugins May 27 21:34:00 nhutnhut volumio[921]: info: Adding plugin cd_controller to MyMusic Plugins May 27 21:34:00 nhutnhut volumio[921]: info: Adding plugin qobuzconnect to MyMusic Plugins May 27 21:34:00 nhutnhut volumio[921]: info: Adding plugin smart_inputs to MyMusic Plugins May 27 21:34:00 nhutnhut volumio[921]: info: Adding plugin tidalconnect to MyMusic Plugins May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio May 27 21:34:00 nhutnhut volumio[921]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 21:34:00 nhutnhut volumio[921]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 21:34:00 nhutnhut volumio[921]: info: Starting MyVolumio Remote Streaming Endpoints May 27 21:34:00 nhutnhut volumio[921]: info: MyVolumio login type: Token May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started May 27 21:34:00 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... May 27 21:34:01 nhutnhut volumio[921]: info: Starting Streaming Service Transparent Proxy May 27 21:34:01 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded May 27 21:34:01 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services May 27 21:34:01 nhutnhut volumio[921]: info: Streaming services startup May 27 21:34:01 nhutnhut volumio[921]: info: Starting Streaming Daemon May 27 21:34:01 nhutnhut sudo[2234]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 27 21:34:01 nhutnhut sudo[2234]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 21:34:01 nhutnhut sudo[2234]: pam_unix(sudo:session): session closed for user root May 27 21:34:01 nhutnhut volumio[921]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started May 27 21:34:01 nhutnhut volumio-time-update[638]: volumio-time-update-util: Date not found in response May 27 21:34:01 nhutnhut volumio-time-update[638]: volumio-time-update-util: Retrying in 5 seconds... May 27 21:34:01 nhutnhut volumio[921]: SPOTIFY: SETTING SPOTIFY VOLUME 65 May 27 21:34:01 nhutnhut volumio[921]: info: Sending Spotify command with payload to local API: /player/volume May 27 21:34:01 nhutnhut volumio[921]: error: Cannot start Volumio Streaming Daemon May 27 21:34:01 nhutnhut volumio[921]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 27 21:34:01 nhutnhut volumio[921]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 27 21:34:01 nhutnhut volumio[921]: error: Failed to send command to Spotify local API: /player/volume: Error: Bad Request May 27 21:34:02 nhutnhut volumio[921]: error: MyVolumio Custom Token format not valid, refreshing it May 27 21:34:02 nhutnhut volumio[921]: STREAMING PROXY: Starting server on port 3245 May 27 21:34:02 nhutnhut volumio[921]: Node JS runtime: 14 May 27 21:34:02 nhutnhut volumio[921]: info: Getting Spotify volume May 27 21:34:02 nhutnhut volumio[921]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 May 27 21:34:02 nhutnhut volumio[921]: info: CoreCommandRouter::volumioGetState May 27 21:34:02 nhutnhut volumio[921]: info: CorePlayQueue::getTrack 0 May 27 21:34:02 nhutnhut volumio[921]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 May 27 21:34:03 nhutnhut volumio[921]: info: MyVolumio login type: Token May 27 21:34:04 nhutnhut volumio[921]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN May 27 21:34:04 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:04+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]" May 27 21:34:04 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:04+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]" May 27 21:34:04 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:04+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]" May 27 21:34:04 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:04+07:00" level=info msg="zeroconf server listening on port 35149" May 27 21:34:04 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:04+07:00" level=debug msg="obtained new client token: AADTuLpr/lsbnTfjFq4qRyv/C2bCpIaJ1UOzdJZVLCwVtvH8cI9r8hhiHJ+6zFsQucKuJb5+EZ2zHXzboc/WYq0QbwfhjyJ8ZTVYKwSup/RKshQdrSDwdjPCCCBH39O7nFmM+5cMXblJ0MV/XJHQTj15ZT2gU9nVP8YTNlMLOFMjcdaGNOekC1zavkTLGddK861kR6hkmqC34K5ZwNiHdF9eHt3FhKAZAuKxC6qm/5ZWZ2UqgMSlXT0=" May 27 21:34:04 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" May 27 21:34:04 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:04+07:00" level=debug msg="completed keyexchange" May 27 21:34:04 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:04+07:00" level=debug msg="completed challenge" May 27 21:34:04 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:04+07:00" level=info msg="authenticated AP as 312yxk6ks3rffrmt3jx7ht4z4eym" May 27 21:34:04 nhutnhut volumio[921]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 27 21:34:04 nhutnhut volumio[921]: info: Received Get System Info May 27 21:34:04 nhutnhut volumio[921]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 27 21:34:04 nhutnhut volumio[921]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 27 21:34:04 nhutnhut volumio[921]: info: Discovery: Getting this device information May 27 21:34:04 nhutnhut volumio[921]: info: CoreCommandRouter::volumioGetState May 27 21:34:04 nhutnhut volumio[921]: info: CorePlayQueue::getTrack 0 May 27 21:34:04 nhutnhut volumio[921]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 27 21:34:04 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:04+07:00" level=info msg="authenticated Login5 as 312yxk6ks3rffrmt3jx7ht4z4eym" May 27 21:34:04 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:04+07:00" level=debug msg="initializing zeroconf session, username: 312yxk6ks3rffrmt3jx7ht4z4eym" May 27 21:34:05 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:05+07:00" level=debug msg="dealer connection opened" May 27 21:34:05 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:05+07:00" level=trace msg="starting accesspoint recv loop" May 27 21:34:05 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:05+07:00" level=trace msg="starting dealer recv loop" May 27 21:34:05 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:05+07:00" level=trace msg="received accesspoint ping" May 27 21:34:05 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:05+07:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 27 21:34:05 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:05+07:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 27 21:34:05 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:05+07:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 27 21:34:05 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:05+07:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 27 21:34:05 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:05+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 27 21:34:05 nhutnhut volumio[921]: info: Spotify volume: 100 May 27 21:34:05 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:05+07:00" level=debug msg="received connection id: NTBjMzYyNDYtYzdmYS00MWY3LThhMDctNzM5OTUyZDZjMWQwK2RlYWxlcit0Y3A6Ly8wYWM5NDk5YS5pcC5nYWUyLnNwb3RpZnkubmV0OjU3MDArMDA2RkFBNTVFRkI0RDU4QTIyNjI5RDEyMzA3NTlFQzAyQkJDNDIwN0NGMjM0QjgxMzBFNDlDNTA5RkQyQTQ1Mg==" May 27 21:34:05 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:05+07:00" level=trace msg="received accesspoint pong ack" May 27 21:34:05 nhutnhut go-librespot[2204]: time="2025-05-27T21:34:05+07:00" level=debug msg="put connect state because NEW_DEVICE" May 27 21:34:05 nhutnhut volumio[921]: info: MyVolumio token set successfully May 27 21:34:05 nhutnhut volumio[921]: info: MYVOLUMIO: Adding device May 27 21:34:05 nhutnhut volumio[921]: info: MYVOLUMIO: Evaluating Server May 27 21:34:05 nhutnhut ntpd[1388]: receive: Unexpected origin timestamp 0xebe04bdd.b9a2fa96 does not match aorg 0000000000.00000000 from server@27.71.27.209 xmt 0xebe04bdd.5585079d May 27 21:34:05 nhutnhut volumio[921]: info: MyVolumio status changed May 27 21:34:05 nhutnhut volumio[921]: info: Streaming services startup May 27 21:34:05 nhutnhut volumio[921]: info: Starting Streaming Daemon May 27 21:34:05 nhutnhut volumio[921]: info: Removing browser output: myVolumio user plan is not superstar May 27 21:34:05 nhutnhut volumio[921]: info: Removing audio output: May 27 21:34:05 nhutnhut volumio[921]: info: Stoppping Tunnel 1 May 27 21:34:05 nhutnhut sudo[2274]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 27 21:34:05 nhutnhut sudo[2274]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 21:34:05 nhutnhut sudo[2274]: pam_unix(sudo:session): session closed for user root May 27 21:34:05 nhutnhut volumio[921]: error: Cannot start Volumio Streaming Daemon May 27 21:34:05 nhutnhut volumio[921]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 27 21:34:05 nhutnhut volumio[921]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 27 21:34:05 nhutnhut sudo[2277]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service May 27 21:34:05 nhutnhut sudo[2277]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 21:34:05 nhutnhut sudo[2277]: pam_unix(sudo:session): session closed for user root May 27 21:34:05 nhutnhut volumio[921]: info: Remote SSH Stopped May 27 21:34:05 nhutnhut volumio[921]: error: Failed to ping endpoint eu2.myvolumio.org : unknown error May 27 21:34:05 nhutnhut volumio[921]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 27 21:34:05 nhutnhut volumio[921]: Error: Unable to resolve or reject the same promise twice May 27 21:34:05 nhutnhut volumio[921]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) May 27 21:34:05 nhutnhut volumio[921]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32086) May 27 21:34:05 nhutnhut volumio[921]: at Socket.emit (events.js:412:35) May 27 21:34:05 nhutnhut volumio[921]: at endReadableNT (internal/streams/readable.js:1333:12) May 27 21:34:05 nhutnhut volumio[921]: at processTicksAndRejections (internal/process/task_queues.js:82:21) May 27 21:34:05 nhutnhut volumio[921]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 27 21:34:05 nhutnhut sudo[2288]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-27 21:33 May 27 21:34:05 nhutnhut sudo[2288]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:50:12 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="39b0f8c200b2dcadf117e189b4b3632d"