-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Mon 2025-12-22 22:25:44 CET. -- Dec 22 22:24:08 tycshd volumio[755]: info: CoreCommandRouter::volumioGetState Dec 22 22:24:09 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 22 22:24:09 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 22 22:24:17 tycshd volumio-time-update[479]: volumio-time-update-util: Date not found in response Dec 22 22:24:17 tycshd volumio-time-update[479]: volumio-time-update-util: Retrying in 5 seconds... Dec 22 22:24:18 tycshd volumio[755]: info: CoreCommandRouter::volumioGetState Dec 22 22:24:21 tycshd go-librespot[1753]: time="2025-12-22T22:24:21+01: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\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)" Dec 22 22:24:21 tycshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 22:24:21 tycshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 22:24:22 tycshd volumio-time-update[479]: volumio-time-update-util: Fetching time from Volumio... Dec 22 22:24:24 tycshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 22 22:24:24 tycshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 22 22:24:24 tycshd systemd[1]: Stopped go-librespot Daemon. Dec 22 22:24:24 tycshd systemd[1]: Started go-librespot Daemon. Dec 22 22:24:24 tycshd go-librespot[1813]: go-librespot daemon starting... Dec 22 22:24:24 tycshd go-librespot[1813]: time="2025-12-22T22:24:24+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 22:24:24 tycshd go-librespot[1813]: time="2025-12-22T22:24:24+01:00" level=debug msg="app state loaded" Dec 22 22:24:24 tycshd go-librespot[1813]: time="2025-12-22T22:24:24+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 22:24:28 tycshd volumio[755]: info: CoreCommandRouter::volumioGetState Dec 22 22:24:38 tycshd volumio[755]: info: CoreCommandRouter::volumioGetState Dec 22 22:24:48 tycshd volumio[755]: info: CoreCommandRouter::volumioGetState Dec 22 22:24:54 tycshd go-librespot[1813]: time="2025-12-22T22:24:54+01: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\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)" Dec 22 22:24:54 tycshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 22:24:54 tycshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 22:24:58 tycshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 22 22:24:58 tycshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Dec 22 22:24:58 tycshd systemd[1]: Stopped go-librespot Daemon. Dec 22 22:24:58 tycshd systemd[1]: Started go-librespot Daemon. Dec 22 22:24:58 tycshd go-librespot[1908]: go-librespot daemon starting... Dec 22 22:24:58 tycshd go-librespot[1908]: time="2025-12-22T22:24:58+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 22:24:58 tycshd go-librespot[1908]: time="2025-12-22T22:24:58+01:00" level=debug msg="app state loaded" Dec 22 22:24:58 tycshd go-librespot[1908]: time="2025-12-22T22:24:58+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 22:24:58 tycshd volumio-time-update[479]: volumio-time-update-util: Date not found in response Dec 22 22:24:58 tycshd volumio-time-update[479]: volumio-time-update-util: Retrying in 5 seconds... Dec 22 22:24:58 tycshd volumio[755]: info: CoreCommandRouter::volumioGetState Dec 22 22:25:03 tycshd volumio-time-update[479]: volumio-time-update-util: Fetching time from Volumio... Dec 22 22:25:08 tycshd volumio[755]: info: CoreCommandRouter::volumioGetState Dec 22 22:25:18 tycshd volumio[755]: info: CoreCommandRouter::volumioGetState Dec 22 22:25:28 tycshd go-librespot[1908]: time="2025-12-22T22:25:28+01: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\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)" Dec 22 22:25:28 tycshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 22:25:28 tycshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 22:25:28 tycshd volumio[755]: info: CoreCommandRouter::volumioGetState Dec 22 22:25:31 tycshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 22 22:25:31 tycshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 22 22:25:31 tycshd systemd[1]: Stopped go-librespot Daemon. Dec 22 22:25:31 tycshd systemd[1]: Started go-librespot Daemon. Dec 22 22:25:31 tycshd go-librespot[2022]: go-librespot daemon starting... Dec 22 22:25:31 tycshd go-librespot[2022]: time="2025-12-22T22:25:31+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 22:25:31 tycshd go-librespot[2022]: time="2025-12-22T22:25:31+01:00" level=debug msg="app state loaded" Dec 22 22:25:31 tycshd go-librespot[2022]: time="2025-12-22T22:25:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 22:25:38 tycshd volumio[755]: info: CoreCommandRouter::volumioGetState Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 22 22:25:39 tycshd volumio-time-update[479]: volumio-time-update-util: Date not found in response Dec 22 22:25:39 tycshd volumio-time-update[479]: volumio-time-update-util: Retrying in 5 seconds... Dec 22 22:25:39 tycshd volumio[755]: 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 22 22:25:39 tycshd volumio[755]: 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 22 22:25:39 tycshd volumio[755]: 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 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Dec 22 22:25:39 tycshd volumio[755]: info: MRS: Found cast device: SHIELD-Android-TV-233c875739c080b993ec1b2f5eacb137 Dec 22 22:25:39 tycshd volumio[755]: info: MRS: Found cast device: SHIELD-Android-TV-c6dde03b445cc32d88335767d45226ca Dec 22 22:25:39 tycshd volumio[755]: info: Discovery: adding 120ce0ca-4893-4538-b389-bf03232d172c Dec 22 22:25:39 tycshd volumio[755]: info: Discovery: Found device TycSHD Dec 22 22:25:39 tycshd volumio[755]: info: CoreCommandRouter::volumioGetState Dec 22 22:25:39 tycshd go-librespot[2022]: time="2025-12-22T22:25:39+01:00" level=debug msg="new websocket client" Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Dec 22 22:25:39 tycshd volumio[755]: info: Connection to go-librespot Websocket established Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 16 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 17 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 18 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 19 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 20 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 21 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 22 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 23 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 24 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 25 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 26 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 27 Dec 22 22:25:39 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 28 Dec 22 22:25:39 tycshd volumio[755]: info: CoreCommandRouter::volumioGetState Dec 22 22:25:39 tycshd volumio[755]: info: CoreCommandRouter::volumioGetState Dec 22 22:25:39 tycshd volumio[755]: SPOTIFY: RECEIVED VOLUMIO VOLUME 62 Dec 22 22:25:39 tycshd volumio[755]: SPOTIFY: SPOTIFY VOLUME undefined Dec 22 22:25:39 tycshd volumio[755]: SPOTIFY: VOLUMIO VOLUME 62 Dec 22 22:25:39 tycshd volumio[755]: info: Aligning Spotify Volume to Volumio Volume Dec 22 22:25:39 tycshd volumio[755]: info: CoreCommandRouter::volumioGetState Dec 22 22:25:39 tycshd volumio[755]: info: Setting Spotify Volume from Volumio: 62 Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 22 22:25:40 tycshd volumio[755]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 22 22:25:40 tycshd go-librespot[2022]: time="2025-12-22T22:25:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 22 22:25:40 tycshd go-librespot[2022]: time="2025-12-22T22:25:40+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 22 22:25:40 tycshd go-librespot[2022]: time="2025-12-22T22:25:40+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 22 22:25:40 tycshd go-librespot[2022]: time="2025-12-22T22:25:40+01:00" level=info msg="zeroconf server listening on port 33259" Dec 22 22:25:40 tycshd go-librespot[2022]: time="2025-12-22T22:25:40+01:00" level=debug msg="obtained new client token: AACWgKr6A+Typ2n8+oHFl2Zr93hiUFNlsuaZOzGPVrXin+I1lAtkFncIaCihWTmXZKdZzTmpRGHRwOjMMpTwYGG3/YDwt/sXjBftz2wk/sGGhUgADqks+ck+t/1gHP7/4Kf0fxTrhawM9KZvgUqLHsS0Hk0oRNosMlE+wyjmVEaJHPXbH9po5XtJ1/d1ZuMDqRPuHGhUWqLfsY20a47UVGMgdOg7c/GM/ppCJq3POIiEZrfRpR88NSYKsQ==" Dec 22 22:25:40 tycshd go-librespot[2022]: time="2025-12-22T22:25:40+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Dec 22 22:25:40 tycshd go-librespot[2022]: time="2025-12-22T22:25:40+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Dec 22 22:25:40 tycshd go-librespot[2022]: time="2025-12-22T22:25:40+01:00" level=debug msg="completed keyexchange" Dec 22 22:25:40 tycshd go-librespot[2022]: time="2025-12-22T22:25:40+01:00" level=debug msg="completed challenge" Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=info msg="authenticated AP" username="ty**rc" Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=info msg="authenticated Login5" username="ty**rc" Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=debug msg="initializing zeroconf session" username="ty**rc" Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=debug msg="dealer connection opened" Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=trace msg="starting accesspoint recv loop" Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=trace msg="starting dealer recv loop" Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=trace msg="received accesspoint ping" Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=debug msg="received connection id: OTg0OTMzZTItYTZj...NEUxQUU4NUMwRg==" Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=trace msg="received accesspoint pong ack" Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=debug msg="update volume requested to 40631/65535" Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=trace msg="emitting websocket event: volume" Dec 22 22:25:41 tycshd volumio[755]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 22 22:25:41 tycshd volumio[755]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 22 22:25:41 tycshd volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 22:25:41 tycshd volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 22:25:41 tycshd volumio[755]: info: Starting MyVolumio Remote Streaming Endpoints Dec 22 22:25:41 tycshd volumio[755]: info: MyVolumio login type: Token Dec 22 22:25:41 tycshd volumio[755]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 22 22:25:41 tycshd volumio[755]: error: [MyVolumio PluginManager] Could not read package.json file: Error: /myvolumio/plugins/music_service/streaming_services//package.json: ENOENT: no such file or directory, open '/myvolumio/plugins/music_service/streaming_services//package.json' Dec 22 22:25:41 tycshd volumio[755]: SPOTIFY: SETTING SPOTIFY VOLUME 62 Dec 22 22:25:41 tycshd volumio[755]: info: Sending Spotify command with payload to local API: /player/volume Dec 22 22:25:41 tycshd volumio[755]: SPOTIFY: received: {"type":"volume","data":{"value":62,"max":100}} Dec 22 22:25:41 tycshd volumio[755]: SPOTIFY: RECEIVED SPOTIFY VOLUME 62 Dec 22 22:25:41 tycshd go-librespot[2022]: time="2025-12-22T22:25:41+01:00" level=debug msg="update volume requested to 40631/65535" Dec 22 22:25:42 tycshd go-librespot[2022]: time="2025-12-22T22:25:42+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 22 22:25:42 tycshd go-librespot[2022]: time="2025-12-22T22:25:42+01:00" level=trace msg="emitting websocket event: volume" Dec 22 22:25:42 tycshd volumio[755]: SPOTIFY: received: {"type":"volume","data":{"value":62,"max":100}} Dec 22 22:25:42 tycshd volumio[755]: SPOTIFY: RECEIVED SPOTIFY VOLUME 62 Dec 22 22:25:42 tycshd volumio[755]: error: MyVolumio Custom Token format not valid, refreshing it Dec 22 22:25:42 tycshd volumio[755]: info: Getting Spotify volume Dec 22 22:25:42 tycshd volumio[755]: info: Spotify volume: 62 Dec 22 22:25:42 tycshd volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 29 Dec 22 22:25:42 tycshd volumio[755]: info: CoreCommandRouter::volumioGetState Dec 22 22:25:42 tycshd volumio[755]: SPOTIFY: RECEIVED VOLUMIO VOLUME 62 Dec 22 22:25:42 tycshd volumio[755]: info: MyVolumio login type: Token Dec 22 22:25:43 tycshd volumio[755]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 22 22:25:43 tycshd volumio[755]: info: MyVolumio token set successfully Dec 22 22:25:43 tycshd volumio[755]: info: MYVOLUMIO: Adding device Dec 22 22:25:43 tycshd volumio[755]: info: MYVOLUMIO: Evaluating Server Dec 22 22:25:44 tycshd volumio-time-update[479]: volumio-time-update-util: Fetching time from Volumio... Dec 22 22:25:44 tycshd volumio-time-update[479]: volumio-time-update-util: Setting system time to: 2025-12-22 22:25:44 Dec 22 22:25:44 tycshd sudo[2075]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-12-22 22:25:44 Dec 22 22:25:44 tycshd sudo[2075]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 22:25:44 tycshd dbus-daemon[476]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.16' (uid=0 pid=2077 comm="timedatectl set-time 2025-12-22 22:25:44 ") Dec 22 22:25:44 tycshd systemd[1]: Starting Time & Date Service... Dec 22 22:25:44 tycshd volumio[755]: info: MyVolumio Plan changed: superstar Dec 22 22:25:44 tycshd volumio[755]: info: [MyVolumio PluginManager] Subscribed plan changed to superstar Dec 22 22:25:44 tycshd volumio[755]: info: Adding audio output: Dec 22 22:25:44 tycshd volumio[755]: info: MYVOLUMIO: Adding device Dec 22 22:25:44 tycshd volumio[755]: info: MYVOLUMIO: Evaluating Server Dec 22 22:25:44 tycshd volumio[755]: info: Remote config written successfully Dec 22 22:25:44 tycshd volumio[755]: info: Starting Tunnel 1 Dec 22 22:25:44 tycshd volumio[755]: info: Starting Tunnel Connection Checker Dec 22 22:25:44 tycshd dbus-daemon[476]: [system] Successfully activated service 'org.freedesktop.timedate1' Dec 22 22:25:44 tycshd systemd[1]: Started Time & Date Service. Dec 22 22:25:44 tycshd systemd-timedated[2081]: Changed local time to Mon Dec 22 22:25:44 2025 Dec 22 22:25:44 tycshd systemd[1]: Started Volumio Time Update Utility. Dec 22 22:25:44 tycshd volumio-time-update[479]: volumio-time-update-util: System time updated successfully. Dec 22 22:25:44 tycshd sudo[2075]: pam_unix(sudo:session): session closed for user root Dec 22 22:25:44 tycshd systemd[1]: Reached target Multi-User System. Dec 22 22:25:44 tycshd systemd[1]: Reached target Graphical Interface. Dec 22 22:25:44 tycshd systemd[1]: Starting Update UTMP about System Runlevel Changes... Dec 22 22:25:44 tycshd volumio[755]: error: Failed to ping endpoint as1.myvolumio.org : unknown error Dec 22 22:25:44 tycshd volumio[755]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 22:25:44 tycshd volumio[755]: Error: Unable to resolve or reject the same promise twice Dec 22 22:25:44 tycshd volumio[755]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Dec 22 22:25:44 tycshd volumio[755]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32086) Dec 22 22:25:44 tycshd volumio[755]: at Socket.emit (events.js:412:35) Dec 22 22:25:44 tycshd volumio[755]: at endReadableNT (internal/streams/readable.js:1333:12) Dec 22 22:25:44 tycshd volumio[755]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Dec 22 22:25:44 tycshd volumio[755]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 22:25:44 tycshd systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Dec 22 22:25:44 tycshd systemd[1]: Started Update UTMP about System Runlevel Changes. Dec 22 22:25:44 tycshd systemd[1]: Startup finished in 7.166s (kernel) + 5min 18.824s (userspace) = 5min 25.990s. Dec 22 22:25:44 tycshd sudo[2098]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-22 22:24 Dec 22 22:25:44 tycshd sudo[2098]: 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="cc50ad4a2058d01de272214eb33827883bd2b7d8" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="8bcc10c3dbcbcb349e9887dc0527d54876b32688" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 18 Nov 2025 04:14:14 PM CET" VOLUMIO_VERSION="3.877" VOLUMIO_HARDWARE="nanopineo2" VOLUMIO_DEVICENAME="NanoPi Neo2" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="57978c68a391dbf6badbe915e5672a72"