-- Logs begin at Thu 2026-03-05 20:59:21 AEDT, end at Sun 2026-03-29 18:19:09 AEDT. -- Mar 29 18:18:21 rivoplus volumio[3103]: info: Mar 29 18:18:21 rivoplus volumio[3103]: ---------------------------- MPD announces state update: player Mar 29 18:18:21 rivoplus volumio[3103]: info: ControllerMpd::getState Mar 29 18:18:21 rivoplus volumio[3103]: verbose: ControllerMpd::sendMpdCommand status Mar 29 18:18:21 rivoplus volumio[3103]: info: sendMpdCommand status took 2 milliseconds Mar 29 18:18:21 rivoplus volumio[3103]: verbose: ControllerMpd::parseState Mar 29 18:18:21 rivoplus volumio[3103]: info: ControllerMpd::pushState Mar 29 18:18:21 rivoplus volumio[3103]: info: CoreCommandRouter::servicePushState Mar 29 18:18:21 rivoplus volumio[3103]: info: CoreStateMachine::pushState Mar 29 18:18:21 rivoplus volumio[3103]: info: CoreCommandRouter::volumioPushState Mar 29 18:18:21 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:18:21 rivoplus volumio[3103]: info: CorePlayQueue::getTrack 0 Mar 29 18:18:21 rivoplus volumio[3103]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Mar 29 18:18:21 rivoplus volumio[3103]: verbose: CURRENT POSITION 0 Mar 29 18:18:21 rivoplus volumio[3103]: info: CoreStateMachine::syncState stateService stop Mar 29 18:18:21 rivoplus volumio[3103]: info: CoreStateMachine::syncState currentStatus play Mar 29 18:18:21 rivoplus volumio[3103]: info: CoreCommandRouter::volumioPushState Mar 29 18:18:21 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:18:21 rivoplus volumio[3103]: info: CoreStateMachine::stPlaybackTimer Mar 29 18:18:21 rivoplus volumio[3103]: info: ------------------------------ 20ms Mar 29 18:18:21 rivoplus volumio[3103]: info: Signalling Playback active due to playback status change Mar 29 18:18:21 rivoplus volumio[3103]: info: MCU Signalled Playback Inactive Mar 29 18:18:27 rivoplus volumio[3103]: error: Upnp client error: Error: This socket has been ended by the other party Mar 29 18:18:43 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:43.383+11:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.165:49164 Mar 29 18:18:43 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:43.580+11:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.165:49164 @ 0x1d94c30" latency=10.073683ms timeout=10s Mar 29 18:18:43 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:43.580+11:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" Mar 29 18:18:43 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:43.580+11:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.165:49164 @ 0x1d94c30" latency=10.950558ms platform=PLATFORM_IOS version=5.260209.0 Mar 29 18:18:43 rivoplus volumio[3103]: info: Received Get System Info Mar 29 18:18:43 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 29 18:18:43 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 29 18:18:43 rivoplus volumio[3103]: info: Discovery: Getting this device information Mar 29 18:18:43 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:18:43 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 29 18:18:43 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 29 18:18:43 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 29 18:18:43 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:43.589+11:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" name=Rivoplus Mar 29 18:18:43 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:43.593+11:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" language=en Mar 29 18:18:43 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Mar 29 18:18:43 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:43.597+11:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" timezone=Australia/Sydney Mar 29 18:18:43 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:43.599+11:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" available=true connected=true macAddress=02:00:00:03:25:01 ip4Address=192.168.1.171/24 ip6Address= Mar 29 18:18:43 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:43.602+11:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 29 18:18:43 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:43.603+11:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" setupComplete=true Mar 29 18:18:43 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Mar 29 18:18:43 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Mar 29 18:18:43 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 18:18:43 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 29 18:18:43 rivoplus volumio[3103]: amixer -c 1 info | grep "Comtrue-inc UAC2 Device" Mar 29 18:18:43 rivoplus volumio[3103]: Card hw:1 'Device'/'Comtrue-inc Comtrue-inc UAC2 Device at usb-xhci-hcd.0.auto-1.4.3, high speed' Mar 29 18:18:43 rivoplus volumio[3103]: amixer -c 5 info | grep "DENAFRIPS USB HiRes Audio" Mar 29 18:18:43 rivoplus volumio[3103]: Card hw:5 'Audio'/'DENAFRIPS DENAFRIPS USB HiRes Audio at usb-xhci-hcd.0.auto-1.4.2, high speed' Mar 29 18:18:43 rivoplus volumio[3103]: amixer -c 5 info | grep "DENAFRIPS USB HiRes Audio" Mar 29 18:18:44 rivoplus volumio[3103]: Card hw:5 'Audio'/'DENAFRIPS DENAFRIPS USB HiRes Audio at usb-xhci-hcd.0.auto-1.4.2, high speed' Mar 29 18:18:44 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:44.053+11:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" selectedOutputId=5 Mar 29 18:18:44 rivoplus volumio[3103]: info: Received Get System Info Mar 29 18:18:44 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 29 18:18:44 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 29 18:18:44 rivoplus volumio[3103]: info: Discovery: Getting this device information Mar 29 18:18:44 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:18:44 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 29 18:18:44 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:44.067+11:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" currentVersion=3.912 latestVersion=3.912 Mar 29 18:18:44 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:44.068+11:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" status=UPDATE_STATUS_NONE progress=0 Mar 29 18:18:44 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 29 18:18:44 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 29 18:18:45 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 29 18:18:45 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 29 18:18:45 rivoplus volumio[3103]: info: Discovery: Getting this device information Mar 29 18:18:45 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:18:45 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 29 18:18:45 rivoplus volumio[3103]: verbose: New Socket.io Connection to 192.168.1.171:3000 from 192.168.1.165 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Mar 29 18:18:45 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 29 18:18:45 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 29 18:18:45 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:45.755+11:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.165:49164 @ 0x1d94c30" latency=12.471661ms platform=PLATFORM_IOS version=5.260209.0 Mar 29 18:18:45 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:45.756+11:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.165:49164 @ 0x1d94c30" latency=13.896959ms timeout=10s Mar 29 18:18:45 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:45.756+11:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" Mar 29 18:18:45 rivoplus volumio[3103]: info: Received Get System Info Mar 29 18:18:45 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 29 18:18:45 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 29 18:18:45 rivoplus volumio[3103]: info: Discovery: Getting this device information Mar 29 18:18:45 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:18:45 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 29 18:18:45 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:45.762+11:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" name=Rivoplus Mar 29 18:18:45 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:45.763+11:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" language=en Mar 29 18:18:45 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Mar 29 18:18:45 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:45.766+11:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" timezone=Australia/Sydney Mar 29 18:18:45 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:45.768+11:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" available=true connected=true macAddress=02:00:00:03:25:01 ip4Address=192.168.1.171/24 ip6Address= Mar 29 18:18:45 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:45.769+11:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 29 18:18:45 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:45.770+11:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" setupComplete=true Mar 29 18:18:45 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Mar 29 18:18:45 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Mar 29 18:18:45 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 18:18:45 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 29 18:18:45 rivoplus volumio[3103]: amixer -c 1 info | grep "Comtrue-inc UAC2 Device" Mar 29 18:18:45 rivoplus volumio[3103]: Card hw:1 'Device'/'Comtrue-inc Comtrue-inc UAC2 Device at usb-xhci-hcd.0.auto-1.4.3, high speed' Mar 29 18:18:46 rivoplus volumio[3103]: amixer -c 5 info | grep "DENAFRIPS USB HiRes Audio" Mar 29 18:18:46 rivoplus volumio[3103]: Card hw:5 'Audio'/'DENAFRIPS DENAFRIPS USB HiRes Audio at usb-xhci-hcd.0.auto-1.4.2, high speed' Mar 29 18:18:46 rivoplus volumio[3103]: amixer -c 5 info | grep "DENAFRIPS USB HiRes Audio" Mar 29 18:18:46 rivoplus volumio[3103]: Card hw:5 'Audio'/'DENAFRIPS DENAFRIPS USB HiRes Audio at usb-xhci-hcd.0.auto-1.4.2, high speed' Mar 29 18:18:46 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:46.216+11:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" selectedOutputId=5 Mar 29 18:18:46 rivoplus volumio[3103]: info: Received Get System Info Mar 29 18:18:46 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 29 18:18:46 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 29 18:18:46 rivoplus volumio[3103]: info: Discovery: Getting this device information Mar 29 18:18:46 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:18:46 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 29 18:18:46 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:46.230+11:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" currentVersion=3.912 latestVersion=3.912 Mar 29 18:18:46 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:46.230+11:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" status=UPDATE_STATUS_NONE progress=0 Mar 29 18:18:46 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 29 18:18:46 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 29 18:18:46 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:46.370+11:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=NRUP0Zek3jYbdy06ourMS844fxh1 tokenExpiry=2026-03-29T19:18:46.370+11:00 Mar 29 18:18:47 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:47.424+11:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=NRUP0Zek3jYbdy06ourMS844fxh1 tokenExpiry=2026-03-29T19:18:47.424+11:00 Mar 29 18:18:48 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:48.186+11:00 level=INFO msg="emitting user changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" userId=NRUP0Zek3jYbdy06ourMS844fxh1 Mar 29 18:18:48 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 29 18:18:48 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 29 18:18:48 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 29 18:18:48 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:48.415+11:00 level=INFO msg="new address was allocated" component=ble/conn old=1 new=2 Mar 29 18:18:48 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:48.463+11:00 level=INFO msg="emitting user changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" userId=NRUP0Zek3jYbdy06ourMS844fxh1 Mar 29 18:18:48 rivoplus dbus-daemon[2854]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.21" (uid=0 pid=4107 comm="/usr/bin/volumio5-onboarding " label="kernel") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.7" (uid=0 pid=3296 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn" label="kernel") Mar 29 18:18:48 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:48.968+11:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=spotify error="could not open plugin config file for \"spop\": open /data/configuration/music_service/spop/config.json: no such file or directory" Mar 29 18:18:48 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:48.969+11:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" providers=9 Mar 29 18:18:48 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:48.970+11:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" providers=9 Mar 29 18:18:48 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 29 18:18:48 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 29 18:18:48 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 29 18:18:49 rivoplus dbus-daemon[2854]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.21" (uid=0 pid=4107 comm="/usr/bin/volumio5-onboarding " label="kernel") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.7" (uid=0 pid=3296 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn" label="kernel") Mar 29 18:18:49 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:49.362+11:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" plugins=26 Mar 29 18:18:49 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:18:49 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:49.367+11:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" state=STATUS_STOPPED positionMs= volume=41 Mar 29 18:18:49 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:18:49 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:49.368+11:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" id=http://192.168.1.36:49152/audirvana/gaplessAudio_f_11.wav title="Audirvana gapless playback" Mar 29 18:18:49 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:49.367+11:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" state=STATUS_STOPPED positionMs= volume=41 Mar 29 18:18:49 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:49.369+11:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" id=http://192.168.1.36:49152/audirvana/gaplessAudio_f_11.wav title="Audirvana gapless playback" Mar 29 18:18:49 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:49.371+11:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" state=STATUS_STOPPED positionMs= volume=41 Mar 29 18:18:49 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:49.371+11:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.165:49164 @ 0x1d94c30" id=http://192.168.1.36:49152/audirvana/gaplessAudio_f_11.wav title="Audirvana gapless playback" Mar 29 18:18:49 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:49.390+11:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.165:49164 @ 0x1d94c30" latency=8.407654ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Mar 29 18:18:52 rivoplus sudo[15645]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 29 18:18:52 rivoplus sudo[15645]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 29 18:18:52 rivoplus sudo[15645]: pam_unix(sudo:session): session closed for user root Mar 29 18:18:52 rivoplus sudo[15647]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 29 18:18:52 rivoplus sudo[15647]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 29 18:18:52 rivoplus sudo[15647]: pam_unix(sudo:session): session closed for user root Mar 29 18:18:52 rivoplus volumio[3103]: verbose: New Socket.io Connection to 192.168.1.171 from 192.168.1.165 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: 7 Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetVisibleSources Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 29 18:18:52 rivoplus volumio[3103]: info: Received Get System Info Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 29 18:18:52 rivoplus volumio[3103]: info: Discovery: Getting this device information Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:18:52 rivoplus volumio[3103]: info: Listing playlists Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 29 18:18:52 rivoplus sudo[15655]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 29 18:18:52 rivoplus sudo[15655]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 29 18:18:52 rivoplus sudo[15655]: pam_unix(sudo:session): session closed for user root Mar 29 18:18:52 rivoplus sudo[15658]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 29 18:18:52 rivoplus sudo[15658]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 29 18:18:52 rivoplus sudo[15658]: pam_unix(sudo:session): session closed for user root Mar 29 18:18:52 rivoplus volumio[3103]: verbose: New Socket.io Connection to 192.168.1.171 from 192.168.1.165 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: 8 Mar 29 18:18:52 rivoplus volumio[3103]: info: Executing endpoint metavolumio Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 29 18:18:52 rivoplus volumio[3103]: info: Executing endpoint metavolumio Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetVisibleSources Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetQueue Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreStateMachine::getQueue Mar 29 18:18:52 rivoplus volumio[3103]: info: CorePlayQueue::getQueue Mar 29 18:18:52 rivoplus volumio[3103]: info: Listing playlists Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 29 18:18:52 rivoplus volumio[3103]: info: Received Get System Info Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 29 18:18:52 rivoplus volumio[3103]: info: Discovery: Getting this device information Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 29 18:18:52 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 29 18:18:54 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Mar 29 18:18:54 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 29 18:18:54 rivoplus volumio[3103]: info: Received Get System Info Mar 29 18:18:54 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 29 18:18:54 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 29 18:18:54 rivoplus volumio[3103]: info: Discovery: Getting this device information Mar 29 18:18:54 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:18:54 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 29 18:18:54 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 29 18:18:54 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:18:54.519+11:00 level=INFO msg="new address was allocated" component=ble/conn old=2 new=3 Mar 29 18:18:54 rivoplus dbus-daemon[2854]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.21" (uid=0 pid=4107 comm="/usr/bin/volumio5-onboarding " label="kernel") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.7" (uid=0 pid=3296 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn" label="kernel") Mar 29 18:18:55 rivoplus dbus-daemon[2854]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.21" (uid=0 pid=4107 comm="/usr/bin/volumio5-onboarding " label="kernel") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.7" (uid=0 pid=3296 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn" label="kernel") Mar 29 18:18:57 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 29 18:18:57 rivoplus volumio[3103]: info: Received Get System Info Mar 29 18:18:57 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 29 18:18:57 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 29 18:18:57 rivoplus volumio[3103]: info: Discovery: Getting this device information Mar 29 18:18:57 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:18:57 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 29 18:18:58 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 29 18:18:58 rivoplus volumio[3103]: info: Received Get System Info Mar 29 18:18:58 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 29 18:18:58 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 29 18:18:58 rivoplus volumio[3103]: info: Discovery: Getting this device information Mar 29 18:18:58 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:18:58 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 29 18:18:59 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetState Mar 29 18:19:01 rivoplus volumio[3103]: info: Executing endpoint metavolumio Mar 29 18:19:01 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 29 18:19:01 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:19:01.840+11:00 level=INFO msg="new address was allocated" component=ble/conn old=3 new=4 Mar 29 18:19:02 rivoplus dbus-daemon[2854]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.21" (uid=0 pid=4107 comm="/usr/bin/volumio5-onboarding " label="kernel") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.7" (uid=0 pid=3296 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn" label="kernel") Mar 29 18:19:02 rivoplus dbus-daemon[2854]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.21" (uid=0 pid=4107 comm="/usr/bin/volumio5-onboarding " label="kernel") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.7" (uid=0 pid=3296 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn" label="kernel") Mar 29 18:19:02 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 29 18:19:04 rivoplus volumio[3103]: info: Retrieving Cloud Streaming UI Mar 29 18:19:04 rivoplus volumio[3103]: info: Getting Tidal Cloud Configuration Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 29 18:19:04 rivoplus volumio[3103]: info: Getting Qobuz Cloud Configuration Mar 29 18:19:04 rivoplus volumio[3103]: info: Asking plugin for UI Config Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 29 18:19:04 rivoplus volumio[3103]: info: Getting Spotify Cloud Configuration Mar 29 18:19:04 rivoplus volumio[3103]: info: Asking plugin for UI Config Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 29 18:19:04 rivoplus volumio[3103]: info: Saving Spotify Acccount Mar 29 18:19:04 rivoplus volumio[3103]: info: Got it Mar 29 18:19:04 rivoplus volumio[3103]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Mar 29 18:19:04 rivoplus volumio[3103]: info: Got Tidal Cloud Configuration Mar 29 18:19:04 rivoplus volumio[3103]: info: Got it Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetBrowseSources Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetBrowseSources Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::volumioGetBrowseSources Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 29 18:19:04 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Mar 29 18:19:07 rivoplus volumio5-onboarding[4107]: time=2026-03-29T18:19:07.079+11:00 level=INFO msg="new address was allocated" component=ble/conn old=4 new=5 Mar 29 18:19:07 rivoplus dbus-daemon[2854]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.21" (uid=0 pid=4107 comm="/usr/bin/volumio5-onboarding " label="kernel") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.7" (uid=0 pid=3296 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn" label="kernel") Mar 29 18:19:07 rivoplus dbus-daemon[2854]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.21" (uid=0 pid=4107 comm="/usr/bin/volumio5-onboarding " label="kernel") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.7" (uid=0 pid=3296 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn" label="kernel") Mar 29 18:19:07 rivoplus volumio[3103]: info: Disabling MyMusic plugin upnp Mar 29 18:19:07 rivoplus sudo[15756]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Mar 29 18:19:07 rivoplus sudo[15756]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 29 18:19:07 rivoplus systemd[1]: Stopping UPnP Renderer front-end to MPD... Mar 29 18:19:07 rivoplus volumio[3103]: error: Upnp client error: Error: This socket has been ended by the other party Mar 29 18:19:08 rivoplus volumio[3103]: info: Enabling MyMusic plugin upnp Mar 29 18:19:08 rivoplus volumio[3103]: info: Enabling plugin upnp Mar 29 18:19:08 rivoplus volumio[3103]: info: Loading plugin "upnp"... Mar 29 18:19:08 rivoplus volumio[3103]: info: [1774768748716] Starting Upmpd Daemon Mar 29 18:19:08 rivoplus volumio[3103]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 29 18:19:08 rivoplus volumio[3103]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 29 18:19:08 rivoplus volumio[3103]: Error: listen EADDRINUSE: address already in use :::6599 Mar 29 18:19:08 rivoplus volumio[3103]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Mar 29 18:19:08 rivoplus volumio[3103]: at listenInCluster (net.js:1379:12) Mar 29 18:19:08 rivoplus volumio[3103]: at Server.listen (net.js:1465:7) Mar 29 18:19:08 rivoplus volumio[3103]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Mar 29 18:19:08 rivoplus volumio[3103]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Mar 29 18:19:08 rivoplus volumio[3103]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Mar 29 18:19:08 rivoplus volumio[3103]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 29 18:19:08 rivoplus volumio[3103]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Mar 29 18:19:08 rivoplus volumio[3103]: code: 'EADDRINUSE', Mar 29 18:19:08 rivoplus volumio[3103]: errno: -98, Mar 29 18:19:08 rivoplus volumio[3103]: syscall: 'listen', Mar 29 18:19:08 rivoplus volumio[3103]: address: '::', Mar 29 18:19:08 rivoplus volumio[3103]: port: 6599 Mar 29 18:19:08 rivoplus volumio[3103]: } Mar 29 18:19:08 rivoplus volumio[3103]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 29 18:19:09 rivoplus sudo[15769]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-03-29 18:18 Mar 29 18:19:09 rivoplus sudo[15769]: 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"