-- Logs begin at Mon 2026-04-13 08:43:48 CEST, end at Mon 2026-04-13 08:51:12 CEST. -- Apr 13 08:50:01 rivoplus volumio-time-update[2872]: volumio-time-update-util: Date not found in response Apr 13 08:50:01 rivoplus volumio-time-update[2872]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 08:50:05 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Apr 13 08:50:06 rivoplus volumio-time-update[2872]: volumio-time-update-util: Fetching time from Volumio... Apr 13 08:50:06 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Apr 13 08:50:11 rivoplus go-librespot[5030]: time="2026-04-13T08:50:11+02: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" Apr 13 08:50:11 rivoplus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 13 08:50:11 rivoplus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 13 08:50:14 rivoplus systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 13 08:50:14 rivoplus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Apr 13 08:50:14 rivoplus systemd[1]: Stopped go-librespot Daemon. Apr 13 08:50:14 rivoplus systemd[1]: Started go-librespot Daemon. Apr 13 08:50:14 rivoplus go-librespot[5147]: go-librespot daemon starting... Apr 13 08:50:14 rivoplus go-librespot[5147]: time="2026-04-13T08:50:14+02:00" level=info msg="running go-librespot 0.7.1" Apr 13 08:50:14 rivoplus go-librespot[5147]: time="2026-04-13T08:50:14+02:00" level=debug msg="app state loaded" Apr 13 08:50:14 rivoplus go-librespot[5147]: time="2026-04-13T08:50:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 13 08:50:33 rivoplus volumio[3284]: info: Connection to go-librespot Websocket established Apr 13 08:50:33 rivoplus go-librespot[5147]: time="2026-04-13T08:50:33+02:00" level=debug msg="new websocket client" Apr 13 08:50:34 rivoplus volumio-time-update[2872]: volumio-time-update-util: Date not found in response Apr 13 08:50:34 rivoplus volumio-time-update[2872]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 08:50:34 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Apr 13 08:50:36 rivoplus volumio[3284]: info: Getting Spotify volume Apr 13 08:50:39 rivoplus volumio-time-update[2872]: volumio-time-update-util: Fetching time from Volumio... Apr 13 08:50:42 rivoplus go-librespot[5147]: time="2026-04-13T08:50:42+02: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" Apr 13 08:50:42 rivoplus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 13 08:50:42 rivoplus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 13 08:50:42 rivoplus volumio[3284]: (node:3284) UnhandledPromiseRejectionWarning: Error: socket hang up Apr 13 08:50:42 rivoplus volumio[3284]: at connResetException (internal/errors.js:639:14) Apr 13 08:50:42 rivoplus volumio[3284]: at Socket.socketOnEnd (_http_client.js:499:23) Apr 13 08:50:42 rivoplus volumio[3284]: at Socket.emit (events.js:412:35) Apr 13 08:50:42 rivoplus volumio[3284]: at endReadableNT (internal/streams/readable.js:1333:12) Apr 13 08:50:42 rivoplus volumio[3284]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Apr 13 08:50:42 rivoplus volumio[3284]: (node:3284) 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) Apr 13 08:50:42 rivoplus volumio[3284]: info: Connection to go-librespot Websocket closed Apr 13 08:50:45 rivoplus volumio[3284]: info: Initializing connection to go-librespot Websocket Apr 13 08:50:45 rivoplus systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 13 08:50:45 rivoplus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Apr 13 08:50:45 rivoplus systemd[1]: Stopped go-librespot Daemon. Apr 13 08:50:45 rivoplus systemd[1]: Started go-librespot Daemon. Apr 13 08:50:45 rivoplus go-librespot[5215]: go-librespot daemon starting... Apr 13 08:50:45 rivoplus go-librespot[5215]: time="2026-04-13T08:50:45+02:00" level=info msg="running go-librespot 0.7.1" Apr 13 08:50:45 rivoplus go-librespot[5215]: time="2026-04-13T08:50:45+02:00" level=debug msg="app state loaded" Apr 13 08:50:45 rivoplus go-librespot[5215]: time="2026-04-13T08:50:45+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 13 08:51:02 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Apr 13 08:51:04 rivoplus kernel: meson6-dwmac ff3f0000.ethernet eth0: Link is Down Apr 13 08:51:04 rivoplus dhcpcd[3176]: eth0: carrier lost Apr 13 08:51:04 rivoplus avahi-daemon[2868]: Withdrawing address record for 192.168.68.168 on eth0. Apr 13 08:51:04 rivoplus avahi-daemon[2868]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.68.168. Apr 13 08:51:04 rivoplus avahi-daemon[2868]: Interface eth0.IPv4 no longer relevant for mDNS. Apr 13 08:51:04 rivoplus volumio[3284]: info: Discovery: A device disappeared from network Apr 13 08:51:04 rivoplus volumio[3284]: info: Discovery: A device disappeared from network Apr 13 08:51:04 rivoplus dhcpcd[3176]: eth0: deleting route to 192.168.68.0/24 Apr 13 08:51:04 rivoplus dhcpcd[3176]: eth0: deleting default route via 192.168.68.1 Apr 13 08:51:04 rivoplus ntpd[4567]: ntpd exiting on signal 15 (Terminated) Apr 13 08:51:04 rivoplus systemd[1]: Stopping Network Time Service... Apr 13 08:51:04 rivoplus ntpd[4567]: 83.228.197.167 local addr 192.168.68.168 -> Apr 13 08:51:04 rivoplus volumio[3284]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 13 08:51:04 rivoplus systemd[1]: ntp.service: Succeeded. Apr 13 08:51:04 rivoplus systemd[1]: Stopped Network Time Service. Apr 13 08:51:04 rivoplus volumio[3284]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Apr 13 08:51:04 rivoplus systemd[1]: Starting Network Time Service... Apr 13 08:51:04 rivoplus volumio[3284]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 13 08:51:04 rivoplus ifplugd(eth0)[3065]: Link beat lost. Apr 13 08:51:04 rivoplus ntpd[5348]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 13 08:51:04 rivoplus ntpd[5348]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -c /run/ntp.conf.dhcp -u 104:103 Apr 13 08:51:04 rivoplus systemd[1]: Started Network Time Service. Apr 13 08:51:04 rivoplus ntpd[5365]: proto: precision = 1.250 usec (-20) Apr 13 08:51:04 rivoplus ntpd[5365]: Listen and drop on 0 v6wildcard [::]:123 Apr 13 08:51:04 rivoplus ntpd[5365]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 13 08:51:04 rivoplus ntpd[5365]: Listen normally on 2 lo 127.0.0.1:123 Apr 13 08:51:04 rivoplus ntpd[5365]: Listen normally on 3 wlan0 192.168.68.59:123 Apr 13 08:51:04 rivoplus ntpd[5365]: Listening on routing socket on fd #20 for interface updates Apr 13 08:51:04 rivoplus ntpd[5365]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 13 08:51:04 rivoplus ntpd[5365]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 13 08:51:04 rivoplus volumio5-onboarding[3463]: time=2026-04-13T08:51:04.577+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="00:00:00:00:00:00%0a @ 0x2000e10" available=true connected=false macAddress= ip4Address= ip6Address= Apr 13 08:51:04 rivoplus volumio[3284]: info: Received Get System Info Apr 13 08:51:04 rivoplus volumio[3284]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 08:51:04 rivoplus volumio[3284]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 08:51:04 rivoplus volumio[3284]: info: Discovery: Getting this device information Apr 13 08:51:04 rivoplus volumio[3284]: info: CoreCommandRouter::volumioGetState Apr 13 08:51:04 rivoplus volumio[3284]: info: CorePlayQueue::getTrack 0 Apr 13 08:51:04 rivoplus volumio[3284]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 08:51:04 rivoplus volumio[3284]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 13 08:51:04 rivoplus volumio[3284]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 13 08:51:04 rivoplus volumio5-onboarding[3463]: time=2026-04-13T08:51:04.648+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.68.56:52475 Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02: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]" Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02: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]" Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02: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]" Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02:00" level=info msg="zeroconf server listening on port 35277" Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration" Apr 13 08:51:05 rivoplus volumio5-onboarding[3463]: time=2026-04-13T08:51:05.386+02:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02:00" level=debug msg="obtained new client token: AADr0HQ68+QpvI3Jvv+TGebFbdn19GugCkRMtBOJELm+BNV55kcPrFvh+k+ek7vPu2z6JQByCE6r17GuRAWHreSyTBGQ1XmoZ0V/GoaFWgRyH/d0GxvcTjs6LOshxrIdw22T1hIuOXJHTd7iR27ickj2ha4wlpNs1srRRIfWlON/KaTbps52K2bvDOi+FzXmgrF3wZbi+to7iABp1zCwZudAlSFBtZElqeu03OG+uQ1eI5STCVKWqBk=" Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02:00" level=debug msg="completed keyexchange" Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02:00" level=debug msg="completed challenge" Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02:00" level=info msg="authenticated AP" username="31************************qa" Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02:00" level=info msg="authenticated Login5" username="31************************qa" Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02:00" level=debug msg="initializing zeroconf session" username="31************************qa" Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02:00" level=debug msg="dealer connection opened" Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02:00" level=trace msg="starting accesspoint recv loop" Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02:00" level=trace msg="starting dealer recv loop" Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02:00" level=trace msg="received accesspoint ping" Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02:00" level=debug msg="received connection id: M2IwMWU5ZTMtY2M0...NzJFMEVFMEQyNg==" Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 13 08:51:05 rivoplus go-librespot[5215]: time="2026-04-13T08:51:05+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 13 08:51:06 rivoplus go-librespot[5215]: time="2026-04-13T08:51:06+02:00" level=debug msg="put connect state because NEW_DEVICE" Apr 13 08:51:06 rivoplus go-librespot[5215]: time="2026-04-13T08:51:06+02:00" level=debug msg="update volume requested to 65535/65535" Apr 13 08:51:06 rivoplus go-librespot[5215]: time="2026-04-13T08:51:06+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 13 08:51:06 rivoplus go-librespot[5215]: time="2026-04-13T08:51:06+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 13 08:51:06 rivoplus go-librespot[5215]: time="2026-04-13T08:51:06+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 13 08:51:06 rivoplus go-librespot[5215]: time="2026-04-13T08:51:06+02:00" level=trace msg="received accesspoint pong ack" Apr 13 08:51:06 rivoplus go-librespot[5215]: time="2026-04-13T08:51:06+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 13 08:51:06 rivoplus go-librespot[5215]: time="2026-04-13T08:51:06+02:00" level=trace msg="emitting websocket event: volume" Apr 13 08:51:06 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Apr 13 08:51:06 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Apr 13 08:51:06 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Apr 13 08:51:06 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 13 08:51:06 rivoplus volumio[3284]: info: Discovery: adding a5a01753-37f7-4cde-90d0-d5cc8a0faf20 Apr 13 08:51:06 rivoplus volumio[3284]: info: Discovery: Found device Rivoplus Apr 13 08:51:06 rivoplus volumio[3284]: info: CoreCommandRouter::volumioGetState Apr 13 08:51:06 rivoplus volumio[3284]: info: CorePlayQueue::getTrack 0 Apr 13 08:51:06 rivoplus volumio[3284]: info: Discovery: this is already registered, a5a01753-37f7-4cde-90d0-d5cc8a0faf20 Apr 13 08:51:06 rivoplus volumio[3284]: info: Discovery: Found device Rivoplus Apr 13 08:51:06 rivoplus volumio[3284]: info: CoreCommandRouter::volumioGetState Apr 13 08:51:06 rivoplus volumio[3284]: info: CorePlayQueue::getTrack 0 Apr 13 08:51:07 rivoplus volumio[3284]: info: Discovery: this is already registered, a5a01753-37f7-4cde-90d0-d5cc8a0faf20 Apr 13 08:51:07 rivoplus volumio[3284]: info: Discovery: Found device Rivoplus Apr 13 08:51:07 rivoplus volumio[3284]: info: CoreCommandRouter::volumioGetState Apr 13 08:51:07 rivoplus volumio[3284]: info: CorePlayQueue::getTrack 0 Apr 13 08:51:07 rivoplus volumio[3284]: info: Discovery: this is already registered, a5a01753-37f7-4cde-90d0-d5cc8a0faf20 Apr 13 08:51:07 rivoplus volumio[3284]: info: Discovery: Found device Rivoplus Apr 13 08:51:07 rivoplus volumio[3284]: info: CoreCommandRouter::volumioGetState Apr 13 08:51:07 rivoplus volumio[3284]: info: CorePlayQueue::getTrack 0 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Apr 13 08:51:07 rivoplus volumio-time-update[2872]: volumio-time-update-util: Date not found in response Apr 13 08:51:07 rivoplus volumio-time-update[2872]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 16 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 17 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 18 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 19 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 20 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 21 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 22 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 23 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 24 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 25 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 26 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 27 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 28 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 29 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 30 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 31 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 32 Apr 13 08:51:07 rivoplus go-librespot[5215]: time="2026-04-13T08:51:07+02:00" level=debug msg="new websocket client" Apr 13 08:51:07 rivoplus volumio[3284]: info: Connection to go-librespot Websocket established Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 33 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 34 Apr 13 08:51:07 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 35 Apr 13 08:51:07 rivoplus volumio[3284]: info: CoreCommandRouter::volumioGetState Apr 13 08:51:07 rivoplus volumio[3284]: info: CorePlayQueue::getTrack 0 Apr 13 08:51:07 rivoplus volumio[3284]: info: Aligning Spotify Volume to Volumio Volume Apr 13 08:51:07 rivoplus volumio[3284]: info: CoreCommandRouter::volumioGetState Apr 13 08:51:07 rivoplus volumio[3284]: info: CorePlayQueue::getTrack 0 Apr 13 08:51:07 rivoplus volumio[3284]: info: Setting Spotify Volume from Volumio: 100 Apr 13 08:51:07 rivoplus volumio[3284]: info: CoreCommandRouter::volumioGetState Apr 13 08:51:07 rivoplus volumio[3284]: info: CorePlayQueue::getTrack 0 Apr 13 08:51:08 rivoplus volumio[3284]: info: MCU Signalled Playback Inactive Apr 13 08:51:08 rivoplus volumio[3284]: info: Reporting MCU Network Status: 2 Apr 13 08:51:08 rivoplus volumio[3284]: info: Volumio Network Manager: Network status updated: 2 Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 13 08:51:08 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 13 08:51:09 rivoplus volumio[3284]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 13 08:51:09 rivoplus volumio[3284]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 13 08:51:09 rivoplus volumio[3284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 08:51:09 rivoplus volumio[3284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 08:51:09 rivoplus volumio[3284]: info: Starting MyVolumio Remote Streaming Endpoints Apr 13 08:51:09 rivoplus volumio[3284]: info: MyVolumio login type: Token Apr 13 08:51:09 rivoplus volumio[3284]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 13 08:51:09 rivoplus volumio[3284]: 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' Apr 13 08:51:09 rivoplus volumio[3284]: info: Sending Spotify command with payload to local API: /player/volume Apr 13 08:51:09 rivoplus go-librespot[5215]: time="2026-04-13T08:51:09+02:00" level=debug msg="update volume requested to 65535/65535" Apr 13 08:51:10 rivoplus go-librespot[5215]: time="2026-04-13T08:51:10+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 13 08:51:10 rivoplus go-librespot[5215]: time="2026-04-13T08:51:10+02:00" level=trace msg="emitting websocket event: volume" Apr 13 08:51:10 rivoplus volumio[3284]: error: MyVolumio Custom Token format not valid, refreshing it Apr 13 08:51:10 rivoplus volumio[3284]: info: Getting Spotify volume Apr 13 08:51:10 rivoplus volumio[3284]: info: Spotify volume: 100 Apr 13 08:51:10 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 36 Apr 13 08:51:10 rivoplus volumio[3284]: info: CoreCommandRouter::volumioGetState Apr 13 08:51:10 rivoplus volumio[3284]: info: CorePlayQueue::getTrack 0 Apr 13 08:51:10 rivoplus volumio[3284]: info: MyVolumio login type: Token Apr 13 08:51:11 rivoplus systemd[1]: Starting Daily apt download activities... Apr 13 08:51:11 rivoplus volumio[3284]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 13 08:51:11 rivoplus volumio[3284]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 13 08:51:11 rivoplus volumio[3284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 36 Apr 13 08:51:11 rivoplus volumio[3284]: info: MyVolumio token set successfully Apr 13 08:51:11 rivoplus volumio[3284]: info: MYVOLUMIO: Adding device Apr 13 08:51:11 rivoplus volumio[3284]: info: MYVOLUMIO: Evaluating Server Apr 13 08:51:12 rivoplus volumio-time-update[2872]: volumio-time-update-util: Fetching time from Volumio... Apr 13 08:51:12 rivoplus systemd[1]: apt-daily.service: Succeeded. Apr 13 08:51:12 rivoplus systemd[1]: Started Daily apt download activities. Apr 13 08:51:12 rivoplus volumio-time-update[2872]: volumio-time-update-util: Setting system time to: 2026-04-13 08:51:12 Apr 13 08:51:12 rivoplus sudo[5456]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2026-04-13 08:51:12 Apr 13 08:51:12 rivoplus sudo[5456]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 08:51:12 rivoplus dbus-daemon[2855]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.48' (uid=0 pid=5459 comm="timedatectl set-time 2026-04-13 08:51:12 " label="kernel") Apr 13 08:51:12 rivoplus systemd[1]: Starting Time & Date Service... Apr 13 08:51:12 rivoplus volumio[3284]: info: MyVolumio status changed Apr 13 08:51:12 rivoplus volumio[3284]: info: Streaming services startup Apr 13 08:51:12 rivoplus volumio[3284]: info: Starting Streaming Daemon Apr 13 08:51:12 rivoplus dbus-daemon[2855]: [system] Successfully activated service 'org.freedesktop.timedate1' Apr 13 08:51:12 rivoplus systemd[1]: Started Time & Date Service. Apr 13 08:51:12 rivoplus systemd-timedated[5463]: Changed local time to Mon Apr 13 08:51:12 2026 Apr 13 08:51:12 rivoplus systemd[1]: Started Volumio Time Update Utility. Apr 13 08:51:12 rivoplus volumio-time-update[2872]: volumio-time-update-util: System time updated successfully. Apr 13 08:51:12 rivoplus sudo[5456]: pam_unix(sudo:session): session closed for user root Apr 13 08:51:12 rivoplus systemd[1]: Reached target Multi-User System. Apr 13 08:51:12 rivoplus systemd[1]: Reached target Graphical Interface. Apr 13 08:51:12 rivoplus systemd[1]: Starting Update UTMP about System Runlevel Changes... Apr 13 08:51:12 rivoplus volumio[3284]: info: Removing browser output: myVolumio user plan is not superstar Apr 13 08:51:12 rivoplus volumio[3284]: info: Removing audio output: Apr 13 08:51:12 rivoplus volumio[3284]: info: Stoppping Tunnel 1 Apr 13 08:51:12 rivoplus systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Apr 13 08:51:12 rivoplus systemd[1]: Started Update UTMP about System Runlevel Changes. Apr 13 08:51:12 rivoplus systemd[1]: Startup finished in 12.825s (kernel) + 7min 24.825s (userspace) = 7min 37.651s. Apr 13 08:51:12 rivoplus sudo[5479]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 13 08:51:12 rivoplus sudo[5479]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 08:51:12 rivoplus volumio[3284]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 13 08:51:12 rivoplus sudo[5479]: pam_unix(sudo:session): session closed for user root Apr 13 08:51:12 rivoplus sudo[5482]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 13 08:51:12 rivoplus sudo[5482]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 08:51:12 rivoplus volumio[3284]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 13 08:51:12 rivoplus sudo[5482]: pam_unix(sudo:session): session closed for user root Apr 13 08:51:12 rivoplus volumio[3284]: error: Failed to ping endpoint eu11.myvolumio.org : unknown error Apr 13 08:51:12 rivoplus volumio[3284]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 13 08:51:12 rivoplus volumio[3284]: Error: Unable to resolve or reject the same promise twice Apr 13 08:51:12 rivoplus volumio[3284]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Apr 13 08:51:12 rivoplus volumio[3284]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32086) Apr 13 08:51:12 rivoplus volumio[3284]: at Socket.emit (events.js:412:35) Apr 13 08:51:12 rivoplus volumio[3284]: at endReadableNT (internal/streams/readable.js:1333:12) Apr 13 08:51:12 rivoplus volumio[3284]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Apr 13 08:51:12 rivoplus volumio[3284]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 13 08:51:12 rivoplus sudo[5493]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-04-13 08:50 Apr 13 08:51:12 rivoplus sudo[5493]: 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="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 11:19:27 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo Plus" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo Plus" VOLUMIO_HASH="a7285124ffc88c43265bb2db03526f6a"