-- Logs begin at Sat 2026-08-29 18:01:31 JST, end at Sat 2026-08-29 18:06:04 JST. -- Aug 29 18:05:00 rivomusique volumio[3261]: info: Received Get System Info Aug 29 18:05:00 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:05:00 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:05:00 rivomusique volumio[3261]: info: Discovery: Getting this device information Aug 29 18:05:00 rivomusique volumio[3261]: info: CoreCommandRouter::volumioGetState Aug 29 18:05:00 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:00.751+09:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.10.101:64409,00:00:00:00:00:00%01 @ 0x293e7e0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 29 18:05:00 rivomusique volumio[3261]: info: CorePlayQueue::getTrack 0 Aug 29 18:05:00 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:05:00 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:00.754+09:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x29ab320" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 29 18:05:00 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 18:05:00 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 18:05:00 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:00.773+09:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 29 18:05:01 rivomusique volumio[3261]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=mp1&variante=rivo&version=3.912&uuid=d01f5fba71fefdedce7f7a3422fd1525" http://updates.volumio.org/downloader-v1/track-device Aug 29 18:05:01 rivomusique volumio[3261]: % Total % Received % Xferd Average Speed Time Time Time Current Aug 29 18:05:01 rivomusique volumio[3261]: Dload Upload Total Spent Left Speed Aug 29 18:05:01 rivomusique volumio[3261]: [1.2K blob data] Aug 29 18:05:01 rivomusique volumio[3261]: retrying in 5 seconds, trial 1 Aug 29 18:05:01 rivomusique volumio[3261]: info: Volumio Calling Home Aug 29 18:05:07 rivomusique volumio[3261]: info: Received Get System Info Aug 29 18:05:07 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:05:07 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:05:07 rivomusique volumio[3261]: info: Discovery: Getting this device information Aug 29 18:05:07 rivomusique volumio[3261]: info: CoreCommandRouter::volumioGetState Aug 29 18:05:07 rivomusique volumio[3261]: info: CorePlayQueue::getTrack 0 Aug 29 18:05:07 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:05:07 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:07.705+09:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.10.101:64409,00:00:00:00:00:00%01 @ 0x293e7e0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 29 18:05:07 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:07.706+09:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x29ab320" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 29 18:05:07 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 18:05:07 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 18:05:07 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:07.718+09:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 29 18:05:09 rivomusique ntpd[3299]: Soliciting pool server 45.76.211.39 Aug 29 18:05:09 rivomusique nmbd[3051]: [2026/08/29 18:05:09.873499, 0] ../source3/libsmb/nmblib.c:917(send_udp) Aug 29 18:05:09 rivomusique nmbd[3051]: Packet send failed to 192.168.10.255(138) ERRNO=Network is unreachable Aug 29 18:05:10 rivomusique ntpd[3299]: Soliciting pool server 46.250.253.227 Aug 29 18:05:10 rivomusique ntpd[3299]: Soliciting pool server 46.250.253.227 Aug 29 18:05:11 rivomusique volumio[3261]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=mp1&variante=rivo&version=3.912&uuid=d01f5fba71fefdedce7f7a3422fd1525" http://updates.volumio.org/downloader-v1/track-device Aug 29 18:05:11 rivomusique volumio[3261]: % Total % Received % Xferd Average Speed Time Time Time Current Aug 29 18:05:11 rivomusique volumio[3261]: Dload Upload Total Spent Left Speed Aug 29 18:05:11 rivomusique volumio[3261]: [132B blob data] Aug 29 18:05:11 rivomusique volumio[3261]: retrying in 5 seconds, trial 2 Aug 29 18:05:11 rivomusique volumio[3261]: info: Volumio Calling Home Aug 29 18:05:11 rivomusique ntpd[3299]: Soliciting pool server 45.76.211.39 Aug 29 18:05:14 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:14.663+09:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.10.101:64409,00:00:00:00:00:00%01 @ 0x293e7e0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 29 18:05:14 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:14.663+09:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x29ab320" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 29 18:05:14 rivomusique volumio[3261]: info: Received Get System Info Aug 29 18:05:14 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:05:14 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:05:14 rivomusique volumio[3261]: info: Discovery: Getting this device information Aug 29 18:05:14 rivomusique volumio[3261]: info: CoreCommandRouter::volumioGetState Aug 29 18:05:14 rivomusique volumio[3261]: info: CorePlayQueue::getTrack 0 Aug 29 18:05:14 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:05:14 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 18:05:14 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 18:05:14 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:14.687+09:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 29 18:05:15 rivomusique systemd[1]: Starting Daily apt download activities... Aug 29 18:05:15 rivomusique volumio[3261]: ------------------------------------ BT MESSAGE: BT STATUS: running Aug 29 18:05:16 rivomusique systemd[1]: apt-daily.service: Succeeded. Aug 29 18:05:16 rivomusique systemd[1]: Started Daily apt download activities. Aug 29 18:05:21 rivomusique wpa_supplicant[3167]: wlan0: Trying to associate with 6c:e4:da:e3:1a:37 (SSID='aterm-125ea7-a' freq=5180 MHz) Aug 29 18:05:21 rivomusique kernel: Connecting with 6c:e4:da:e3:1a:37 ssid "aterm-125ea7-a", len (14) channel=36 Aug 29 18:05:21 rivomusique kernel: dhd_dbg_start_pkt_monitor, 1724 Aug 29 18:05:21 rivomusique kernel: wl_iw_event: Link UP with 6c:e4:da:e3:1a:37 Aug 29 18:05:21 rivomusique kernel: wl_bss_connect_done succeeded with 6c:e4:da:e3:1a:37 Aug 29 18:05:21 rivomusique kernel: CFG80211-ERROR) wl_cfg80211_scan_abort : scan abort failed Aug 29 18:05:21 rivomusique wpa_supplicant[3167]: wlan0: Associated with 6c:e4:da:e3:1a:37 Aug 29 18:05:21 rivomusique wpa_supplicant[3167]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Aug 29 18:05:21 rivomusique wpa_supplicant[3167]: wlan0: WPA: Key negotiation completed with 6c:e4:da:e3:1a:37 [PTK=CCMP GTK=CCMP] Aug 29 18:05:21 rivomusique wpa_supplicant[3167]: wlan0: CTRL-EVENT-CONNECTED - Connection to 6c:e4:da:e3:1a:37 completed [id=0 id_str=] Aug 29 18:05:21 rivomusique dhcpcd[3300]: wlan0: carrier acquired Aug 29 18:05:21 rivomusique dhcpcd[3300]: wlan0: IAID c9:8f:83:0c Aug 29 18:05:21 rivomusique kernel: wl_bss_connect_done succeeded with 6c:e4:da:e3:1a:37 vndr_oui: 00-0D-02 00-E0-4C Aug 29 18:05:21 rivomusique volumio[3261]: info: Received Get System Info Aug 29 18:05:21 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:05:21 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:05:21 rivomusique volumio[3261]: info: Discovery: Getting this device information Aug 29 18:05:21 rivomusique volumio[3261]: info: CoreCommandRouter::volumioGetState Aug 29 18:05:21 rivomusique volumio[3261]: info: CorePlayQueue::getTrack 0 Aug 29 18:05:21 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:05:21 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:21.787+09:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.10.101:64409,00:00:00:00:00:00%01 @ 0x293e7e0" available=true connected=true macAddress=54:78:c9:8f:83:0c ip4Address= ip6Address= ssid=aterm-125ea7-a Aug 29 18:05:21 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:21.789+09:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x29ab320" available=true connected=true macAddress=54:78:c9:8f:83:0c ip4Address= ip6Address= ssid=aterm-125ea7-a Aug 29 18:05:21 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 18:05:21 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 18:05:21 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:21.812+09:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 29 18:05:21 rivomusique dhcpcd[3300]: wlan0: rebinding lease of 192.168.10.106 Aug 29 18:05:22 rivomusique dhcpcd[3300]: wlan0: soliciting an IPv6 router Aug 29 18:05:23 rivomusique dhcpcd[3300]: wlan0: probing address 192.168.10.106/24 Aug 29 18:05:29 rivomusique dhcpcd[3300]: wlan0: leased 192.168.10.106 for 86400 seconds Aug 29 18:05:29 rivomusique avahi-daemon[2837]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.10.106. Aug 29 18:05:29 rivomusique dhcpcd[3300]: wlan0: adding route to 192.168.10.0/24 Aug 29 18:05:29 rivomusique dhcpcd[3300]: wlan0: adding default route via 192.168.10.1 Aug 29 18:05:29 rivomusique avahi-daemon[2837]: New relevant interface wlan0.IPv4 for mDNS. Aug 29 18:05:29 rivomusique avahi-daemon[2837]: Registering new address record for 192.168.10.106 on wlan0.IPv4. Aug 29 18:05:29 rivomusique ntpd[3299]: ntpd exiting on signal 15 (Terminated) Aug 29 18:05:29 rivomusique systemd[1]: Stopping Network Time Service... Aug 29 18:05:29 rivomusique volumio[3261]: ------------------------------------ BT MESSAGE: BT STATUS: running Aug 29 18:05:29 rivomusique systemd[1]: ntp.service: Succeeded. Aug 29 18:05:29 rivomusique systemd[1]: Stopped Network Time Service. Aug 29 18:05:29 rivomusique systemd[1]: Starting Network Time Service... Aug 29 18:05:29 rivomusique volumio[3261]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Aug 29 18:05:29 rivomusique volumio[3261]: ------------------------------------ BT MESSAGE: BT STATUS: running Aug 29 18:05:29 rivomusique ntpd[4559]: ntpd 4.2.8p12@1.3728-o (1): Starting Aug 29 18:05:29 rivomusique ntpd[4559]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Aug 29 18:05:29 rivomusique systemd[1]: Started Network Time Service. Aug 29 18:05:29 rivomusique ntpd[4581]: proto: precision = 1.250 usec (-20) Aug 29 18:05:29 rivomusique ntpd[4581]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Aug 29 18:05:29 rivomusique ntpd[4581]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Aug 29 18:05:29 rivomusique ntpd[4581]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 1341 days ago Aug 29 18:05:29 rivomusique ntpd[4581]: Listen and drop on 0 v6wildcard [::]:123 Aug 29 18:05:29 rivomusique ntpd[4581]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Aug 29 18:05:29 rivomusique ntpd[4581]: Listen normally on 2 lo 127.0.0.1:123 Aug 29 18:05:29 rivomusique ntpd[4581]: Listen normally on 3 wlan0 192.168.10.106:123 Aug 29 18:05:29 rivomusique ntpd[4581]: Listening on routing socket on fd #20 for interface updates Aug 29 18:05:29 rivomusique ntpd[4581]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Aug 29 18:05:29 rivomusique ntpd[4581]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Aug 29 18:05:29 rivomusique volumio[3261]: info: Reporting MCU Network Status: 2 Aug 29 18:05:29 rivomusique volumio[3261]: info: Volumio Network Manager: Network status updated: 2 Aug 29 18:05:29 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:29.578+09:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.10.101:64409,00:00:00:00:00:00%01 @ 0x293e7e0" available=true connected=true macAddress=54:78:c9:8f:83:0c ip4Address=192.168.10.106/24 ip6Address= ssid=aterm-125ea7-a Aug 29 18:05:29 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:29.580+09:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x29ab320" available=true connected=true macAddress=54:78:c9:8f:83:0c ip4Address=192.168.10.106/24 ip6Address= ssid=aterm-125ea7-a Aug 29 18:05:29 rivomusique volumio[3261]: info: Received Get System Info Aug 29 18:05:29 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:05:29 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:05:29 rivomusique volumio[3261]: info: Discovery: Getting this device information Aug 29 18:05:29 rivomusique volumio[3261]: info: CoreCommandRouter::volumioGetState Aug 29 18:05:29 rivomusique volumio[3261]: info: CorePlayQueue::getTrack 0 Aug 29 18:05:29 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:05:29 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 18:05:29 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 18:05:30 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:30.433+09:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 29 18:05:38 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:05:38 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:05:38 rivomusique volumio[3261]: info: Discovery: Getting this device information Aug 29 18:05:38 rivomusique volumio[3261]: info: CoreCommandRouter::volumioGetState Aug 29 18:05:38 rivomusique volumio[3261]: info: CorePlayQueue::getTrack 0 Aug 29 18:05:38 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:05:38 rivomusique volumio[3261]: verbose: New Socket.io Connection to 192.168.10.106:3000 from 192.168.10.101 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Aug 29 18:05:38 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 18:05:38 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 18:05:39 rivomusique volumio[3261]: verbose: New Socket.io Connection to 192.168.10.106 from 192.168.10.101 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 6 Aug 29 18:05:39 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 29 18:05:39 rivomusique volumio[3261]: info: CoreCommandRouter::volumioGetVisibleSources Aug 29 18:05:39 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 18:05:39 rivomusique volumio[3261]: info: CoreCommandRouter::volumioGetState Aug 29 18:05:39 rivomusique volumio[3261]: info: CorePlayQueue::getTrack 0 Aug 29 18:05:39 rivomusique volumio[3261]: info: CoreCommandRouter::volumioGetState Aug 29 18:05:39 rivomusique volumio[3261]: info: CorePlayQueue::getTrack 0 Aug 29 18:05:39 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 29 18:05:39 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 29 18:05:39 rivomusique volumio[3261]: info: Received Get System Info Aug 29 18:05:39 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:05:39 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:05:39 rivomusique volumio[3261]: info: Discovery: Getting this device information Aug 29 18:05:39 rivomusique volumio[3261]: info: CoreCommandRouter::volumioGetState Aug 29 18:05:39 rivomusique volumio[3261]: info: CorePlayQueue::getTrack 0 Aug 29 18:05:39 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:05:39 rivomusique volumio[3261]: info: CoreCommandRouter::volumioGetState Aug 29 18:05:39 rivomusique volumio[3261]: info: CorePlayQueue::getTrack 0 Aug 29 18:05:39 rivomusique volumio[3261]: info: Listing playlists Aug 29 18:05:39 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 18:05:39 rivomusique volumio[3261]: info: Received Get System Info Aug 29 18:05:39 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:05:39 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:05:39 rivomusique volumio[3261]: info: Discovery: Getting this device information Aug 29 18:05:39 rivomusique volumio[3261]: info: CoreCommandRouter::volumioGetState Aug 29 18:05:39 rivomusique volumio[3261]: info: CorePlayQueue::getTrack 0 Aug 29 18:05:39 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:05:40 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Aug 29 18:05:48 rivomusique ntpd[4581]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Aug 29 18:05:50 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:50.122+09:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.10.101:65077 Aug 29 18:05:50 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:50.149+09:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.101:65077 @ 0x293f1a0" latency=1.077185556s timeout=10s Aug 29 18:05:50 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:05:50 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:05:50 rivomusique volumio[3261]: info: Discovery: Getting this device information Aug 29 18:05:50 rivomusique volumio[3261]: info: CoreCommandRouter::volumioGetState Aug 29 18:05:50 rivomusique volumio[3261]: info: CorePlayQueue::getTrack 0 Aug 29 18:05:50 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:05:50 rivomusique volumio[3261]: verbose: New Socket.io Connection to 192.168.10.106:3000 from 192.168.10.101 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Aug 29 18:05:50 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 18:05:50 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 18:05:52 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:05:52 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:05:52 rivomusique volumio[3261]: info: Discovery: Getting this device information Aug 29 18:05:52 rivomusique volumio[3261]: info: CoreCommandRouter::volumioGetState Aug 29 18:05:52 rivomusique volumio[3261]: info: CorePlayQueue::getTrack 0 Aug 29 18:05:52 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:05:52 rivomusique volumio[3261]: verbose: New Socket.io Connection to 192.168.10.106:3000 from 192.168.10.101 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Aug 29 18:05:52 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 18:05:52 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 18:05:56 rivomusique ntpd[4581]: Soliciting pool server 160.251.138.123 Aug 29 18:05:57 rivomusique ntpd[4581]: Soliciting pool server 162.159.200.1 Aug 29 18:05:57 rivomusique ntpd[4581]: Soliciting pool server 139.162.81.45 Aug 29 18:05:57 rivomusique ntpd[4581]: Soliciting pool server 163.44.119.85 Aug 29 18:05:57 rivomusique ntpd[4581]: Soliciting pool server 129.250.35.250 Aug 29 18:05:57 rivomusique ntpd[4581]: Soliciting pool server 162.159.200.123 Aug 29 18:05:58 rivomusique ntpd[4581]: Soliciting pool server 117.102.178.88 Aug 29 18:05:58 rivomusique ntpd[4581]: Soliciting pool server 172.233.91.137 Aug 29 18:05:58 rivomusique ntpd[4581]: Soliciting pool server 142.91.105.55 Aug 29 18:05:58 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:58.724+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.101:65077 @ 0x293f1a0" latency=1.077185556s timeout=10s endpoint=http://pushupdates.volumio.org duration=8.569980594s Aug 29 18:05:58 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:58.849+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.101:65077 @ 0x293f1a0" latency=1.077185556s timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=8.698003338s Aug 29 18:05:58 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:58.868+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.101:65077 @ 0x293f1a0" latency=1.077185556s timeout=10s endpoint=http://plugins.volumio.org duration=8.713148115s Aug 29 18:05:58 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:58.942+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.101:65077 @ 0x293f1a0" latency=1.077185556s timeout=10s endpoint=https://www.googleapis.com duration=8.791918135s Aug 29 18:05:59 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:59.000+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.101:65077 @ 0x293f1a0" latency=1.077185556s timeout=10s endpoint=https://myvolumio.firebaseio.com duration=8.848420223s Aug 29 18:05:59 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:59.103+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.101:65077 @ 0x293f1a0" latency=1.077185556s timeout=10s endpoint=https://securetoken.googleapis.com duration=8.95320882s Aug 29 18:05:59 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:59.117+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.101:65077 @ 0x293f1a0" latency=1.077185556s timeout=10s endpoint=http://cddb.volumio.org duration=8.963929077s Aug 29 18:05:59 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:59.263+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.101:65077 @ 0x293f1a0" latency=1.077185556s timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=9.112991999s Aug 29 18:05:59 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:59.289+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.101:65077 @ 0x293f1a0" latency=1.077185556s timeout=10s endpoint=https://functions.volumio.cloud duration=9.137200566s Aug 29 18:05:59 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:59.290+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.101:65077 @ 0x293f1a0" latency=1.077185556s timeout=10s endpoint=https://functions.volumio.cloud duration=9.1338848s Aug 29 18:05:59 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:59.333+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.101:65077 @ 0x293f1a0" latency=1.077185556s timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=9.182778104s Aug 29 18:05:59 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:59.341+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.101:65077 @ 0x293f1a0" latency=1.077185556s timeout=10s endpoint=https://database.volumio.cloud duration=9.185421574s Aug 29 18:05:59 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:05:59.408+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.101:65077 @ 0x293f1a0" latency=1.077185556s timeout=10s endpoint=https://google.com duration=9.258472987s Aug 29 18:05:59 rivomusique ntpd[4581]: Soliciting pool server 46.250.253.227 Aug 29 18:05:59 rivomusique ntpd[4581]: Soliciting pool server 45.76.211.39 Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 29 18:05:59 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 29 18:06:00 rivomusique ntpd[4581]: Soliciting pool server 103.131.151.20 Aug 29 18:06:01 rivomusique ntpd[4581]: Soliciting pool server 172.104.124.149 Aug 29 18:06:01 rivomusique volumio[3261]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 29 18:06:01 rivomusique volumio[3261]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 29 18:06:01 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:06:01 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 18:06:01 rivomusique volumio[3261]: info: Starting MyVolumio Remote Streaming Endpoints Aug 29 18:06:01 rivomusique ntpd[4581]: Soliciting pool server 167.179.119.205 Aug 29 18:06:01 rivomusique volumio[3261]: info: MyVolumio login type: Token Aug 29 18:06:01 rivomusique volumio[3261]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 29 18:06:01 rivomusique volumio[3261]: 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' Aug 29 18:06:01 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 18:06:01 rivomusique volumio[3261]: info: Received Get System Info Aug 29 18:06:01 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 18:06:01 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 18:06:01 rivomusique volumio[3261]: info: Discovery: Getting this device information Aug 29 18:06:01 rivomusique volumio[3261]: info: CoreCommandRouter::volumioGetState Aug 29 18:06:01 rivomusique volumio[3261]: info: CorePlayQueue::getTrack 0 Aug 29 18:06:01 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 18:06:01 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:06:01.841+09:00 level=ERROR msg="failed to read message" component=conn/ws remoteAddr=192.168.10.101:64409 error="read tcp 192.168.10.106:7331->192.168.10.101:64409: read: connection reset by peer" Aug 29 18:06:01 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:06:01.842+09:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.10.101:64409 Aug 29 18:06:01 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:06:01.842+09:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.10.101:64409 Aug 29 18:06:02 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Aug 29 18:06:02 rivomusique volumio[3261]: info: MyVolumio login type: Token Aug 29 18:06:02 rivomusique volumio[3261]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 18:06:02 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:06:02.292+09:00 level=INFO msg="emitting user changed event" component=server peer="00:00:00:00:00:00%01,192.168.10.101:65077 @ 0x293e7e0" userId= Aug 29 18:06:02 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:06:02.292+09:00 level=INFO msg="emitting user changed event" component=server peer="00:00:00:00:00:00%01 @ 0x29ab320" userId= Aug 29 18:06:02 rivomusique volumio[3261]: info: Discovery: adding bd19b621-a421-4cc6-8f0b-0d4c32b388f8 Aug 29 18:06:02 rivomusique volumio[3261]: info: Discovery: Found device RivoMusique Aug 29 18:06:02 rivomusique volumio[3261]: info: CoreCommandRouter::volumioGetState Aug 29 18:06:02 rivomusique volumio[3261]: info: CorePlayQueue::getTrack 0 Aug 29 18:06:02 rivomusique ntpd[4581]: Soliciting pool server 142.91.108.61 Aug 29 18:06:02 rivomusique volumio[3261]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 29 18:06:02 rivomusique volumio5-onboarding[3715]: time=2026-08-29T18:06:02.713+09:00 level=INFO msg="emitting user changed event" component=server peer="192.168.10.101:65077 @ 0x293f1a0" userId= Aug 29 18:06:03 rivomusique volumio[3261]: info: MyVolumio token set successfully Aug 29 18:06:03 rivomusique volumio[3261]: info: MYVOLUMIO: Adding device Aug 29 18:06:03 rivomusique volumio[3261]: info: MYVOLUMIO: Evaluating Server Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.364 [3756.4715] INFO SampleApp: API endpoint invoked: get-connect-info Aug 29 18:06:03 rivomusique volumio[3261]: info: MyVolumio status changed Aug 29 18:06:03 rivomusique volumio[3261]: info: Streaming services startup Aug 29 18:06:03 rivomusique volumio[3261]: info: Starting Streaming Daemon Aug 29 18:06:03 rivomusique ntpd[4581]: Soliciting pool server 8.209.206.137 Aug 29 18:06:03 rivomusique volumio[3261]: info: Removing browser output: myVolumio user plan is not superstar Aug 29 18:06:03 rivomusique volumio[3261]: info: Removing audio output: Aug 29 18:06:03 rivomusique volumio[3261]: info: Stoppping Tunnel 1 Aug 29 18:06:03 rivomusique sudo[4717]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 29 18:06:03 rivomusique sudo[4717]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 18:06:03 rivomusique sudo[4717]: pam_unix(sudo:session): session closed for user root Aug 29 18:06:03 rivomusique sudo[4720]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 29 18:06:03 rivomusique sudo[4720]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 18:06:03 rivomusique sudo[4720]: pam_unix(sudo:session): session closed for user root Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.713 [3756.4715] INFO SampleApp: API endpoint invoked: connect-to-qconnect Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.713 [3756.3756] INFO EndpointManager: [0xac3d3700]: Updating API endpoint Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.713 [3756.3756] INFO EndpointManager: [0xac3d3700]: Updating QConnect endpoint Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.713 [3756.3756] INFO ActiveStateManager: [0xac3d2798]: Setting new active state: active Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.713 [3756.3756] INFO PlaybackSessionManager: [0xac3d3a18]: Starting playback session maintenance Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.714 [3756.3756] INFO HttpDownloader: [0xac3d3bc0]: Downloading content from: https://www.qobuz.com/api.json/0.2/session/start Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.714 [3756.3756] INFO CloudClient: [0xac3d40e8]: Connecting to the cloud Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.715 [3756.3756] INFO SampleApp: Renderer is now active Aug 29 18:06:03 rivomusique volumio[3261]: info: Remote SSH Stopped Aug 29 18:06:04 rivomusique volumio[3261]: error: Cannot start Volumio Streaming Daemon Aug 29 18:06:04 rivomusique volumio[3261]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 29 18:06:04 rivomusique volumio[3261]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.287 [3756.3756] INFO CloudClient: [0xac3d40e8]: Connection established Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.287 [3756.3756] INFO QwspMessageSender: [0xac4bea08]: Sending Authenticate message Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.288 [3756.3756] INFO QwspMessageSender: [0xac4bea08]: Sending Subscribe message Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.288 [3756.3756] INFO QConnectMessageSender: [0xac4bea18]: Sending JoinSession message Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.288 [3756.3756] INFO QConnectMessageSender: [0xac4bea18]: Sending VolumeChanged message Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.288 [3756.3756] INFO QConnectMessageSender: [0xac4bea18]: Sending VolumeMuted message Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.288 [3756.3756] INFO QConnectMessageSender: [0xac4bea18]: Sending MaxAudioQualityChanged message Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.288 [3756.3756] INFO QwspMessageSender: [0xac4bea08]: Sending Payload message Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.312 [3756.3756] INFO ProtocolHandler: [0xac3d41f8]: Received SetActive message: active Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.312 [3756.3756] INFO ProtocolHandler: [0xac3d41f8]: Received SetState message: Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.312 [3756.3756] INFO ProtocolHandler: [0xac3d41f8]: Playing state: Paused Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.312 [3756.3756] INFO ProtocolHandler: [0xac3d41f8]: Playback position: 134476 Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.312 [3756.3756] INFO ProtocolHandler: [0xac3d41f8]: Queue version: 5.1 Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.312 [3756.3756] INFO ProtocolHandler: [0xac3d41f8]: Current track: TID: 60017488, QID: 9, Context UUID: c9baf244-0e7a-4a09-b1c4-165766954412 Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.312 [3756.3756] INFO ProtocolHandler: [0xac3d41f8]: Next track: TID: 60017489, QID: 10, Context UUID: c9baf244-0e7a-4a09-b1c4-165766954412 Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.312 [3756.3756] INFO MediaEngine: [0xac3d3c20]: Stopping playback, clearing tracks Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.312 [3756.3756] INFO MediaEngine: [0xac3d3c20]: Initiating playback Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.313 [3756.3756] INFO RendererActionAvailabilityManager: [0xac3d4158]: Renderer action 'Next' is available Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.313 [3756.3756] INFO ProtocolHandler: [0xac3d41f8]: Received SetLoopMode message: Off Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.313 [3756.3756] INFO PlaybackModeManager: [0xac3d3ee8]: Setting new loop mode: Off Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.313 [3756.3756] INFO MediaEngine: [0xac3d3c20]: Setting current track: 60017488, initial offset: 134476ms Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.313 [3756.3756] INFO AudioStreamManager: [0xac3d3cd0]: Clearing all streams Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.313 [3756.3756] INFO AudioStreamManager: [0xac3d3cd0]: New stream: 1 Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.313 [3756.3756] INFO HttpDownloader: [0xac4bfbf0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=4ac7bf90630809a53ef14cab64d77bc0&request_ts=1787994364&track_id=60017488 Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.313 [3756.3756] INFO HttpDownloader: [0xac515170]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=60017488 Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.313 [3756.3756] INFO AudioStreamManager: [0xac3d3cd0]: [Stream 1]: Running audio stream Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.314 [3756.3756] INFO ProtocolHandler: [0xac3d41f8]: Received SetShuffleMode message: disabled Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.314 [3756.3756] INFO PlaybackModeManager: [0xac3d3ee8]: Setting new shuffle mode: disabled Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.315 [3756.3756] INFO MediaEngine: [0xac3d3c20]: Setting next track: 60017489 Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.315 [3756.3756] INFO AudioStreamManager: [0xac3d3cd0]: New stream: 2 Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.315 [3756.3756] INFO HttpDownloader: [0xac4fffd0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=4c8bb7854e05c51c41a61a9708e941af&request_ts=1787994364&track_id=60017489 Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.315 [3756.3756] INFO HttpDownloader: [0xac4fb860]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=60017489 Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.316 [3756.3756] INFO MediaEngine: [0xac3d3c20]: Waiting for current stream to start before starting audio renderer Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.410 [3756.3756] INFO PlaybackSessionManager: [0xac3d3a18]: Playback session has been refreshed Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.410 [3756.3756] INFO HttpDownloader: [0xac50b738]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=5188537c5f497d38874a87f40119c910&request_ts=1787994364&track_id=60017488 Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.410 [3756.3756] INFO HttpDownloader: [0xac57fa30]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=fc22c5db88f2fd9c6ae1e22edad94daa&request_ts=1787994364&track_id=60017489 Aug 29 18:06:03 rivomusique ntpd[4581]: receive: Unexpected origin timestamp 0xee3d1f7c.7fc0ac9f does not match aorg 0000000000.00000000 from server@142.91.105.55 xmt 0xee3d1f7b.6e6c073e Aug 29 18:06:03 rivomusique ntpd[4581]: receive: Unexpected origin timestamp 0xee3d1f7c.7fc3094d does not match aorg 0000000000.00000000 from server@162.159.200.123 xmt 0xee3d1f7b.6e816940 Aug 29 18:06:03 rivomusique ntpd[4581]: receive: Unexpected origin timestamp 0xee3d1f7c.7fc7c245 does not match aorg 0000000000.00000000 from server@162.159.200.1 xmt 0xee3d1f7b.6de5e646 Aug 29 18:06:03 rivomusique ntpd[4581]: receive: Unexpected origin timestamp 0xee3d1f7c.7fb45db6 does not match aorg 0000000000.00000000 from server@167.179.119.205 xmt 0xee3d1f7b.6f5b3b26 Aug 29 18:06:03 rivomusique volumio[3261]: error: Failed to ping endpoint us4.myvolumio.org : unknown error Aug 29 18:06:03 rivomusique volumio[3261]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 18:06:03 rivomusique volumio[3261]: Error: Unable to resolve or reject the same promise twice Aug 29 18:06:03 rivomusique volumio[3261]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Aug 29 18:06:03 rivomusique volumio[3261]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32086) Aug 29 18:06:03 rivomusique volumio[3261]: at Socket.emit (events.js:412:35) Aug 29 18:06:03 rivomusique volumio[3261]: at endReadableNT (internal/streams/readable.js:1333:12) Aug 29 18:06:03 rivomusique volumio[3261]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Aug 29 18:06:03 rivomusique volumio[3261]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.518 [3756.3756] INFO AudioStreamManager: [0xac3d3cd0]: [Stream 1]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=6386560&eid=60017488&fmt=6&profile=raw&app_id=174516466&cid=3063770&etsp=1787997963&hmac=Awk15REqvH6K8Av9Qd-FMVctLf4 Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.555 [3756.3756] INFO AudioStreamManager: [0xac3d3cd0]: [Stream 2]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=6386560&eid=60017489&fmt=6&profile=raw&app_id=174516466&cid=3063770&etsp=1787997963&hmac=M4cvbhqW3-va7-nzfYy9jiVlTz8 Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.563 [3756.3756] INFO AudioStreamManager: [0xac3d3cd0]: [Stream 2]: Metadata became available: Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.563 [3756.3756] INFO AudioStreamManager: [0xac3d3cd0]: Title: Caprices No. 11 for Solo Violin in C Major, Op. 1 Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.563 [3756.3756] INFO AudioStreamManager: [0xac3d3cd0]: Artist: Sergei Stadler Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.563 [3756.3756] INFO AudioStreamManager: [0xac3d3cd0]: Album: Paganini: Caprices for Violin & Violin Concerto No. 1 Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.563 [3756.3756] INFO AudioStreamManager: [0xac3d3cd0]: Album art URL: https://static.qobuz.com/images/covers/fb/st/p9gievtxmstfb_600.jpg Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.584 [3756.3756] INFO AudioStreamManager: [0xac3d3cd0]: [Stream 1]: Metadata became available: Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.584 [3756.3756] INFO AudioStreamManager: [0xac3d3cd0]: Title: Caprices No. 10 for Solo Violin in G Minor, Op. 1 Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.584 [3756.3756] INFO AudioStreamManager: [0xac3d3cd0]: Artist: Sergei Stadler Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.584 [3756.3756] INFO AudioStreamManager: [0xac3d3cd0]: Album: Paganini: Caprices for Violin & Violin Concerto No. 1 Aug 29 18:06:03 rivomusique qobuz-connect[3756]: 20260829 18:06:03.584 [3756.3756] INFO AudioStreamManager: [0xac3d3cd0]: Album art URL: https://static.qobuz.com/images/covers/fb/st/p9gievtxmstfb_600.jpg Aug 29 18:06:04 rivomusique sudo[4752]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-08-29 18:05 Aug 29 18:06:04 rivomusique sudo[4752]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.207 [3756.3756] INFO AudioStreamManager: [0xac3d3cd0]: [Stream 1]: stream information have been fetched Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.207 [3756.3756] INFO UrlAudioSource: [0xac4bfcd0]: Starting URL audio source, initial position: 134476ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=6386560&eid=60017488&fmt=6&profile=raw&app_id=174516466&cid=3063770&etsp=1787997963&hmac=Awk15REqvH6K8Av9Qd-FMVctLf4 Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.207 [3756.3756] INFO ContentFetcher: [0xac3d99b0]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=6386560&eid=60017488&fmt=6&profile=raw&app_id=174516466&cid=3063770&etsp=1787997963&hmac=Awk15REqvH6K8Av9Qd-FMVctLf4, offset: 0 Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.207 [3756.3756] INFO AudioRenderer: [0xac3d3d88]: Starting audio renderer, initial playback state: Paused Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.207 [3756.3756] INFO SampleApp: [Stream 1]: New audio stream (starting from 134475ms) Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.208 [3756.3756] INFO SampleApp: [Stream 1]: Stream metadata became available: Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.208 [3756.3756] INFO SampleApp: Title: Caprices No. 10 for Solo Violin in G Minor, Op. 1 Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.208 [3756.3756] INFO SampleApp: Artist: Sergei Stadler Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.208 [3756.3756] INFO SampleApp: Album: Paganini: Caprices for Violin & Violin Concerto No. 1 Aug 29 18:06:04 rivomusique qobuz-connect[3756]: 20260829 18:06:04.208 [3756.3756] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/fb/st/p9gievtxmstfb_600.jpg 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="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 11:38:48 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="8e381701610c2a79deb52e712150c089"