Oct 15 11:09:00 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:00.332+02:00 level=ERROR msg="failed to read message" component=conn/ws remoteAddr=192.168.100.40:33066 error="websocket: close 1006 (abnormal closure): unexpected EOF" Oct 15 11:09:00 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:00.333+02:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.100.40:33066 Oct 15 11:09:00 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:00.333+02:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.100.40:33066 Oct 15 11:09:00 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:00.812+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.100.40:51064 Oct 15 11:09:00 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:00.967+02:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.100.40:51064 @ 0x247e8d0" latency=169.905011ms platform=PLATFORM_ANDROID version=6.260930.0 Oct 15 11:09:00 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:00.967+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.100.40:51064 @ 0x247e8d0" latency=170.355722ms timeout=20s included=[] excluded=[] Oct 15 11:09:00 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:00.967+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" Oct 15 11:09:00 rivoplus volumio[3566]: info: Received Get System Info Oct 15 11:09:00 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 11:09:00 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 11:09:00 rivoplus volumio[3566]: info: Discovery: Getting this device information Oct 15 11:09:00 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:00 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 11:09:00 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:00.974+02:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" name=Rivoplus Oct 15 11:09:00 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:00.976+02:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" language=pl Oct 15 11:09:00 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Oct 15 11:09:00 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:00.980+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" timezone=Europe/Warsaw Oct 15 11:09:00 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:00.982+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" available=true connected=true macAddress=02:00:00:27:29:01 ip4Address=192.168.100.41/24 ip6Address= Oct 15 11:09:00 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:00.985+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Oct 15 11:09:00 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:00.985+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" setupComplete=true Oct 15 11:09:00 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 11:09:00 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 11:09:00 rivoplus volumio[3566]: info: Discovery: Getting this device information Oct 15 11:09:00 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:00 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 11:09:00 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Oct 15 11:09:01 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 15 11:09:01 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 11:09:01 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 11:09:01 rivoplus volumio[3566]: amixer -c 5 info | grep "Comtrue-inc UAC2 Device" Oct 15 11:09:01 rivoplus volumio[3566]: Card sysdefault:5 'Device'/'Comtrue-inc Comtrue-inc UAC2 Device at usb-xhci-hcd.0.auto-1.4.3, high speed' Oct 15 11:09:01 rivoplus volumio[3566]: Invalid card number '1'. Oct 15 11:09:01 rivoplus volumio[3566]: amixer -c 1 info | grep "WooAudio" Oct 15 11:09:01 rivoplus volumio[3566]: Invalid card number '1'. Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.117+02:00 level=WARN msg="active output device not found in available devices" component=volumio/socket activeDeviceId=1 Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.117+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" selectedOutputId=1 Oct 15 11:09:01 rivoplus volumio[3566]: verbose: New Socket.io Connection to 192.168.100.41:3000 from 192.168.100.40 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Oct 15 11:09:01 rivoplus volumio[3566]: info: Received Get System Info Oct 15 11:09:01 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 11:09:01 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 11:09:01 rivoplus volumio[3566]: info: Discovery: Getting this device information Oct 15 11:09:01 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:01 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.135+02:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" currentVersion=4.208 latestVersion=4.208 Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.136+02:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" status=UPDATE_STATUS_NONE progress=0 Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.136+02:00 level=INFO msg="emitting user changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" userId= Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.136+02:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" providers=3 Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.137+02:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" plugins=28 Oct 15 11:09:01 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 15 11:09:01 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 15 11:09:01 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.143+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.143+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=8583 volume=100 Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.143+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" id= title= Oct 15 11:09:01 rivoplus bluealsa[3448]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_83_06_A5_69_D9/mcp/player0, ...) Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.715+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.100.40:51064 @ 0x247e8d0" latency=76.190351ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.728+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:51064 @ 0x247e8d0" latency=74.483842ms timeout=10s Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.756+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:51064 @ 0x247e8d0" latency=74.483842ms timeout=10s endpoint=http://pushupdates.volumio.org duration=26.779091ms Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.759+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:51064 @ 0x247e8d0" latency=74.483842ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=30.939284ms Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.764+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:51064 @ 0x247e8d0" latency=74.483842ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=35.221938ms Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.770+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:51064 @ 0x247e8d0" latency=74.483842ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=40.615598ms Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.800+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:51064 @ 0x247e8d0" latency=74.483842ms timeout=10s endpoint=http://cddb.volumio.org duration=71.475257ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.843+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:51064 @ 0x247e8d0" latency=74.483842ms timeout=10s endpoint=https://www.googleapis.com duration=114.0547ms Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.867+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:51064 @ 0x247e8d0" latency=74.483842ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=138.819112ms Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.875+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:51064 @ 0x247e8d0" latency=74.483842ms timeout=10s endpoint=https://securetoken.googleapis.com duration=146.191243ms Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.877+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:51064 @ 0x247e8d0" latency=74.483842ms timeout=10s endpoint=https://functions.volumio.cloud duration=148.569301ms Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.880+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:51064 @ 0x247e8d0" latency=74.483842ms timeout=10s endpoint=https://database.volumio.cloud duration=150.460229ms Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.881+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:51064 @ 0x247e8d0" latency=74.483842ms timeout=10s endpoint=https://functions.volumio.cloud duration=152.54616ms Oct 15 11:09:01 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:01.889+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:51064 @ 0x247e8d0" latency=74.483842ms timeout=10s endpoint=http://plugins.volumio.org duration=160.300668ms Oct 15 11:09:02 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:02.030+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:51064 @ 0x247e8d0" latency=74.483842ms timeout=10s endpoint=https://google.com duration=301.049501ms Oct 15 11:09:02 rivoplus sudo[5136]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 15 11:09:02 rivoplus sudo[5137]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 15 11:09:02 rivoplus sudo[5136]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:09:02 rivoplus sudo[5137]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:09:02 rivoplus sudo[5137]: pam_unix(sudo:session): session closed for user root Oct 15 11:09:02 rivoplus sudo[5136]: pam_unix(sudo:session): session closed for user root Oct 15 11:09:02 rivoplus volumio[3566]: verbose: New Socket.io Connection to 192.168.100.41 from 192.168.100.40 UA: Mozilla/5.0 (Linux; Android 16; SM-S938B Build/BP4A.251205.006; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/154.0.8037.106 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 8 Oct 15 11:09:02 rivoplus sudo[5143]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 15 11:09:02 rivoplus sudo[5143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:09:02 rivoplus sudo[5145]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 15 11:09:02 rivoplus sudo[5145]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:09:02 rivoplus sudo[5143]: pam_unix(sudo:session): session closed for user root Oct 15 11:09:02 rivoplus sudo[5145]: pam_unix(sudo:session): session closed for user root Oct 15 11:09:02 rivoplus volumio[3566]: verbose: New Socket.io Connection to 192.168.100.41 from 192.168.100.40 UA: Mozilla/5.0 (Linux; Android 16; SM-S938B Build/BP4A.251205.006; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/154.0.8037.106 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 9 Oct 15 11:09:02 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 15 11:09:02 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetVisibleSources Oct 15 11:09:02 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 15 11:09:02 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:02 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 15 11:09:02 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 15 11:09:02 rivoplus volumio[3566]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 15 11:09:02 rivoplus volumio[3566]: info: Received Get System Info Oct 15 11:09:02 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 11:09:02 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 11:09:02 rivoplus volumio[3566]: info: Discovery: Getting this device information Oct 15 11:09:02 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:02 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 11:09:02 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:02 rivoplus volumio[3566]: info: Listing playlists Oct 15 11:09:02 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 15 11:09:02 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 15 11:09:02 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 15 11:09:03 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:03 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 15 11:09:03 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPlay Oct 15 11:09:03 rivoplus volumio[3566]: info: CoreStateMachine::play index undefined Oct 15 11:09:03 rivoplus volumio[3566]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 11:09:03 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:03 rivoplus volumio[3566]: info: CoreStateMachine::startPlaybackTimer Oct 15 11:09:03 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:03 rivoplus volumio[3566]: info: [1792055343796] ControllerTidal::clearAddPlayTrack Oct 15 11:09:03 rivoplus volumio[3566]: info: Getting stream with soundQuality HI_RES Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 15 11:09:04 rivoplus volumio[3566]: info: getStreamUrl took 346 milliseconds Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand stop Oct 15 11:09:04 rivoplus volumio[3566]: info: sendMpdCommand stop took 14 milliseconds Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand clear Oct 15 11:09:04 rivoplus volumio[3566]: info: Oct 15 11:09:04 rivoplus volumio[3566]: ---------------------------- MPD announces state update: player Oct 15 11:09:04 rivoplus volumio[3566]: info: Oct 15 11:09:04 rivoplus volumio[3566]: ---------------------------- MPD announces system playlist update Oct 15 11:09:04 rivoplus volumio[3566]: info: Ignoring MPD Status Update Oct 15 11:09:04 rivoplus volumio[3566]: info: ControllerMpd::getState Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand status Oct 15 11:09:04 rivoplus volumio[3566]: info: sendMpdCommand clear took 3 milliseconds Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidlODFmYTdhYTkyNzc5MjUxN2UzYWU4ZWJhNmM0NzExZV82MS5tcDQ/0.flac?token=1792058944~ZDA0OTRiNDIxYWNlOTgwOGJlM2Q4NzMyNTZlYjAxNGM1ZWEwMmEzNg==" Oct 15 11:09:04 rivoplus volumio[3566]: info: Oct 15 11:09:04 rivoplus volumio[3566]: ---------------------------- MPD announces state update: player Oct 15 11:09:04 rivoplus volumio[3566]: info: ControllerMpd::getState Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand status Oct 15 11:09:04 rivoplus volumio[3566]: error: updateQueue error: null Oct 15 11:09:04 rivoplus volumio[3566]: info: Oct 15 11:09:04 rivoplus volumio[3566]: ---------------------------- MPD announces system playlist update Oct 15 11:09:04 rivoplus volumio[3566]: info: Ignoring MPD Status Update Oct 15 11:09:04 rivoplus volumio[3566]: info: sendMpdCommand status took 7 milliseconds Oct 15 11:09:04 rivoplus volumio[3566]: info: ------------------------------ 8ms Oct 15 11:09:04 rivoplus volumio[3566]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidlODFmYTdhYTkyNzc5MjUxN2UzYWU4ZWJhNmM0NzExZV82MS5tcDQ/0.flac?token=1792058944~ZDA0OTRiNDIxYWNlOTgwOGJlM2Q4NzMyNTZlYjAxNGM1ZWEwMmEzNg==" took 6 milliseconds Oct 15 11:09:04 rivoplus volumio[3566]: info: sendMpdCommand status took 4 milliseconds Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::parseState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand play Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::parseState Oct 15 11:09:04 rivoplus volumio[3566]: info: ControllerMpd::pushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:04 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:04 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:04 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:04 rivoplus volumio[3566]: 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} Oct 15 11:09:04 rivoplus volumio[3566]: verbose: CURRENT POSITION 0 Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::syncState stateService stop Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::syncState currentStatus stop Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:04 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:04 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:04 rivoplus volumio[3566]: info: No code Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:04 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:04 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:04 rivoplus volumio[3566]: info: ControllerMpd::pushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:04 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:04 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:04 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:04 rivoplus volumio[3566]: 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} Oct 15 11:09:04 rivoplus volumio[3566]: verbose: CURRENT POSITION 0 Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::syncState stateService stop Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::syncState currentStatus stop Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:04 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:04 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:04 rivoplus volumio[3566]: info: No code Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:04 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:04 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:04 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:04.225+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:04 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:04.226+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=334 volume=100 Oct 15 11:09:04 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:04.227+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:04 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:04.227+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=334 volume=100 Oct 15 11:09:04 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:04.229+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:04 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:04.229+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=334 volume=100 Oct 15 11:09:04 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:04.230+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:04 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:04.230+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=334 volume=100 Oct 15 11:09:04 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:04.231+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:04 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:04.231+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=334 volume=100 Oct 15 11:09:04 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:04.232+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:04 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:04.232+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=334 volume=100 Oct 15 11:09:04 rivoplus volumio[3566]: info: ------------------------------ 113ms Oct 15 11:09:04 rivoplus volumio[3566]: info: ------------------------------ 111ms Oct 15 11:09:04 rivoplus volumio[3566]: info: Oct 15 11:09:04 rivoplus volumio[3566]: ---------------------------- MPD announces system playlist update Oct 15 11:09:04 rivoplus volumio[3566]: info: Ignoring MPD Status Update Oct 15 11:09:04 rivoplus volumio[3566]: info: Oct 15 11:09:04 rivoplus volumio[3566]: ---------------------------- MPD announces state update: player Oct 15 11:09:04 rivoplus volumio[3566]: info: Oct 15 11:09:04 rivoplus volumio[3566]: ---------------------------- MPD announces state update: player Oct 15 11:09:04 rivoplus volumio[3566]: info: ------------------------------ 117ms Oct 15 11:09:04 rivoplus volumio[3566]: info: sendMpdCommand play took 115 milliseconds Oct 15 11:09:04 rivoplus volumio[3566]: info: ControllerMpd::getState Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand status Oct 15 11:09:04 rivoplus volumio[3566]: info: ------------------------------ 12ms Oct 15 11:09:04 rivoplus volumio[3566]: info: ControllerMpd::getState Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand status Oct 15 11:09:04 rivoplus volumio[3566]: info: Oct 15 11:09:04 rivoplus volumio[3566]: ---------------------------- MPD announces state update: player Oct 15 11:09:04 rivoplus volumio[3566]: info: ControllerMpd::getState Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand status Oct 15 11:09:04 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:04 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:04 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:04 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:04 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:04 rivoplus volumio[3566]: error: MPD returned error for command status: Failed to open "alsa" (alsa); Failed to open ALSA device "volumio": No such device Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 15 11:09:04 rivoplus volumio[3566]: info: sendMpdCommand status took 116 milliseconds Oct 15 11:09:04 rivoplus volumio[3566]: error: MPD returned error for command status: Failed to open "alsa" (alsa); Failed to open ALSA device "volumio": No such device Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 15 11:09:04 rivoplus volumio[3566]: info: sendMpdCommand status took 119 milliseconds Oct 15 11:09:04 rivoplus volumio[3566]: error: MPD returned error for command status: Failed to open "alsa" (alsa); Failed to open ALSA device "volumio": No such device Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 15 11:09:04 rivoplus volumio[3566]: info: sendMpdCommand status took 117 milliseconds Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::parseState Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::parseState Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::parseState Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 15 11:09:04 rivoplus volumio[3566]: info: Received Get System Info Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 11:09:04 rivoplus volumio[3566]: info: Discovery: Getting this device information Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 11:09:04 rivoplus volumio[3566]: info: sendMpdCommand clearerror took 33 milliseconds Oct 15 11:09:04 rivoplus volumio[3566]: info: sendMpdCommand clearerror took 29 milliseconds Oct 15 11:09:04 rivoplus volumio[3566]: info: sendMpdCommand clearerror took 26 milliseconds Oct 15 11:09:04 rivoplus volumio[3566]: info: sendMpdCommand playlistinfo took 17 milliseconds Oct 15 11:09:04 rivoplus volumio[3566]: info: sendMpdCommand playlistinfo took 16 milliseconds Oct 15 11:09:04 rivoplus volumio[3566]: info: sendMpdCommand playlistinfo took 15 milliseconds Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::parseTrackInfo Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::parseTrackInfo Oct 15 11:09:04 rivoplus volumio[3566]: verbose: ControllerMpd::parseTrackInfo Oct 15 11:09:04 rivoplus volumio[3566]: info: ControllerMpd::pushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:04 rivoplus volumio[3566]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":218,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1792058944~ZDA0OTRiNDIxYWNlOTgwOGJlM2Q4NzMyNTZlYjAxNGM1ZWEwMmEzNg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidlODFmYTdhYTkyNzc5MjUxN2UzYWU4ZWJhNmM0NzExZV82MS5tcDQ/0.flac?token=1792058944~ZDA0OTRiNDIxYWNlOTgwOGJlM2Q4NzMyNTZlYjAxNGM1ZWEwMmEzNg==","trackType":"tidal"} Oct 15 11:09:04 rivoplus volumio[3566]: verbose: CURRENT POSITION 0 Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::syncState stateService pause Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::syncState currentStatus stop Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:04 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:04 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:04 rivoplus volumio[3566]: info: ControllerMpd::pushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:04 rivoplus volumio[3566]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":218,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1792058944~ZDA0OTRiNDIxYWNlOTgwOGJlM2Q4NzMyNTZlYjAxNGM1ZWEwMmEzNg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidlODFmYTdhYTkyNzc5MjUxN2UzYWU4ZWJhNmM0NzExZV82MS5tcDQ/0.flac?token=1792058944~ZDA0OTRiNDIxYWNlOTgwOGJlM2Q4NzMyNTZlYjAxNGM1ZWEwMmEzNg==","trackType":"tidal"} Oct 15 11:09:04 rivoplus volumio[3566]: verbose: CURRENT POSITION 0 Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::syncState stateService pause Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::syncState currentStatus stop Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:04 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:04 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:04 rivoplus volumio[3566]: info: ControllerMpd::pushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:04 rivoplus volumio[3566]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":218,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1792058944~ZDA0OTRiNDIxYWNlOTgwOGJlM2Q4NzMyNTZlYjAxNGM1ZWEwMmEzNg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidlODFmYTdhYTkyNzc5MjUxN2UzYWU4ZWJhNmM0NzExZV82MS5tcDQ/0.flac?token=1792058944~ZDA0OTRiNDIxYWNlOTgwOGJlM2Q4NzMyNTZlYjAxNGM1ZWEwMmEzNg==","trackType":"tidal"} Oct 15 11:09:04 rivoplus volumio[3566]: verbose: CURRENT POSITION 0 Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::syncState stateService pause Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::syncState currentStatus stop Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:04 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:04 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:04 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:04 rivoplus bluealsa[3448]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_83_06_A5_69_D9/mcp/player0, ...) Oct 15 11:09:04 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:04.486+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:04 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:04.486+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=602 volume=100 Oct 15 11:09:04 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:04.488+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:04 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:04.488+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=602 volume=100 Oct 15 11:09:04 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:04.489+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:04 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:04.489+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=602 volume=100 Oct 15 11:09:04 rivoplus volumio[3566]: info: ------------------------------ 224ms Oct 15 11:09:04 rivoplus volumio[3566]: info: ------------------------------ 224ms Oct 15 11:09:04 rivoplus volumio[3566]: info: ------------------------------ 213ms Oct 15 11:09:04 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:04 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:04 rivoplus volumio[3566]: ------------------------------------ BT MESSAGE: [_watchMediaPlayer] Binding player for path: /org/bluez/hci0/dev_9C_83_06_A5_69_D9/mcp/player0 mac: 9C:83:06:A5:69:D9 Oct 15 11:09:04 rivoplus volumio[3566]: ------------------------------------ BT MESSAGE: activePlayer bound: /org/bluez/hci0/dev_9C_83_06_A5_69_D9/mcp/player0 Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPlay Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::play index undefined Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 11:09:05 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::startPlaybackTimer Oct 15 11:09:05 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:05 rivoplus volumio[3566]: info: [1792055345095] ControllerTidal::clearAddPlayTrack Oct 15 11:09:05 rivoplus volumio[3566]: info: Getting stream with soundQuality HI_RES Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 15 11:09:05 rivoplus volumio[3566]: info: Received Get System Info Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 11:09:05 rivoplus volumio[3566]: info: Discovery: Getting this device information Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:05 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 11:09:05 rivoplus volumio[3566]: info: getStreamUrl took 209 milliseconds Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand stop Oct 15 11:09:05 rivoplus volumio[3566]: info: sendMpdCommand stop took 11 milliseconds Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand clear Oct 15 11:09:05 rivoplus volumio[3566]: info: Oct 15 11:09:05 rivoplus volumio[3566]: ---------------------------- MPD announces state update: player Oct 15 11:09:05 rivoplus volumio[3566]: info: Oct 15 11:09:05 rivoplus volumio[3566]: ---------------------------- MPD announces system playlist update Oct 15 11:09:05 rivoplus volumio[3566]: info: Ignoring MPD Status Update Oct 15 11:09:05 rivoplus volumio[3566]: info: ControllerMpd::getState Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand status Oct 15 11:09:05 rivoplus volumio[3566]: info: sendMpdCommand clear took 3 milliseconds Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidlODFmYTdhYTkyNzc5MjUxN2UzYWU4ZWJhNmM0NzExZV82MS5tcDQ/0.flac?token=1792058945~NTIxNTgwMTMxNTZjNDIxOWZiZDY2MjkzNGZlNmNjNThhMjNlNDJiYQ==" Oct 15 11:09:05 rivoplus volumio[3566]: info: Oct 15 11:09:05 rivoplus volumio[3566]: ---------------------------- MPD announces state update: player Oct 15 11:09:05 rivoplus volumio[3566]: info: ControllerMpd::getState Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand status Oct 15 11:09:05 rivoplus volumio[3566]: error: updateQueue error: null Oct 15 11:09:05 rivoplus volumio[3566]: info: Oct 15 11:09:05 rivoplus volumio[3566]: ---------------------------- MPD announces system playlist update Oct 15 11:09:05 rivoplus volumio[3566]: info: Ignoring MPD Status Update Oct 15 11:09:05 rivoplus volumio[3566]: info: sendMpdCommand status took 6 milliseconds Oct 15 11:09:05 rivoplus volumio[3566]: info: ------------------------------ 8ms Oct 15 11:09:05 rivoplus volumio[3566]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidlODFmYTdhYTkyNzc5MjUxN2UzYWU4ZWJhNmM0NzExZV82MS5tcDQ/0.flac?token=1792058945~NTIxNTgwMTMxNTZjNDIxOWZiZDY2MjkzNGZlNmNjNThhMjNlNDJiYQ==" took 5 milliseconds Oct 15 11:09:05 rivoplus volumio[3566]: info: sendMpdCommand status took 3 milliseconds Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::parseState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand play Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::parseState Oct 15 11:09:05 rivoplus volumio[3566]: info: ControllerMpd::pushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:05 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:05 rivoplus volumio[3566]: 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} Oct 15 11:09:05 rivoplus volumio[3566]: verbose: CURRENT POSITION 0 Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::syncState stateService stop Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::syncState currentStatus stop Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:05 rivoplus volumio[3566]: info: No code Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:05 rivoplus volumio[3566]: info: ControllerMpd::pushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:05 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:05 rivoplus volumio[3566]: 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} Oct 15 11:09:05 rivoplus volumio[3566]: verbose: CURRENT POSITION 0 Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::syncState stateService stop Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::syncState currentStatus stop Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:05 rivoplus volumio[3566]: info: No code Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.377+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.377+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=54 volume=100 Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.379+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.379+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=54 volume=100 Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.380+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.381+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=54 volume=100 Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.382+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.382+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=54 volume=100 Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.383+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.383+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=54 volume=100 Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.384+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.384+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=54 volume=100 Oct 15 11:09:05 rivoplus volumio[3566]: info: ------------------------------ 93ms Oct 15 11:09:05 rivoplus volumio[3566]: info: ------------------------------ 90ms Oct 15 11:09:05 rivoplus volumio[3566]: info: Oct 15 11:09:05 rivoplus volumio[3566]: ---------------------------- MPD announces system playlist update Oct 15 11:09:05 rivoplus volumio[3566]: info: Ignoring MPD Status Update Oct 15 11:09:05 rivoplus volumio[3566]: info: ------------------------------ 94ms Oct 15 11:09:05 rivoplus volumio[3566]: info: sendMpdCommand play took 91 milliseconds Oct 15 11:09:05 rivoplus volumio[3566]: info: ------------------------------ 6ms Oct 15 11:09:05 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:05 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:05 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:05 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:05 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:05 rivoplus volumio[3566]: info: Oct 15 11:09:05 rivoplus volumio[3566]: ---------------------------- MPD announces state update: player Oct 15 11:09:05 rivoplus volumio[3566]: info: ControllerMpd::getState Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand status Oct 15 11:09:05 rivoplus volumio[3566]: info: Oct 15 11:09:05 rivoplus volumio[3566]: ---------------------------- MPD announces state update: player Oct 15 11:09:05 rivoplus volumio[3566]: info: ControllerMpd::getState Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand status Oct 15 11:09:05 rivoplus volumio[3566]: info: Oct 15 11:09:05 rivoplus volumio[3566]: ---------------------------- MPD announces state update: player Oct 15 11:09:05 rivoplus volumio[3566]: info: ControllerMpd::getState Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand status Oct 15 11:09:05 rivoplus volumio[3566]: error: MPD returned error for command status: Failed to open "alsa" (alsa); Failed to open ALSA device "volumio": No such device Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 15 11:09:05 rivoplus volumio[3566]: info: sendMpdCommand status took 12 milliseconds Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::parseState Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 11:09:05 rivoplus volumio[3566]: info: Oct 15 11:09:05 rivoplus volumio[3566]: ---------------------------- MPD announces state update: player Oct 15 11:09:05 rivoplus volumio[3566]: info: ControllerMpd::getState Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand status Oct 15 11:09:05 rivoplus volumio[3566]: error: MPD returned error for command status: Failed to open "alsa" (alsa); Failed to open ALSA device "volumio": No such device Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 15 11:09:05 rivoplus volumio[3566]: info: sendMpdCommand status took 24 milliseconds Oct 15 11:09:05 rivoplus volumio[3566]: error: MPD returned error for command status: Failed to open "alsa" (alsa); Failed to open ALSA device "volumio": No such device Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 15 11:09:05 rivoplus volumio[3566]: info: sendMpdCommand status took 26 milliseconds Oct 15 11:09:05 rivoplus volumio[3566]: info: sendMpdCommand clearerror took 21 milliseconds Oct 15 11:09:05 rivoplus volumio[3566]: info: sendMpdCommand playlistinfo took 18 milliseconds Oct 15 11:09:05 rivoplus volumio[3566]: info: sendMpdCommand status took 17 milliseconds Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::parseState Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::parseState Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::parseTrackInfo Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::parseState Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 11:09:05 rivoplus volumio[3566]: info: ControllerMpd::pushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:05 rivoplus volumio[3566]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":218,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1792058945~NTIxNTgwMTMxNTZjNDIxOWZiZDY2MjkzNGZlNmNjNThhMjNlNDJiYQ==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidlODFmYTdhYTkyNzc5MjUxN2UzYWU4ZWJhNmM0NzExZV82MS5tcDQ/0.flac?token=1792058945~NTIxNTgwMTMxNTZjNDIxOWZiZDY2MjkzNGZlNmNjNThhMjNlNDJiYQ==","trackType":"tidal"} Oct 15 11:09:05 rivoplus volumio[3566]: verbose: CURRENT POSITION 0 Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::syncState stateService pause Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::syncState currentStatus stop Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.554+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.554+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=323 volume=100 Oct 15 11:09:05 rivoplus volumio[3566]: info: ------------------------------ 86ms Oct 15 11:09:05 rivoplus volumio[3566]: info: sendMpdCommand clearerror took 81 milliseconds Oct 15 11:09:05 rivoplus volumio[3566]: info: sendMpdCommand clearerror took 77 milliseconds Oct 15 11:09:05 rivoplus volumio[3566]: info: sendMpdCommand playlistinfo took 68 milliseconds Oct 15 11:09:05 rivoplus volumio[3566]: info: sendMpdCommand playlistinfo took 67 milliseconds Oct 15 11:09:05 rivoplus volumio[3566]: info: sendMpdCommand playlistinfo took 66 milliseconds Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::parseTrackInfo Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::parseTrackInfo Oct 15 11:09:05 rivoplus volumio[3566]: verbose: ControllerMpd::parseTrackInfo Oct 15 11:09:05 rivoplus volumio[3566]: info: ControllerMpd::pushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:05 rivoplus volumio[3566]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":218,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1792058945~NTIxNTgwMTMxNTZjNDIxOWZiZDY2MjkzNGZlNmNjNThhMjNlNDJiYQ==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidlODFmYTdhYTkyNzc5MjUxN2UzYWU4ZWJhNmM0NzExZV82MS5tcDQ/0.flac?token=1792058945~NTIxNTgwMTMxNTZjNDIxOWZiZDY2MjkzNGZlNmNjNThhMjNlNDJiYQ==","trackType":"tidal"} Oct 15 11:09:05 rivoplus volumio[3566]: verbose: CURRENT POSITION 0 Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::syncState stateService pause Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::syncState currentStatus stop Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:05 rivoplus volumio[3566]: info: ControllerMpd::pushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:05 rivoplus volumio[3566]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":218,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1792058945~NTIxNTgwMTMxNTZjNDIxOWZiZDY2MjkzNGZlNmNjNThhMjNlNDJiYQ==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidlODFmYTdhYTkyNzc5MjUxN2UzYWU4ZWJhNmM0NzExZV82MS5tcDQ/0.flac?token=1792058945~NTIxNTgwMTMxNTZjNDIxOWZiZDY2MjkzNGZlNmNjNThhMjNlNDJiYQ==","trackType":"tidal"} Oct 15 11:09:05 rivoplus volumio[3566]: verbose: CURRENT POSITION 0 Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::syncState stateService pause Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::syncState currentStatus stop Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:05 rivoplus volumio[3566]: info: ControllerMpd::pushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:05 rivoplus volumio[3566]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":218,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1792058945~NTIxNTgwMTMxNTZjNDIxOWZiZDY2MjkzNGZlNmNjNThhMjNlNDJiYQ==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidlODFmYTdhYTkyNzc5MjUxN2UzYWU4ZWJhNmM0NzExZV82MS5tcDQ/0.flac?token=1792058945~NTIxNTgwMTMxNTZjNDIxOWZiZDY2MjkzNGZlNmNjNThhMjNlNDJiYQ==","trackType":"tidal"} Oct 15 11:09:05 rivoplus volumio[3566]: verbose: CURRENT POSITION 0 Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::syncState stateService pause Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::syncState currentStatus stop Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:05 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:05 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.636+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.636+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=323 volume=100 Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.637+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.637+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=323 volume=100 Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.638+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:05 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:05.638+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x23b8a80" state=STATUS_STOPPED positionMs=323 volume=100 Oct 15 11:09:05 rivoplus volumio[3566]: info: ------------------------------ 163ms Oct 15 11:09:05 rivoplus volumio[3566]: info: ------------------------------ 161ms Oct 15 11:09:05 rivoplus volumio[3566]: info: ------------------------------ 149ms Oct 15 11:09:05 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:05 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:05 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:06 rivoplus volumio[3566]: ------------------------------------ BT MESSAGE: Debounce: emitting confirmed playback=false for 9C:83:06:A5:69:D9 (player.Status=stopped, after 800ms) Oct 15 11:09:06 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:06.883+02:00 level=INFO msg="new address was allocated" component=ble/conn old=2 new=3 Oct 15 11:09:06 rivoplus volumio[3566]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: false from 9C:83:06:A5:69:D9 Oct 15 11:09:07 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:07.536+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:09:07 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:07.537+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:09:07 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:07.537+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=334 volume=100 Oct 15 11:09:07 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:07.537+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" id= title= Oct 15 11:09:07 rivoplus volumio[3566]: info: Executing endpoint metavolumio Oct 15 11:09:07 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 15 11:09:09 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:09.581+02:00 level=ERROR msg="failed to read message" component=conn/ws remoteAddr=192.168.100.40:51064 error="websocket: close 1006 (abnormal closure): unexpected EOF" Oct 15 11:09:09 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:09.581+02:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.100.40:51064 Oct 15 11:09:09 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:09.581+02:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.100.40:51064 Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.470+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.100.40:44816 Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.504+02:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.100.40:44816 @ 0x22d1950" latency=74.85424ms platform=PLATFORM_ANDROID version=6.260930.0 Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.505+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.100.40:44816 @ 0x22d1950" latency=75.595661ms timeout=20s included=[] excluded=[] Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.505+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" Oct 15 11:09:10 rivoplus volumio[3566]: info: Received Get System Info Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 11:09:10 rivoplus volumio[3566]: info: Discovery: Getting this device information Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.511+02:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" name=Rivoplus Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.512+02:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" language=pl Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.514+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" timezone=Europe/Warsaw Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.527+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" available=true connected=true macAddress=02:00:00:27:29:01 ip4Address=192.168.100.41/24 ip6Address= Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.529+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.530+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" setupComplete=true Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 11:09:10 rivoplus volumio[3566]: amixer -c 5 info | grep "Comtrue-inc UAC2 Device" Oct 15 11:09:10 rivoplus bluealsa[3448]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_83_06_A5_69_D9/mcp/player0, ...) Oct 15 11:09:10 rivoplus volumio[3566]: Card sysdefault:5 'Device'/'Comtrue-inc Comtrue-inc UAC2 Device at usb-xhci-hcd.0.auto-1.4.3, high speed' Oct 15 11:09:10 rivoplus volumio[3566]: Invalid card number '1'. Oct 15 11:09:10 rivoplus volumio[3566]: amixer -c 1 info | grep "WooAudio" Oct 15 11:09:10 rivoplus volumio[3566]: Invalid card number '1'. Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.659+02:00 level=WARN msg="active output device not found in available devices" component=volumio/socket activeDeviceId=1 Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.659+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" selectedOutputId=1 Oct 15 11:09:10 rivoplus volumio[3566]: info: Received Get System Info Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 11:09:10 rivoplus volumio[3566]: info: Discovery: Getting this device information Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.673+02:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" currentVersion=4.208 latestVersion=4.208 Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.673+02:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.100.40:44816 @ 0x22d1950" status=UPDATE_STATUS_NONE progress=0 Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.674+02:00 level=INFO msg="emitting user changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" userId= Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.674+02:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" providers=3 Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.674+02:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" plugins=28 Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.678+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.678+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_STOPPED positionMs=5336 volume=100 Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.678+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 11:09:10 rivoplus volumio[3566]: info: Discovery: Getting this device information Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 11:09:10 rivoplus volumio[3566]: verbose: New Socket.io Connection to 192.168.100.41:3000 from 192.168.100.40 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 15 11:09:10 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.845+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.846+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.846+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=334 volume=100 Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.846+02:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x247e8d0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Oct 15 11:09:10 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:10.846+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:11 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:11.596+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.100.40:44816 @ 0x22d1950" latency=77.775011ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Oct 15 11:09:11 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:11.617+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=75.339996ms timeout=10s Oct 15 11:09:11 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:11.646+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=75.339996ms timeout=10s endpoint=http://pushupdates.volumio.org duration=25.922375ms Oct 15 11:09:11 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:11.648+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=75.339996ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=30.437821ms Oct 15 11:09:11 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:11.654+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=75.339996ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=34.933267ms Oct 15 11:09:11 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:11.659+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=75.339996ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=40.843263ms Oct 15 11:09:11 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:11.687+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=75.339996ms timeout=10s endpoint=http://cddb.volumio.org duration=66.902431ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 15 11:09:11 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:11.732+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=75.339996ms timeout=10s endpoint=https://www.googleapis.com duration=113.94111ms Oct 15 11:09:11 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:11.759+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=75.339996ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=140.014819ms Oct 15 11:09:11 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:11.766+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=75.339996ms timeout=10s endpoint=https://securetoken.googleapis.com duration=147.613909ms Oct 15 11:09:11 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:11.770+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=75.339996ms timeout=10s endpoint=https://database.volumio.cloud duration=147.837661ms Oct 15 11:09:11 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:11.771+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=75.339996ms timeout=10s endpoint=https://functions.volumio.cloud duration=151.267641ms Oct 15 11:09:11 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:11.772+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=75.339996ms timeout=10s endpoint=https://functions.volumio.cloud duration=151.508059ms Oct 15 11:09:11 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:11.782+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=75.339996ms timeout=10s endpoint=http://plugins.volumio.org duration=161.801626ms Oct 15 11:09:11 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:11.920+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=75.339996ms timeout=10s endpoint=https://google.com duration=302.265698ms Oct 15 11:09:12 rivoplus sudo[5186]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 15 11:09:12 rivoplus sudo[5186]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:09:12 rivoplus sudo[5187]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 15 11:09:12 rivoplus sudo[5187]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:09:12 rivoplus sudo[5186]: pam_unix(sudo:session): session closed for user root Oct 15 11:09:12 rivoplus sudo[5187]: pam_unix(sudo:session): session closed for user root Oct 15 11:09:12 rivoplus volumio[3566]: verbose: New Socket.io Connection to 192.168.100.41 from 192.168.100.40 UA: Mozilla/5.0 (Linux; Android 16; SM-S938B Build/BP4A.251205.006; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/154.0.8037.106 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 9 Oct 15 11:09:12 rivoplus sudo[5193]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 15 11:09:12 rivoplus sudo[5193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:09:12 rivoplus sudo[5195]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 15 11:09:12 rivoplus sudo[5195]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:09:12 rivoplus sudo[5193]: pam_unix(sudo:session): session closed for user root Oct 15 11:09:12 rivoplus sudo[5195]: pam_unix(sudo:session): session closed for user root Oct 15 11:09:12 rivoplus volumio[3566]: verbose: New Socket.io Connection to 192.168.100.41 from 192.168.100.40 UA: Mozilla/5.0 (Linux; Android 16; SM-S938B Build/BP4A.251205.006; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/154.0.8037.106 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 10 Oct 15 11:09:12 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 15 11:09:12 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetVisibleSources Oct 15 11:09:12 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 15 11:09:12 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:12 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 15 11:09:12 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 15 11:09:12 rivoplus volumio[3566]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 15 11:09:12 rivoplus volumio[3566]: info: Received Get System Info Oct 15 11:09:12 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 11:09:12 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 11:09:12 rivoplus volumio[3566]: info: Discovery: Getting this device information Oct 15 11:09:12 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:12 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 11:09:12 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:12 rivoplus volumio[3566]: info: Listing playlists Oct 15 11:09:12 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 15 11:09:12 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 15 11:09:12 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 15 11:09:13 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 15 11:09:14 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:14.155+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:09:14 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:14.155+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:09:14 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:14.156+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=334 volume=100 Oct 15 11:09:14 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:14.156+02:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x247e8d0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Oct 15 11:09:14 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:14.156+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:14 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 15 11:09:14 rivoplus volumio[3566]: info: Received Get System Info Oct 15 11:09:14 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 11:09:14 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 11:09:14 rivoplus volumio[3566]: info: Discovery: Getting this device information Oct 15 11:09:14 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:14 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 11:09:14 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 15 11:09:14 rivoplus volumio[3566]: info: Received Get System Info Oct 15 11:09:14 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 11:09:14 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 11:09:14 rivoplus volumio[3566]: info: Discovery: Getting this device information Oct 15 11:09:14 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:14 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 11:09:17 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:17.466+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:09:17 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:17.467+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:09:17 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:17.467+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=334 volume=100 Oct 15 11:09:17 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:17.467+02:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x247e8d0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Oct 15 11:09:17 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:17.467+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:20 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:20.774+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:09:20 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:20.775+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:09:20 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:20.775+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=334 volume=100 Oct 15 11:09:20 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:20.775+02:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x247e8d0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Oct 15 11:09:20 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:20.775+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:22 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:22 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:22 rivoplus volumio[3566]: info: Currently active: mpd Oct 15 11:09:22 rivoplus volumio[3566]: info: Stopping currently active service Oct 15 11:09:22 rivoplus volumio[3566]: info: CoreCommandRouter::volumioStop Oct 15 11:09:22 rivoplus volumio[3566]: info: CoreStateMachine::stop Oct 15 11:09:22 rivoplus volumio[3566]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 11:09:22 rivoplus volumio[3566]: info: TidalConnect Active Oct 15 11:09:22 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:22 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:22 rivoplus volumio[3566]: info: Currently active: tidal Oct 15 11:09:22 rivoplus volumio[3566]: info: Setting Volatile state to tidalconnect Oct 15 11:09:22 rivoplus volumio[3566]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 11:09:22 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:22 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:22 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:09:22 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:22 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:22 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:22 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:22 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:22 rivoplus volumio[3566]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Oct 15 11:09:22 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:22 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:22 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:22 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:22 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:22 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:22 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:22 rivoplus volumio[3566]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Oct 15 11:09:22 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:22.174+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:22 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:22.174+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_STOPPED positionMs= volume=100 Oct 15 11:09:22 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:22.174+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:22 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:22.175+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:22 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:22.175+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_STOPPED positionMs= volume=100 Oct 15 11:09:22 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:22.176+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:22 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:22 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:22 rivoplus vtcs[4699]: [2026-10-15 11:09:22.607] [tisoc] [warning] [PlaybackControllerImpl.cpp:498] Illegal state:1 Oct 15 11:09:22 rivoplus volumio[3566]: info: PlaybackInactive Oct 15 11:09:22 rivoplus volumio[3566]: info: Device Session is_active: true Oct 15 11:09:22 rivoplus volumio[3566]: info: DeviceInactive Oct 15 11:09:22 rivoplus volumio[3566]: info: Relinquishing Volumio State Oct 15 11:09:22 rivoplus volumio[3566]: verbose: UNSET VOLATILE: Service: undefined Oct 15 11:09:22 rivoplus volumio[3566]: info: unSetVolatile called Oct 15 11:09:22 rivoplus volumio[3566]: info: Relinquishing Volumio State to another service Oct 15 11:09:22 rivoplus vtcs[4699]: [2026-10-15 11:09:22.612] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Oct 15 11:09:22 rivoplus vtcs[4699]: [2026-10-15 11:09:22] [info] asio async_shutdown error: asio.misc:2 (End of file) Oct 15 11:09:22 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 15 11:09:24 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:24.083+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:09:24 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:24.084+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:09:24 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:24.084+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=334 volume=100 Oct 15 11:09:24 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:24.084+02:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x247e8d0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Oct 15 11:09:24 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:24.085+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:24 rivoplus volumio[3566]: info: Executing endpoint metavolumio Oct 15 11:09:24 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 15 11:09:27 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:27.392+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:09:27 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:27.393+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:09:27 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:27.393+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=602 volume=100 Oct 15 11:09:27 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:27.393+02:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x247e8d0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Oct 15 11:09:27 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:27.394+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:30 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:30 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:30 rivoplus volumio[3566]: info: Currently active: tidal Oct 15 11:09:30 rivoplus volumio[3566]: info: Stopping currently active service Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreCommandRouter::volumioStop Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreStateMachine::stop Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 11:09:30 rivoplus volumio[3566]: info: TidalConnect Active Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:30 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:30 rivoplus volumio[3566]: info: Currently active: tidal Oct 15 11:09:30 rivoplus volumio[3566]: info: Setting Volatile state to tidalconnect Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:30 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:30 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:30 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:30 rivoplus volumio[3566]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:30 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:30 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:30 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:30 rivoplus volumio[3566]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Oct 15 11:09:30 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:30.426+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:30 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:30.426+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_STOPPED positionMs= volume=100 Oct 15 11:09:30 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:30.426+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:30 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:30.428+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:30 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:30.428+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_STOPPED positionMs= volume=100 Oct 15 11:09:30 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:30.429+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:30 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:30 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:30 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:30.702+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:09:30 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:30.702+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:09:30 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:30.702+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=602 volume=100 Oct 15 11:09:30 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:30.703+02:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x247e8d0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Oct 15 11:09:30 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:30.703+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:30 rivoplus vtcs[4699]: [2026-10-15 11:09:30.776] [tisoc] [warning] [PlaybackControllerImpl.cpp:498] Illegal state:1 Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:30 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:30 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:30 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:30 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:30 rivoplus volumio[3566]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Oct 15 11:09:30 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:30.790+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:30 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:30.790+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_STOPPED positionMs= volume=100 Oct 15 11:09:30 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:30.791+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:30 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:31 rivoplus vtcs[4699]: [2026-10-15 11:09:31.331] [tisoc] [warning] [PlaybackControllerImpl.cpp:213] Ignore play request because playback state is not STARTED. state_=2, playstate_=1, player_state_=0 Oct 15 11:09:31 rivoplus volumio[3566]: info: Pushing metadata Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:31 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:31 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:31 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:31 rivoplus volumio[3566]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:31 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:31 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:31 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:09:31 rivoplus volumio[3566]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:31 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:31 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:31 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:31 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:31 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:31.387+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:31 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:31.388+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_STOPPED positionMs= volume=100 Oct 15 11:09:31 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:31.388+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:31 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:31.389+02:00 level=WARN msg="received unknown player status" component=volumio status="" Oct 15 11:09:31 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:31.389+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_STOPPED positionMs= volume=100 Oct 15 11:09:31 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:31.389+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:31 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:31.390+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PAUSED positionMs=5160 volume=100 Oct 15 11:09:31 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:31.391+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title="Ólafsson: Sleep Spiral" Oct 15 11:09:31 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:31.392+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PLAYING positionMs=5160 volume=100 Oct 15 11:09:31 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:31.392+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title="Ólafsson: Sleep Spiral" Oct 15 11:09:31 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:31 rivoplus volumio[3566]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 15 11:09:31 rivoplus volumio[3566]: info: Signalling Playback active due to playback status change Oct 15 11:09:31 rivoplus volumio[3566]: info: MCU Signalled Playback Active Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 15 11:09:31 rivoplus volumio[3566]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 15 11:09:31 rivoplus volumio[3566]: info: Received Get System Version Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 15 11:09:31 rivoplus volumio[3566]: info: Received Get System Info Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 11:09:31 rivoplus volumio[3566]: info: Discovery: Getting this device information Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:31 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 11:09:32 rivoplus volumio[3566]: info: Pushing metadata Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:32 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:32 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:32 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:32.136+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PLAYING positionMs=5160 volume=100 Oct 15 11:09:32 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:32.137+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title="Ólafsson: Sleep Spiral" Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:32 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:32 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:32 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:32 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:32 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:32 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:32 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:32 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:32 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:32 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:32.185+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PLAYING positionMs=5160 volume=100 Oct 15 11:09:32 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:32.186+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title="Ólafsson: Sleep Spiral" Oct 15 11:09:32 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:32.187+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PAUSED positionMs=5160 volume=100 Oct 15 11:09:32 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:32.188+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title="Ólafsson: Sleep Spiral" Oct 15 11:09:32 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:32.189+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PLAYING positionMs=5160 volume=100 Oct 15 11:09:32 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:32.190+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PLAYING positionMs=5160 volume=100 Oct 15 11:09:32 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:32.191+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title="Ólafsson: Sleep Spiral" Oct 15 11:09:32 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:32.192+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title="Ólafsson: Sleep Spiral" Oct 15 11:09:32 rivoplus volumio[3566]: info: Signalling Playback active due to playback status change Oct 15 11:09:32 rivoplus volumio[3566]: info: MCU Signalled Playback Inactive Oct 15 11:09:32 rivoplus volumio[3566]: info: MCU Signalled Playback Active Oct 15 11:09:33 rivoplus vtcs[4699]: [close:85] Entering Oct 15 11:09:33 rivoplus vtcs[4699]: [close:100] Exiting Oct 15 11:09:33 rivoplus vtcs[4699]: [open:50] Opening with sample rate: 48000, type: 0 Oct 15 11:09:33 rivoplus vtcs[4699]: [start:106] Entering Oct 15 11:09:33 rivoplus vtcs[4699]: [start:113] Reopening PCM device... Oct 15 11:09:33 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:33 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:09:33 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:33 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:33 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:33 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:33 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:33.043+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PLAYING positionMs=5160 volume=100 Oct 15 11:09:33 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:33.044+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title="Ólafsson: Sleep Spiral" Oct 15 11:09:33 rivoplus vtcs[4699]: ALSA lib confmisc.c:165:(snd_config_get_card) Cannot get card index for WooAudio Oct 15 11:09:33 rivoplus vtcs[4699]: ALSA lib ./src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Oct 15 11:09:33 rivoplus vtcs[4699]: [reopen:182] ALSA error: No such device Oct 15 11:09:33 rivoplus vtcs[4699]: [start:114] Error: 3 Oct 15 11:09:33 rivoplus vtcs[4699]: [2026-10-15 11:09:33.124] [tisoc] [warning] [flac_decoder.cpp:302] FLACDecoder::error_callback FLAC__STREAM_DECODER_ERROR_STATUS_LOST_SYNC Oct 15 11:09:33 rivoplus volumio[3566]: info: Executing endpoint metavolumio Oct 15 11:09:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 15 11:09:33 rivoplus volumio[3566]: info: Executing endpoint metavolumio Oct 15 11:09:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 15 11:09:33 rivoplus volumio[3566]: info: Executing endpoint metavolumio Oct 15 11:09:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 15 11:09:34 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:34.025+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:09:34 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:34.026+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:09:34 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:34.026+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=602 volume=100 Oct 15 11:09:34 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:34.026+02:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x247e8d0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Oct 15 11:09:34 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:34.026+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:37 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:37.335+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:09:37 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:37.336+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:09:37 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:37.336+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=54 volume=100 Oct 15 11:09:37 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:37.336+02:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x247e8d0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Oct 15 11:09:37 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:37.336+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:40 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:40.644+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:09:40 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:40.645+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:09:40 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:40.646+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=54 volume=100 Oct 15 11:09:40 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:40.646+02:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x247e8d0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Oct 15 11:09:40 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:40.646+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:43 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:43.953+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:09:43 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:43.954+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:09:43 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:43.954+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=54 volume=100 Oct 15 11:09:43 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:43.954+02:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x247e8d0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Oct 15 11:09:43 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:43.954+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:47 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:47.260+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:09:47 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:47.261+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:09:47 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:47.261+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=54 volume=100 Oct 15 11:09:47 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:47.261+02:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x247e8d0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Oct 15 11:09:47 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:47.261+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:48 rivoplus vtcs[4699]: [close:85] Entering Oct 15 11:09:48 rivoplus vtcs[4699]: [close:100] Exiting Oct 15 11:09:48 rivoplus volumio[3566]: info: Pushing metadata Oct 15 11:09:48 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:48 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:48 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:09:48 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:48 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:48 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:48 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:48 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:48 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:48 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:09:48 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:48 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:48 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:48 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:48 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:48 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:48 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:09:48 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:48 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:48 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:48 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:48 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:48.910+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PLAYING positionMs=5160 volume=100 Oct 15 11:09:48 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:48.910+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title=Esja Oct 15 11:09:48 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:48.912+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PLAYING positionMs=0 volume=100 Oct 15 11:09:48 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:48.912+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title=Esja Oct 15 11:09:48 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:48.917+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PAUSED positionMs=0 volume=100 Oct 15 11:09:48 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:48.917+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title=Esja Oct 15 11:09:49 rivoplus vtcs[4699]: [close:85] Entering Oct 15 11:09:49 rivoplus vtcs[4699]: [close:100] Exiting Oct 15 11:09:49 rivoplus volumio[3566]: info: Pushing metadata Oct 15 11:09:49 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:49 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:49 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:49 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:49 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:49 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:49 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:49 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:49 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:49 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:49 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:49 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:49 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:49.044+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PAUSED positionMs=0 volume=100 Oct 15 11:09:49 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:49.044+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title=Esja Oct 15 11:09:49 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:49.052+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PAUSED positionMs=0 volume=100 Oct 15 11:09:49 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:49.053+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title=Esja Oct 15 11:09:49 rivoplus volumio[3566]: info: MCU Signalled Playback Inactive Oct 15 11:09:49 rivoplus vtcs[4699]: [close:85] Entering Oct 15 11:09:49 rivoplus vtcs[4699]: [close:100] Exiting Oct 15 11:09:49 rivoplus vtcs[4699]: [open:50] Opening with sample rate: 44100, type: 0 Oct 15 11:09:49 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:49 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:49 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:09:49 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:49 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:49 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:49 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:49 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:49.707+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PAUSED positionMs=0 volume=100 Oct 15 11:09:49 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:49.708+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title=Esja Oct 15 11:09:50 rivoplus vtcs[4699]: [start:106] Entering Oct 15 11:09:50 rivoplus vtcs[4699]: [start:113] Reopening PCM device... Oct 15 11:09:50 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:50 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:50 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:09:50 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:50 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:50 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:50 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:50 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:50.127+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PLAYING positionMs=0 volume=100 Oct 15 11:09:50 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:50.127+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title=Esja Oct 15 11:09:50 rivoplus vtcs[4699]: ALSA lib confmisc.c:165:(snd_config_get_card) Cannot get card index for WooAudio Oct 15 11:09:50 rivoplus vtcs[4699]: ALSA lib ./src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Oct 15 11:09:50 rivoplus vtcs[4699]: [reopen:182] ALSA error: No such device Oct 15 11:09:50 rivoplus vtcs[4699]: [start:114] Error: 3 Oct 15 11:09:50 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:50 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:50 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:50 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:50 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:50 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:50 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:09:50 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:09:50 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:09:50 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:09:50 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:09:50 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:09:50 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:50.161+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PLAYING positionMs=0 volume=100 Oct 15 11:09:50 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:50.161+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title=Esja Oct 15 11:09:50 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:50.162+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PLAYING positionMs=0 volume=100 Oct 15 11:09:50 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:50.163+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title=Esja Oct 15 11:09:50 rivoplus volumio[3566]: info: Signalling Playback active due to playback status change Oct 15 11:09:50 rivoplus volumio[3566]: info: MCU Signalled Playback Active Oct 15 11:09:50 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:50.567+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:09:50 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:50.567+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:09:50 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:50.568+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=54 volume=100 Oct 15 11:09:50 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:50.568+02:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x247e8d0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Oct 15 11:09:50 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:50.568+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:51 rivoplus volumio[3566]: info: Executing endpoint metavolumio Oct 15 11:09:51 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 15 11:09:51 rivoplus volumio[3566]: info: Executing endpoint metavolumio Oct 15 11:09:51 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 15 11:09:51 rivoplus volumio[3566]: info: Executing endpoint metavolumio Oct 15 11:09:51 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 15 11:09:53 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:53.874+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:09:53 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:53.874+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:09:53 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:53.875+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=54 volume=100 Oct 15 11:09:53 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:53.875+02:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x247e8d0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Oct 15 11:09:53 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:53.875+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:09:57 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:57.181+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:09:57 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:57.182+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:09:57 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:57.182+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=323 volume=100 Oct 15 11:09:57 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:57.182+02:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x247e8d0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Oct 15 11:09:57 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:09:57.182+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:10:00 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:00.488+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:10:00 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:00.488+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:10:00 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:00.488+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=323 volume=100 Oct 15 11:10:00 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:00.488+02:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x247e8d0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Oct 15 11:10:00 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:00.488+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:10:03 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:03.800+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:10:03 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:03.800+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:10:03 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:03.801+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=323 volume=100 Oct 15 11:10:03 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:03.801+02:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x247e8d0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Oct 15 11:10:03 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:03.801+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:10:07 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:07.111+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Oct 15 11:10:07 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:07.111+02:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01 @ 0x23b8a80" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Oct 15 11:10:07 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:07.111+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:51064 @ 0x247e8d0" state=STATUS_STOPPED positionMs=323 volume=100 Oct 15 11:10:07 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:07.111+02:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x247e8d0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Oct 15 11:10:07 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:07.112+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title= Oct 15 11:10:28 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:28.929+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=111.595778ms timeout=10s Oct 15 11:10:28 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:28.959+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=111.595778ms timeout=10s endpoint=http://pushupdates.volumio.org duration=26.593783ms Oct 15 11:10:28 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:28.959+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=111.595778ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=29.948381ms Oct 15 11:10:28 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:28.974+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=111.595778ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=40.921887ms Oct 15 11:10:29 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:29.009+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=111.595778ms timeout=10s endpoint=http://cddb.volumio.org duration=76.111083ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 15 11:10:29 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:29.045+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=111.595778ms timeout=10s endpoint=https://www.googleapis.com duration=114.200375ms Oct 15 11:10:29 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:29.079+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=111.595778ms timeout=10s endpoint=https://securetoken.googleapis.com duration=147.440645ms Oct 15 11:10:29 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:29.081+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=111.595778ms timeout=10s endpoint=https://functions.volumio.cloud duration=148.539317ms Oct 15 11:10:29 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:29.082+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=111.595778ms timeout=10s endpoint=https://functions.volumio.cloud duration=149.452821ms Oct 15 11:10:29 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:29.150+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=111.595778ms timeout=10s endpoint=http://plugins.volumio.org duration=217.014491ms Oct 15 11:10:29 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:29.218+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=111.595778ms timeout=10s endpoint=https://database.volumio.cloud duration=285.532417ms Oct 15 11:10:29 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:29.232+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=111.595778ms timeout=10s endpoint=https://google.com duration=301.49907ms Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 11:10:29 rivoplus volumio[3566]: info: Discovery: Getting this device information Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 11:10:29 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:29.283+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=111.595778ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=351.911582ms Oct 15 11:10:29 rivoplus volumio[3566]: verbose: New Socket.io Connection to 192.168.100.41:3000 from 192.168.100.40 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 15 11:10:29 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:29.362+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.40:44816 @ 0x22d1950" latency=111.595778ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=429.203213ms Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 11:10:29 rivoplus volumio[3566]: Invalid card number '1'. Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: inputs , getAdditionalUiSection Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:29 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:32 rivoplus volumio[3566]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Oct 15 11:10:32 rivoplus volumio[3566]: info: Preparing to save Alsa Options, stopping services first Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPause Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreStateMachine::pause Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreStateMachine::stPlaybackTimer Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreStateMachine::servicePause Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreCommandRouter::servicePause Oct 15 11:10:32 rivoplus volumio[3566]: info: Received pause Oct 15 11:10:32 rivoplus volumio[3566]: info: Saving Audio Output to: {"output_device":{"value":"1","label":"WooAudio"}} Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 11:10:32 rivoplus vtcs[4699]: [pause:147] Entering Oct 15 11:10:32 rivoplus volumio[3566]: warn: Unable to locate the device WooAudio a reboot may be required. Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 11:10:32 rivoplus volumio[3566]: Invalid card number '1'. Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 15 11:10:32 rivoplus volumio[3566]: info: Updating Volume Controller Parameters: Device: 1 Name: WooAudio Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 15 11:10:32 rivoplus volumio[3566]: info: Disabling external Volume Control Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 15 11:10:32 rivoplus volumio[3566]: info: Preparing to generate the ALSA configuration file Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:32 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:10:32 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreCommandRouter::servicePushState Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:10:32 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:32 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:10:32 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:10:32 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:32.961+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PLAYING positionMs=0 volume=100 Oct 15 11:10:32 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:32.962+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title=Esja Oct 15 11:10:32 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:32.963+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PAUSED positionMs=0 volume=100 Oct 15 11:10:32 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:32.964+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title=Esja Oct 15 11:10:32 rivoplus volumio[3566]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 15 11:10:32 rivoplus volumio[3566]: info: Reading ALSA contributions from plugins. Oct 15 11:10:32 rivoplus volumio[3566]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number '1'. Oct 15 11:10:33 rivoplus volumio[3566]: info: VolumeController:: Volume=undefined Mute =false Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:33 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:10:33 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:10:33 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:33.153+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PAUSED positionMs=0 volume= Oct 15 11:10:33 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:33.154+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title=Esja Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 11:10:33 rivoplus volumio[3566]: Invalid card number '1'. Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: inputs , getAdditionalUiSection Oct 15 11:10:33 rivoplus volumio[3566]: info: VolumeController::SetAlsaVolume0 Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:33 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:10:33 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:10:33 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:33.437+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PAUSED positionMs=0 volume=0 Oct 15 11:10:33 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:33.438+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title=Esja Oct 15 11:10:33 rivoplus volumio[3566]: info: VolumeController::SetAlsaVolume0 Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:33 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:10:33 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:10:33 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:33.471+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PAUSED positionMs=0 volume=0 Oct 15 11:10:33 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:33.472+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id= title=Esja Oct 15 11:10:33 rivoplus volumio[3566]: info: MCU Signalled Playback Inactive Oct 15 11:10:33 rivoplus volumio[3566]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number '1'. Oct 15 11:10:33 rivoplus volumio[3566]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number '1'. Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:33 rivoplus volumio[3566]: info: Asound.conf file written Oct 15 11:10:33 rivoplus sudo[5396]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 15 11:10:33 rivoplus sudo[5396]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:33 rivoplus sudo[5396]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:33 rivoplus kernel: Fine tdm clk setting range (0~2000000), 12287994 Oct 15 11:10:33 rivoplus kernel: Err: can not set rate to 4278967296! Oct 15 11:10:33 rivoplus kernel: Range[3920000 - 500000000] Oct 15 11:10:33 rivoplus kernel: out of value, fixed it Oct 15 11:10:33 rivoplus kernel: id=0 set inskew=0 Oct 15 11:10:33 rivoplus volumio[3566]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Oct 15 11:10:33 rivoplus volumio[3566]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:eARC_TX CDS:0' : Operation not permitted Oct 15 11:10:33 rivoplus volumio[3566]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:I2SIn CLK:0' : Operation not permitted Oct 15 11:10:33 rivoplus volumio[3566]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:SPDIFIN audio samplerate:0' : Operation not permitted Oct 15 11:10:33 rivoplus volumio[3566]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:SPDIFIN Audio Type:0' : Operation not permitted Oct 15 11:10:33 rivoplus volumio[3566]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:Clock Source 5 Validity:0' : Operation not permitted Oct 15 11:10:33 rivoplus volumio[3566]: info: Output device has changed, restarting MPD Oct 15 11:10:33 rivoplus volumio[3566]: info: Output device has changed, restarting Shairport Sync Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 11:10:33 rivoplus sudo[5402]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 15 11:10:33 rivoplus sudo[5402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:33 rivoplus volumio[3566]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 15 11:10:33 rivoplus volumio[3566]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:33 rivoplus sudo[5402]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:33 rivoplus sudo[5403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 15 11:10:33 rivoplus sudo[5403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:33 rivoplus volumio[3566]: info: QobuzConnect: setDeactiveState invoked Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:33 rivoplus volumio[3566]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:33 rivoplus volumio[3566]: info: Relinquishing Volumio State Oct 15 11:10:33 rivoplus volumio[3566]: verbose: UNSET VOLATILE: Service: tidalconnect Oct 15 11:10:33 rivoplus volumio[3566]: info: unSetVolatile called Oct 15 11:10:33 rivoplus volumio[3566]: info: Relinquishing Volumio State to another service Oct 15 11:10:33 rivoplus vtcs[4699]: [close:85] Entering Oct 15 11:10:33 rivoplus vtcs[4699]: [close:100] Exiting Oct 15 11:10:33 rivoplus vtcs[4699]: [2026-10-15 11:10:33.697] [tisoc] [error] [SpkconServer.cpp:476] socket write error. fd=3 errorno=32 error=Broken pipe Oct 15 11:10:33 rivoplus vtcs[4699]: [2026-10-15 11:10:33.697] [tisoc] [error] [SpkconServer.cpp:476] socket write error. fd=3 errorno=32 error=Broken pipe Oct 15 11:10:33 rivoplus vtcs[4699]: [2026-10-15 11:10:33.697] [tisoc] [error] [SpkconServer.cpp:476] socket write error. fd=3 errorno=32 error=Broken pipe Oct 15 11:10:33 rivoplus vtcs[4699]: [2026-10-15 11:10:33.697] [tisoc] [error] [SpkconServer.cpp:476] socket write error. fd=3 errorno=32 error=Broken pipe Oct 15 11:10:33 rivoplus vtcs[4699]: [2026-10-15 11:10:33.697] [tisoc] [error] [SpkconServer.cpp:378] recv error. socket disconnected Oct 15 11:10:33 rivoplus vtcs[4699]: [2026-10-15 11:10:33.700] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Oct 15 11:10:33 rivoplus vtcs[4699]: [2026-10-15 11:10:33] [info] asio async_shutdown error: asio.misc:2 (End of file) Oct 15 11:10:33 rivoplus volumio[3566]: info: Output device has changed, restarting MPD Oct 15 11:10:33 rivoplus systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 15 11:10:33 rivoplus volumio[3566]: info: Output device has changed, restarting Shairport Sync Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 11:10:33 rivoplus sudo[5412]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:33 rivoplus sudo[5412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:33 rivoplus sudo[5418]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 15 11:10:33 rivoplus sudo[5414]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 15 11:10:33 rivoplus sudo[5418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:33 rivoplus sudo[5414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:33 rivoplus volumio[3566]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 15 11:10:33 rivoplus volumio[3566]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:33 rivoplus sudo[5414]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:33 rivoplus volumio[3566]: info: QobuzConnect: setDeactiveState invoked Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:33 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:33 rivoplus volumio[3566]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Oct 15 11:10:33 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:33 rivoplus systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Oct 15 11:10:33 rivoplus systemd[1]: vtcs.service: Deactivated successfully. Oct 15 11:10:33 rivoplus systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Oct 15 11:10:33 rivoplus sudo[5427]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:33 rivoplus sudo[5427]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:33 rivoplus sudo[5429]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:33 rivoplus sudo[5429]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:33 rivoplus sudo[5412]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:33 rivoplus sudo[5432]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:33 rivoplus sudo[5432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:33 rivoplus sudo[5440]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 15 11:10:33 rivoplus sudo[5440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:33 rivoplus systemd[1]: mpd.service: Deactivated successfully. Oct 15 11:10:33 rivoplus systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 15 11:10:34 rivoplus systemd[1]: mpd.socket: Deactivated successfully. Oct 15 11:10:34 rivoplus volumio[3566]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Oct 15 11:10:34 rivoplus volumio[3566]: info: MPD Permissions set Oct 15 11:10:34 rivoplus volumio[3566]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Oct 15 11:10:34 rivoplus volumio[3566]: info: MPD Permissions set Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:10:34 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:34 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:34 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:10:34 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:10:34 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:34.043+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PAUSED positionMs=88349 volume=100 Oct 15 11:10:34 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:34.044+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id=tidal://song/122854182 title="Co Mówimy ?" Oct 15 11:10:34 rivoplus sudo[5446]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 15 11:10:34 rivoplus systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 15 11:10:34 rivoplus sudo[5446]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:34 rivoplus systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 15 11:10:34 rivoplus systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:10:34 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:10:34 rivoplus systemd[1]: Starting mpd.service - Music Player Daemon... Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:34 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:34 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:10:34 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:10:34 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:34.106+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PAUSED positionMs=88349 volume=100 Oct 15 11:10:34 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:34.106+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id=tidal://song/122854182 title="Co Mówimy ?" Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus sudo[5427]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:34 rivoplus sudo[5429]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 15 11:10:34 rivoplus sudo[5440]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:34 rivoplus sudo[5446]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus sudo[5432]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:34 rivoplus sudo[5471]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 15 11:10:34 rivoplus sudo[5470]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 15 11:10:34 rivoplus sudo[5471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:34 rivoplus sudo[5470]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: Not Reporting Auto name since its the default one Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:34 rivoplus volumio[3566]: info: Not Reporting Auto name since its the default one Oct 15 11:10:34 rivoplus systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Oct 15 11:10:34 rivoplus volumio[3566]: info: Starting Shairport Sync Oct 15 11:10:34 rivoplus volumio[3566]: info: Starting Shairport Sync Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Oct 15 11:10:34 rivoplus sudo[5485]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 15 11:10:34 rivoplus sudo[5485]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:34 rivoplus qobuz-connect[4700]: 20261015 11:10:34.459 [4700.4700] INFO SampleApp: Stopping Local configuration server Oct 15 11:10:34 rivoplus sudo[5487]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 15 11:10:34 rivoplus sudo[5487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:34 rivoplus volumio[3566]: info: Configured Audio card not found, not starting RAAT Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Oct 15 11:10:34 rivoplus systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 15 11:10:34 rivoplus systemd[1]: shairport-sync.service: Deactivated successfully. Oct 15 11:10:34 rivoplus systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 15 11:10:34 rivoplus systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 15 11:10:34 rivoplus qobuz-connect[4700]: 20261015 11:10:34.561 [4700.4700] INFO SampleApp: shat down connection on UNIX socket Oct 15 11:10:34 rivoplus sudo[5485]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:34 rivoplus volumio[3566]: info: Configured Audio card not found, not starting RAAT Oct 15 11:10:34 rivoplus volumio[3566]: info: Shairport-Sync Started Oct 15 11:10:34 rivoplus volumio[3566]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Oct 15 11:10:34 rivoplus volumio[3566]: info: QobuzConnect: setDeactiveState invoked Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:34 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:34 rivoplus systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 15 11:10:34 rivoplus systemd[1]: shairport-sync.service: Deactivated successfully. Oct 15 11:10:34 rivoplus systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 15 11:10:34 rivoplus systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 15 11:10:34 rivoplus sudo[5487]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:34 rivoplus volumio[3566]: info: Shairport-Sync Started Oct 15 11:10:34 rivoplus systemd[1]: qobuz-connect.service: Deactivated successfully. Oct 15 11:10:34 rivoplus systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Oct 15 11:10:34 rivoplus systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Oct 15 11:10:34 rivoplus sudo[5453]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 15 11:10:34 rivoplus sudo[5453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 15 11:10:34 rivoplus sudo[5471]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:34 rivoplus sudo[5470]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:34 rivoplus sudo[5453]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:34 rivoplus volumio[3566]: info: Executing endpoint qc_getconfig Oct 15 11:10:34 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Oct 15 11:10:34 rivoplus qobuz-connect[5495]: 20261015 11:10:34.886 [5495.5495] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Oct 15 11:10:34 rivoplus volumio[3566]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Oct 15 11:10:34 rivoplus volumio[3566]: info: QobuzConnect: QOBUZ Connect daemon connected Oct 15 11:10:34 rivoplus qobuz-connect[5495]: 20261015 11:10:34.909 [5495.5495] INFO VolumeManager: [0xac006168]: Setting new playback volume: 75 Oct 15 11:10:34 rivoplus qobuz-connect[5495]: 20261015 11:10:34.909 [5495.5495] INFO VolumeManager: [0xac006168]: Setting new mute state: 0 Oct 15 11:10:34 rivoplus qobuz-connect[5495]: 20261015 11:10:34.909 [5495.5495] INFO AudioStreamManager: [0xac005ec0]: Setting new audio download buffer size: 1048576 Oct 15 11:10:34 rivoplus qobuz-connect[5495]: 20261015 11:10:34.909 [5495.5495] INFO QobuzConnect: [0xac006a30]: Client initialized! Oct 15 11:10:34 rivoplus qobuz-connect[5495]: 20261015 11:10:34.909 [5495.5495] INFO SampleApp: Starting Avahi advertising, name: Rivoplus, service name: _qobuz-connect._tcp Oct 15 11:10:34 rivoplus qobuz-connect[5495]: 20261015 11:10:34.936 [5495.5495] INFO LocalConfigManager: [0xac005be8]: Starting Local Configuration server Oct 15 11:10:34 rivoplus qobuz-connect[5495]: 20261015 11:10:34.936 [5495.5495] INFO SampleApp: Starting Local configuration server Oct 15 11:10:34 rivoplus qobuz-connect[5495]: 20261015 11:10:34.937 [5495.5495] INFO SampleApp: Connected to UNIX socket client 0xabff0908 Oct 15 11:10:35 rivoplus qobuz-connect[5495]: 20261015 11:10:35.036 [5495.5495] INFO SampleApp: Playback volume changed: 75 Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:35 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:35 rivoplus volumio[3566]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Oct 15 11:10:35 rivoplus volumio[3566]: info: Preparing to save Alsa Options, stopping services first Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:35 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPause Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreStateMachine::pause Oct 15 11:10:35 rivoplus volumio[3566]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"S/PDIF + AES/EBU + I2S"}} Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 11:10:35 rivoplus volumio[3566]: info: Found match in Cards Database for ignoring default Mixer Oct 15 11:10:35 rivoplus volumio[3566]: info: Setting mixer PCM for card S/PDIF + AES/EBU + I2S Oct 15 11:10:35 rivoplus volumio[3566]: info: QobuzConnect: setDeactiveState invoked Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:35 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:35 rivoplus volumio[3566]: info: Reconfiguring and Restarting RAAT Plugin due to audio path changes Oct 15 11:10:35 rivoplus volumio[3566]: info: Ignoring Mixers Options Oct 15 11:10:35 rivoplus volumio[3566]: info: Device 5 does not have any Mixer Control Available Oct 15 11:10:35 rivoplus volumio[3566]: info: QobuzConnect: setDeactiveState invoked Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:35 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:35 rivoplus volumio[3566]: info: Reconfiguring and Restarting RAAT Plugin due to audio path changes Oct 15 11:10:35 rivoplus sudo[5523]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:35 rivoplus sudo[5523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:35 rivoplus sudo[5526]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:35 rivoplus sudo[5526]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 15 11:10:35 rivoplus volumio[3566]: info: Updating Volume Controller Parameters: Device: 5 Name: S/PDIF + AES/EBU + I2S Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 15 11:10:35 rivoplus volumio[3566]: info: Disabling external Volume Control Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:10:35 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:35 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:35 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:10:35 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:10:35 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:35.527+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PAUSED positionMs=88349 volume=100 Oct 15 11:10:35 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:35.528+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id=tidal://song/122854182 title="Co Mówimy ?" Oct 15 11:10:35 rivoplus sudo[5523]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:35 rivoplus volumio[3566]: info: Preparing to generate the ALSA configuration file Oct 15 11:10:35 rivoplus sudo[5526]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:35 rivoplus sudo[5534]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:35 rivoplus sudo[5534]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:35 rivoplus sudo[5537]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:35 rivoplus sudo[5537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:35 rivoplus sudo[5543]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 15 11:10:35 rivoplus sudo[5543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:35 rivoplus volumio[3566]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 15 11:10:35 rivoplus volumio[3566]: info: Reading ALSA contributions from plugins. Oct 15 11:10:35 rivoplus volumio[3566]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number '1'. Oct 15 11:10:35 rivoplus sudo[5549]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 15 11:10:35 rivoplus sudo[5549]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:35 rivoplus sudo[5534]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:35 rivoplus sudo[5543]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:35 rivoplus sudo[5537]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:35 rivoplus sudo[5552]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 15 11:10:35 rivoplus sudo[5552]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:35 rivoplus sudo[5549]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 11:10:35 rivoplus qobuz-connect[5495]: 20261015 11:10:35.900 [5495.5495] INFO SampleApp: Stopping Local configuration server Oct 15 11:10:35 rivoplus systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Oct 15 11:10:35 rivoplus sudo[5557]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 15 11:10:35 rivoplus sudo[5557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: inputs , getAdditionalUiSection Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:35 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:35 rivoplus volumio[3566]: info: Not Reporting Auto name since its the default one Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:36 rivoplus volumio[3566]: info: Not Reporting Auto name since its the default one Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Oct 15 11:10:36 rivoplus sudo[5572]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Oct 15 11:10:36 rivoplus sudo[5572]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:36 rivoplus sudo[5572]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:36 rivoplus sudo[5577]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Oct 15 11:10:36 rivoplus sudo[5577]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:36 rivoplus volumio[3566]: info: Asound.conf file written Oct 15 11:10:36 rivoplus sudo[5578]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Oct 15 11:10:36 rivoplus sudo[5578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:36 rivoplus sudo[5581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 15 11:10:36 rivoplus sudo[5581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:36 rivoplus sudo[5581]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:36 rivoplus sudo[5577]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:36 rivoplus kernel: Fine tdm clk setting range (0~2000000), 12287994 Oct 15 11:10:36 rivoplus kernel: Err: can not set rate to 4274967296! Oct 15 11:10:36 rivoplus kernel: Range[3920000 - 500000000] Oct 15 11:10:36 rivoplus kernel: out of value, fixed it Oct 15 11:10:36 rivoplus kernel: id=0 set inskew=0 Oct 15 11:10:36 rivoplus volumio[3566]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Oct 15 11:10:36 rivoplus volumio[3566]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:eARC_TX CDS:0' : Operation not permitted Oct 15 11:10:36 rivoplus volumio[3566]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:I2SIn CLK:0' : Operation not permitted Oct 15 11:10:36 rivoplus volumio[3566]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:SPDIFIN audio samplerate:0' : Operation not permitted Oct 15 11:10:36 rivoplus volumio[3566]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:SPDIFIN Audio Type:0' : Operation not permitted Oct 15 11:10:36 rivoplus volumio[3566]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:Clock Source 5 Validity:0' : Operation not permitted Oct 15 11:10:36 rivoplus volumio[3566]: info: Output device has changed, restarting MPD Oct 15 11:10:36 rivoplus sudo[5585]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Oct 15 11:10:36 rivoplus sudo[5585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:36 rivoplus systemd[1]: Started raat-daemon.service - RAAT DAEMON. Oct 15 11:10:36 rivoplus volumio[3566]: info: Output device has changed, restarting Shairport Sync Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 11:10:36 rivoplus sudo[5578]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:36 rivoplus sudo[5591]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 15 11:10:36 rivoplus sudo[5591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:36 rivoplus sudo[5591]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:36 rivoplus sudo[5593]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 15 11:10:36 rivoplus sudo[5593]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:36 rivoplus systemd[1]: Stopping raat-daemon.service - RAAT DAEMON... Oct 15 11:10:36 rivoplus systemd[1]: raat-daemon.service: Deactivated successfully. Oct 15 11:10:36 rivoplus systemd[1]: Stopped raat-daemon.service - RAAT DAEMON. Oct 15 11:10:36 rivoplus volumio[3566]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 15 11:10:36 rivoplus volumio[3566]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:36 rivoplus volumio[3566]: info: QobuzConnect: setDeactiveState invoked Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:36 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:36 rivoplus volumio[3566]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:36 rivoplus systemd[1]: Started raat-daemon.service - RAAT DAEMON. Oct 15 11:10:36 rivoplus volumio[3566]: info: Output device has changed, restarting MPD Oct 15 11:10:36 rivoplus sudo[5585]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:36 rivoplus volumio[3566]: info: Output device has changed, restarting Shairport Sync Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 11:10:36 rivoplus sudo[5611]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:36 rivoplus sudo[5611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:36 rivoplus sudo[5624]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 15 11:10:36 rivoplus sudo[5624]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:36 rivoplus volumio[3566]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 15 11:10:36 rivoplus volumio[3566]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:36 rivoplus sudo[5617]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 15 11:10:36 rivoplus sudo[5617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:36 rivoplus sudo[5617]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:36 rivoplus volumio[3566]: info: QobuzConnect: setDeactiveState invoked Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:36 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:36 rivoplus volumio[3566]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:36 rivoplus systemd[1]: mpd.service: Deactivated successfully. Oct 15 11:10:36 rivoplus systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 15 11:10:36 rivoplus systemd[1]: mpd.socket: Deactivated successfully. Oct 15 11:10:36 rivoplus sudo[5634]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:36 rivoplus sudo[5634]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:36 rivoplus systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 15 11:10:36 rivoplus sudo[5636]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:36 rivoplus systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 15 11:10:36 rivoplus sudo[5636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:36 rivoplus sudo[5639]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:36 rivoplus sudo[5639]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:36 rivoplus systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 15 11:10:36 rivoplus systemd[1]: Starting mpd.service - Music Player Daemon... Oct 15 11:10:36 rivoplus sudo[5648]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 15 11:10:36 rivoplus sudo[5648]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:36 rivoplus volumio[3566]: info: Executing endpoint metavolumio Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 15 11:10:36 rivoplus sudo[5654]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 15 11:10:36 rivoplus sudo[5654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:36 rivoplus volumio[3566]: info: Executing endpoint metavolumio Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 15 11:10:36 rivoplus volumio[3566]: info: Executing endpoint metavolumio Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 15 11:10:36 rivoplus volumio[3566]: info: MPD Permissions set Oct 15 11:10:36 rivoplus volumio[3566]: info: MPD Permissions set Oct 15 11:10:36 rivoplus volumio[3566]: info: Raat Daemon started successfully Oct 15 11:10:36 rivoplus volumio[3566]: info: Raat Daemon started successfully Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreStateMachine::getcurrentVolume Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::volumioRetrievevolume Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:10:36 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:36 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:36 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:10:36 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:10:36 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:36.905+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PAUSED positionMs=88349 volume=100 Oct 15 11:10:36 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:36.906+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id=tidal://song/122854182 title="Co Mówimy ?" Oct 15 11:10:36 rivoplus sudo[5611]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:36 rivoplus qobuz-connect[5495]: 20261015 11:10:36.944 [5495.5495] INFO SampleApp: shat down connection on UNIX socket Oct 15 11:10:36 rivoplus volumio[3566]: info: Executing endpoint restartRAATSocket Oct 15 11:10:36 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Oct 15 11:10:36 rivoplus systemd[1]: qobuz-connect.service: Deactivated successfully. Oct 15 11:10:36 rivoplus systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Oct 15 11:10:37 rivoplus sudo[5648]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:37 rivoplus sudo[5654]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:37 rivoplus volumio[3566]: info: TidalConnect service stoped! Oct 15 11:10:37 rivoplus volumio[3566]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Oct 15 11:10:37 rivoplus volumio[3566]: info: QobuzConnect: setDeactiveState invoked Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:37 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:37 rivoplus sudo[5658]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 15 11:10:37 rivoplus sudo[5658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:37 rivoplus sudo[5659]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 15 11:10:37 rivoplus sudo[5659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: Not Reporting Auto name since its the default one Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus sudo[5552]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:37 rivoplus sudo[5557]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus systemd[1]: mpd.service: Deactivated successfully. Oct 15 11:10:37 rivoplus systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:37 rivoplus volumio[3566]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Oct 15 11:10:37 rivoplus volumio[3566]: info: Preparing to save Alsa Options, stopping services first Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:37 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPause Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreStateMachine::pause Oct 15 11:10:37 rivoplus volumio[3566]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"S/PDIF + AES/EBU + I2S"}} Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 11:10:37 rivoplus sudo[5639]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:37 rivoplus sudo[5634]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 11:10:37 rivoplus volumio[3566]: info: Found match in Cards Database for ignoring default Mixer Oct 15 11:10:37 rivoplus sudo[5636]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:37 rivoplus volumio[3566]: info: Setting mixer PCM for card S/PDIF + AES/EBU + I2S Oct 15 11:10:37 rivoplus volumio[3566]: info: QobuzConnect: setDeactiveState invoked Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:37 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:37 rivoplus volumio[3566]: info: Reconfiguring and Restarting RAAT Plugin due to audio path changes Oct 15 11:10:37 rivoplus volumio[3566]: info: Ignoring Mixers Options Oct 15 11:10:37 rivoplus volumio[3566]: info: Device 5 does not have any Mixer Control Available Oct 15 11:10:37 rivoplus volumio[3566]: info: QobuzConnect: setDeactiveState invoked Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:37 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:37 rivoplus volumio[3566]: info: Reconfiguring and Restarting RAAT Plugin due to audio path changes Oct 15 11:10:37 rivoplus systemd[1]: mpd.socket: Deactivated successfully. Oct 15 11:10:37 rivoplus systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 15 11:10:37 rivoplus systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 15 11:10:37 rivoplus sudo[5689]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:37 rivoplus sudo[5689]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:37 rivoplus systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 15 11:10:37 rivoplus sudo[5691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:37 rivoplus sudo[5691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 15 11:10:37 rivoplus volumio[3566]: info: Updating Volume Controller Parameters: Device: 5 Name: S/PDIF + AES/EBU + I2S Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 15 11:10:37 rivoplus volumio[3566]: info: Disabling external Volume Control Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 15 11:10:37 rivoplus systemd[1]: Starting mpd.service - Music Player Daemon... Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:10:37 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:10:37 rivoplus systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:37 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:37 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:10:37 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:10:37 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:37.456+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PAUSED positionMs=88349 volume=100 Oct 15 11:10:37 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:37.456+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id=tidal://song/122854182 title="Co Mówimy ?" Oct 15 11:10:37 rivoplus volumio[3566]: info: Preparing to generate the ALSA configuration file Oct 15 11:10:37 rivoplus systemd[1]: qobuz-connect.service: Deactivated successfully. Oct 15 11:10:37 rivoplus systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Oct 15 11:10:37 rivoplus sudo[5699]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:37 rivoplus sudo[5699]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:37 rivoplus sudo[5701]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:37 rivoplus sudo[5701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:37 rivoplus systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Oct 15 11:10:37 rivoplus sudo[5659]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:37 rivoplus sudo[5658]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:37 rivoplus sudo[5709]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 15 11:10:37 rivoplus sudo[5709]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: Not Reporting Auto name since its the default one Oct 15 11:10:37 rivoplus volumio[3566]: info: RAAT: Requesting Headphone Status Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Oct 15 11:10:37 rivoplus volumio[3566]: info: RAAT: Requesting Headphone Status Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Oct 15 11:10:37 rivoplus volumio[3566]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 15 11:10:37 rivoplus volumio[3566]: info: Reading ALSA contributions from plugins. Oct 15 11:10:37 rivoplus sudo[5715]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 15 11:10:37 rivoplus sudo[5689]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:37 rivoplus sudo[5715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:37 rivoplus volumio[3566]: info: TidalConnect service stoped! Oct 15 11:10:37 rivoplus volumio[3566]: info: TidalConnect service stoped! Oct 15 11:10:37 rivoplus volumio[3566]: info: TidalConnect service stoped! Oct 15 11:10:37 rivoplus volumio[3566]: info: Executing endpoint qc_getconfig Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Oct 15 11:10:37 rivoplus volumio[3566]: info: Starting Shairport Sync Oct 15 11:10:37 rivoplus volumio[3566]: info: Starting Shairport Sync Oct 15 11:10:37 rivoplus sudo[5691]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:37 rivoplus volumio[3566]: info: MCU Signalled Headphone Mode Disabled Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Oct 15 11:10:37 rivoplus volumio[3566]: info: Reporting Headphone State: false Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: Updating RAAT Signal Path Oct 15 11:10:37 rivoplus volumio[3566]: info: MCU Signalled Headphone Mode Disabled Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Oct 15 11:10:37 rivoplus volumio[3566]: info: Reporting Headphone State: false Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: Updating RAAT Signal Path Oct 15 11:10:37 rivoplus sudo[5709]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:37 rivoplus sudo[5715]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:37 rivoplus volumio[3566]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Oct 15 11:10:37 rivoplus sudo[5733]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 15 11:10:37 rivoplus sudo[5733]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:37 rivoplus sudo[5736]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 15 11:10:37 rivoplus sudo[5736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:37 rivoplus sudo[5737]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 15 11:10:37 rivoplus sudo[5737]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:37 rivoplus sudo[5699]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:37 rivoplus sudo[5738]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 15 11:10:37 rivoplus sudo[5738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: Not Reporting Auto name since its the default one Oct 15 11:10:37 rivoplus sudo[5701]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:37 rivoplus volumio[3566]: info: Not Reporting Auto name since its the default one Oct 15 11:10:37 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Oct 15 11:10:37 rivoplus sudo[5697]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 15 11:10:37 rivoplus sudo[5697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 15 11:10:38 rivoplus sudo[5697]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Oct 15 11:10:38 rivoplus systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Oct 15 11:10:38 rivoplus systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 15 11:10:38 rivoplus systemd[1]: shairport-sync.service: Deactivated successfully. Oct 15 11:10:38 rivoplus systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 15 11:10:38 rivoplus sudo[5765]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Oct 15 11:10:38 rivoplus sudo[5765]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:38 rivoplus systemd[1]: qobuz-connect.service: Deactivated successfully. Oct 15 11:10:38 rivoplus systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 11:10:38 rivoplus sudo[5772]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Oct 15 11:10:38 rivoplus sudo[5772]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:38 rivoplus systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Oct 15 11:10:38 rivoplus sudo[5736]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:38 rivoplus sudo[5737]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:38 rivoplus systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection Oct 15 11:10:38 rivoplus sudo[5738]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:38 rivoplus sudo[5733]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: inputs , getAdditionalUiSection Oct 15 11:10:38 rivoplus sudo[5765]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:38 rivoplus sudo[5779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Oct 15 11:10:38 rivoplus sudo[5779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:38 rivoplus volumio[3566]: info: Executing endpoint qc_getconfig Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Oct 15 11:10:38 rivoplus sudo[5772]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:38 rivoplus volumio[3566]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 15 11:10:38 rivoplus volumio[3566]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 15 11:10:38 rivoplus sudo[5797]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Oct 15 11:10:38 rivoplus sudo[5797]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:38 rivoplus systemd[1]: Stopping raat-daemon.service - RAAT DAEMON... Oct 15 11:10:38 rivoplus systemd[1]: raat-daemon.service: Deactivated successfully. Oct 15 11:10:38 rivoplus systemd[1]: Stopped raat-daemon.service - RAAT DAEMON. Oct 15 11:10:38 rivoplus volumio[3566]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 15 11:10:38 rivoplus volumio[3566]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 15 11:10:38 rivoplus systemd[1]: Started raat-daemon.service - RAAT DAEMON. Oct 15 11:10:38 rivoplus sudo[5779]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:38 rivoplus volumio[3566]: info: Raat Daemon started successfully Oct 15 11:10:38 rivoplus volumio[3566]: info: Shairport-Sync Started Oct 15 11:10:38 rivoplus volumio[3566]: info: Shairport-Sync Started Oct 15 11:10:38 rivoplus volumio[3566]: info: Executing endpoint qc_getconfig Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Oct 15 11:10:38 rivoplus sudo[5801]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Oct 15 11:10:38 rivoplus sudo[5801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:38 rivoplus sudo[5803]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Oct 15 11:10:38 rivoplus sudo[5803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:38 rivoplus systemd[1]: Stopping raat-daemon.service - RAAT DAEMON... Oct 15 11:10:38 rivoplus systemd[1]: raat-daemon.service: Deactivated successfully. Oct 15 11:10:38 rivoplus systemd[1]: Stopped raat-daemon.service - RAAT DAEMON. Oct 15 11:10:38 rivoplus qobuz-connect[5777]: 20261015 11:10:38.566 [5777.5777] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Oct 15 11:10:38 rivoplus qobuz-connect[5777]: 20261015 11:10:38.572 [5777.5777] INFO VolumeManager: [0xac4c2168]: Setting new playback volume: 75 Oct 15 11:10:38 rivoplus qobuz-connect[5777]: 20261015 11:10:38.572 [5777.5777] INFO VolumeManager: [0xac4c2168]: Setting new mute state: 0 Oct 15 11:10:38 rivoplus qobuz-connect[5777]: 20261015 11:10:38.572 [5777.5777] INFO AudioStreamManager: [0xac4c1ec0]: Setting new audio download buffer size: 1048576 Oct 15 11:10:38 rivoplus qobuz-connect[5777]: 20261015 11:10:38.572 [5777.5777] INFO QobuzConnect: [0xac4c2a30]: Client initialized! Oct 15 11:10:38 rivoplus qobuz-connect[5777]: 20261015 11:10:38.572 [5777.5777] INFO SampleApp: Starting Avahi advertising, name: Rivoplus, service name: _qobuz-connect._tcp Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Oct 15 11:10:38 rivoplus systemd[1]: Started raat-daemon.service - RAAT DAEMON. Oct 15 11:10:38 rivoplus qobuz-connect[5777]: 20261015 11:10:38.605 [5777.5777] INFO LocalConfigManager: [0xac4c1be8]: Starting Local Configuration server Oct 15 11:10:38 rivoplus qobuz-connect[5777]: 20261015 11:10:38.606 [5777.5777] INFO SampleApp: Starting Local configuration server Oct 15 11:10:38 rivoplus qobuz-connect[5777]: 20261015 11:10:38.611 [5777.5777] INFO SampleApp: Connected to UNIX socket client 0xac4ac908 Oct 15 11:10:38 rivoplus sudo[5797]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:38 rivoplus systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Oct 15 11:10:38 rivoplus sudo[5803]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:38 rivoplus sudo[5801]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:38 rivoplus qobuz-connect[5777]: 20261015 11:10:38.716 [5777.5777] INFO SampleApp: Playback volume changed: 75 Oct 15 11:10:38 rivoplus volumio[3566]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Oct 15 11:10:38 rivoplus volumio[3566]: info: QobuzConnect: QOBUZ Connect daemon connected Oct 15 11:10:38 rivoplus volumio[3566]: info: TidalConnect service stoped! Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Oct 15 11:10:38 rivoplus sudo[5836]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Oct 15 11:10:38 rivoplus sudo[5836]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:38 rivoplus sudo[5836]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:38 rivoplus sudo[5842]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Oct 15 11:10:38 rivoplus sudo[5842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:38 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:38 rivoplus volumio[3566]: info: Raat Daemon started successfully Oct 15 11:10:38 rivoplus volumio[3566]: info: TidalConnect service stoped! Oct 15 11:10:38 rivoplus sudo[5843]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Oct 15 11:10:38 rivoplus sudo[5843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:38 rivoplus volumio[3566]: info: Executing endpoint restartRAATSocket Oct 15 11:10:38 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Oct 15 11:10:38 rivoplus sudo[5842]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:38 rivoplus volumio[3566]: info: TidalConnect service stoped! Oct 15 11:10:38 rivoplus sudo[5846]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Oct 15 11:10:38 rivoplus sudo[5846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:39 rivoplus systemd[1]: Stopping raat-daemon.service - RAAT DAEMON... Oct 15 11:10:39 rivoplus systemd[1]: raat-daemon.service: Deactivated successfully. Oct 15 11:10:39 rivoplus systemd[1]: Stopped raat-daemon.service - RAAT DAEMON. Oct 15 11:10:39 rivoplus volumio[3566]: info: TidalConnect service stoped! Oct 15 11:10:39 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:39 rivoplus systemd[1]: Started raat-daemon.service - RAAT DAEMON. Oct 15 11:10:39 rivoplus sudo[5843]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:39 rivoplus volumio[3566]: info: RAAT: Requesting Headphone Status Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Oct 15 11:10:39 rivoplus volumio[3566]: info: RAAT: Requesting Headphone Status Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Oct 15 11:10:39 rivoplus volumio[3566]: info: Asound.conf file written Oct 15 11:10:39 rivoplus systemd[1]: Stopping raat-daemon.service - RAAT DAEMON... Oct 15 11:10:39 rivoplus systemd[1]: raat-daemon.service: Deactivated successfully. Oct 15 11:10:39 rivoplus systemd[1]: Stopped raat-daemon.service - RAAT DAEMON. Oct 15 11:10:39 rivoplus sudo[5880]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 15 11:10:39 rivoplus sudo[5880]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:39 rivoplus systemd[1]: Started raat-daemon.service - RAAT DAEMON. Oct 15 11:10:39 rivoplus sudo[5880]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:39 rivoplus sudo[5846]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:39 rivoplus kernel: Fine tdm clk setting range (0~2000000), 12287994 Oct 15 11:10:39 rivoplus kernel: Err: can not set rate to 4270967296! Oct 15 11:10:39 rivoplus kernel: Range[3920000 - 500000000] Oct 15 11:10:39 rivoplus kernel: out of value, fixed it Oct 15 11:10:39 rivoplus kernel: id=0 set inskew=0 Oct 15 11:10:39 rivoplus volumio[3566]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Oct 15 11:10:39 rivoplus volumio[3566]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:eARC_TX CDS:0' : Operation not permitted Oct 15 11:10:39 rivoplus volumio[3566]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:I2SIn CLK:0' : Operation not permitted Oct 15 11:10:39 rivoplus volumio[3566]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:SPDIFIN audio samplerate:0' : Operation not permitted Oct 15 11:10:39 rivoplus volumio[3566]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:SPDIFIN Audio Type:0' : Operation not permitted Oct 15 11:10:39 rivoplus volumio[3566]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:Clock Source 5 Validity:0' : Operation not permitted Oct 15 11:10:39 rivoplus volumio[3566]: info: Output device has changed, restarting MPD Oct 15 11:10:39 rivoplus volumio[3566]: info: Output device has changed, restarting Shairport Sync Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 11:10:39 rivoplus sudo[5908]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 15 11:10:39 rivoplus sudo[5908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:39 rivoplus sudo[5910]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 15 11:10:39 rivoplus sudo[5910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:39 rivoplus sudo[5908]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:39 rivoplus volumio[3566]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 15 11:10:39 rivoplus volumio[3566]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:39 rivoplus volumio[3566]: info: QobuzConnect: setDeactiveState invoked Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:39 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:39 rivoplus volumio[3566]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:39 rivoplus volumio[3566]: info: Preparing to generate the ALSA configuration file Oct 15 11:10:39 rivoplus volumio[3566]: info: Output device has changed, restarting MPD Oct 15 11:10:39 rivoplus sudo[5919]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:39 rivoplus sudo[5919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:39 rivoplus systemd[1]: mpd.service: Deactivated successfully. Oct 15 11:10:39 rivoplus systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 15 11:10:39 rivoplus volumio[3566]: info: Output device has changed, restarting Shairport Sync Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 11:10:39 rivoplus systemd[1]: mpd.socket: Deactivated successfully. Oct 15 11:10:39 rivoplus systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 15 11:10:39 rivoplus systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 15 11:10:39 rivoplus sudo[5922]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 15 11:10:39 rivoplus sudo[5922]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:39 rivoplus volumio[3566]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 15 11:10:39 rivoplus volumio[3566]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:39 rivoplus volumio[3566]: info: QobuzConnect: setDeactiveState invoked Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:39 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:39 rivoplus volumio[3566]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:39 rivoplus sudo[5922]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:39 rivoplus sudo[5925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 15 11:10:39 rivoplus sudo[5925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:39 rivoplus systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 15 11:10:39 rivoplus systemd[1]: Starting mpd.service - Music Player Daemon... Oct 15 11:10:39 rivoplus sudo[5935]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:39 rivoplus sudo[5935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:39 rivoplus sudo[5939]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:39 rivoplus sudo[5939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:39 rivoplus systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Oct 15 11:10:39 rivoplus sudo[5938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:39 rivoplus sudo[5938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:39 rivoplus systemd[1]: vtcs.service: Deactivated successfully. Oct 15 11:10:39 rivoplus systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Oct 15 11:10:39 rivoplus systemd[1]: mpd.service: Deactivated successfully. Oct 15 11:10:39 rivoplus systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 15 11:10:39 rivoplus sudo[5947]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 15 11:10:39 rivoplus sudo[5947]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:39 rivoplus volumio[3566]: info: Raat Daemon started successfully Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreStateMachine::getcurrentVolume Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::volumioRetrievevolume Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:10:39 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:39 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:39 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:10:39 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:10:39 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:39.841+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PAUSED positionMs=88349 volume=100 Oct 15 11:10:39 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:39.842+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id=tidal://song/122854182 title="Co Mówimy ?" Oct 15 11:10:39 rivoplus sudo[5953]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 15 11:10:39 rivoplus sudo[5953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:39 rivoplus sudo[5919]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:39 rivoplus volumio[3566]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 15 11:10:39 rivoplus volumio[3566]: info: Reading ALSA contributions from plugins. Oct 15 11:10:39 rivoplus volumio[3566]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Oct 15 11:10:39 rivoplus volumio[3566]: info: MPD Permissions set Oct 15 11:10:39 rivoplus volumio[3566]: info: MPD Permissions set Oct 15 11:10:39 rivoplus volumio[3566]: info: Raat Daemon started successfully Oct 15 11:10:39 rivoplus volumio[3566]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 15 11:10:39 rivoplus volumio[3566]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 15 11:10:39 rivoplus volumio[3566]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 15 11:10:39 rivoplus volumio[3566]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 15 11:10:39 rivoplus volumio[3566]: info: MCU Signalled Headphone Mode Disabled Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Oct 15 11:10:39 rivoplus volumio[3566]: info: Reporting Headphone State: false Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:39 rivoplus volumio[3566]: info: Updating RAAT Signal Path Oct 15 11:10:39 rivoplus sudo[5957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Oct 15 11:10:39 rivoplus sudo[5957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:39 rivoplus volumio[3566]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Oct 15 11:10:39 rivoplus volumio[3566]: info: Preparing to save Alsa Options, stopping services first Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:39 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPause Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreStateMachine::pause Oct 15 11:10:39 rivoplus volumio[3566]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"S/PDIF + AES/EBU + I2S"}} Oct 15 11:10:39 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 11:10:39 rivoplus sudo[5959]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Oct 15 11:10:39 rivoplus sudo[5959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:39 rivoplus sudo[5947]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:39 rivoplus sudo[5953]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:39 rivoplus sudo[5939]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:39 rivoplus sudo[5935]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:40 rivoplus sudo[5964]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 15 11:10:40 rivoplus sudo[5938]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:40 rivoplus sudo[5964]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:40 rivoplus sudo[5965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 15 11:10:40 rivoplus sudo[5965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 11:10:40 rivoplus volumio[3566]: info: Found match in Cards Database for ignoring default Mixer Oct 15 11:10:40 rivoplus volumio[3566]: info: Setting mixer PCM for card S/PDIF + AES/EBU + I2S Oct 15 11:10:40 rivoplus volumio[3566]: info: QobuzConnect: setDeactiveState invoked Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:40 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:40 rivoplus volumio[3566]: info: Reconfiguring and Restarting RAAT Plugin due to audio path changes Oct 15 11:10:40 rivoplus volumio[3566]: info: Ignoring Mixers Options Oct 15 11:10:40 rivoplus volumio[3566]: info: Device 5 does not have any Mixer Control Available Oct 15 11:10:40 rivoplus volumio[3566]: info: QobuzConnect: setDeactiveState invoked Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:40 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:40 rivoplus volumio[3566]: info: Reconfiguring and Restarting RAAT Plugin due to audio path changes Oct 15 11:10:40 rivoplus systemd[1]: mpd.socket: Deactivated successfully. Oct 15 11:10:40 rivoplus sudo[5973]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:40 rivoplus systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 15 11:10:40 rivoplus systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 15 11:10:40 rivoplus sudo[5973]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:40 rivoplus systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 15 11:10:40 rivoplus sudo[5975]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:40 rivoplus sudo[5975]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 15 11:10:40 rivoplus volumio[3566]: info: Updating Volume Controller Parameters: Device: 5 Name: S/PDIF + AES/EBU + I2S Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 15 11:10:40 rivoplus volumio[3566]: info: Disabling external Volume Control Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreStateMachine::pushState Oct 15 11:10:40 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::volumioPushState Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::volumioGetState Oct 15 11:10:40 rivoplus volumio[3566]: info: CorePlayQueue::getTrack 0 Oct 15 11:10:40 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output update for this device Oct 15 11:10:40 rivoplus volumio[3566]: info: MRS: Pushing multiroomSync output Oct 15 11:10:40 rivoplus systemd[1]: Starting mpd.service - Music Player Daemon... Oct 15 11:10:40 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:40.146+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" state=STATUS_PAUSED positionMs=88349 volume=100 Oct 15 11:10:40 rivoplus volumio5-onboarding[3882]: time=2026-10-15T11:10:40.147+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.40:44816 @ 0x22d1950" id=tidal://song/122854182 title="Co Mówimy ?" Oct 15 11:10:40 rivoplus qobuz-connect[5777]: 20261015 11:10:40.153 [5777.5777] INFO SampleApp: Stopping Local configuration server Oct 15 11:10:40 rivoplus systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Oct 15 11:10:40 rivoplus systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Oct 15 11:10:40 rivoplus sudo[5959]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:40 rivoplus sudo[5957]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:40 rivoplus sudo[5989]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:40 rivoplus sudo[5989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:40 rivoplus sudo[5991]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 11:10:40 rivoplus sudo[5991]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:40 rivoplus systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Oct 15 11:10:40 rivoplus systemd[1]: vtcs.service: Deactivated successfully. Oct 15 11:10:40 rivoplus systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Oct 15 11:10:40 rivoplus sudo[5997]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 15 11:10:40 rivoplus sudo[5997]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:40 rivoplus volumio[3566]: info: Executing endpoint tc_getconfig Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Oct 15 11:10:40 rivoplus sudo[6003]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 15 11:10:40 rivoplus sudo[6003]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: Not Reporting Auto name since its the default one Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: Not Reporting Auto name since its the default one Oct 15 11:10:40 rivoplus volumio[3566]: info: MCU Signalled Headphone Mode Disabled Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Oct 15 11:10:40 rivoplus volumio[3566]: info: Reporting Headphone State: false Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 11:10:40 rivoplus volumio[3566]: info: Updating RAAT Signal Path Oct 15 11:10:40 rivoplus volumio[3566]: info: Executing endpoint restartRAATSocket Oct 15 11:10:40 rivoplus volumio[3566]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Oct 15 11:10:40 rivoplus volumio[3566]: info: TidalConnect service stoped! Oct 15 11:10:40 rivoplus volumio[3566]: info: TidalConnect service stoped! Oct 15 11:10:40 rivoplus volumio[3566]: info: TidalConnect service stoped! Oct 15 11:10:40 rivoplus volumio[3566]: error: Error starting TidalConnect Command failed: /usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3 Oct 15 11:10:40 rivoplus volumio[3566]: Job for vtcs.service canceled. Oct 15 11:10:40 rivoplus volumio[3566]: {"cmd":"/usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3","code":1,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3\nJob for vtcs.service canceled.\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)","stderr":"Job for vtcs.service canceled.\n","stdout":""} Oct 15 11:10:40 rivoplus volumio[3566]: error: Error starting TidalConnect Command failed: /usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3 Oct 15 11:10:40 rivoplus volumio[3566]: Job for vtcs.service canceled. Oct 15 11:10:40 rivoplus volumio[3566]: {"cmd":"/usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3","code":1,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3\nJob for vtcs.service canceled.\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)","stderr":"Job for vtcs.service canceled.\n","stdout":""} Oct 15 11:10:40 rivoplus volumio[3566]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 15 11:10:40 rivoplus volumio[3566]: Error: Command failed: /usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3 Oct 15 11:10:40 rivoplus volumio[3566]: Job for vtcs.service canceled. Oct 15 11:10:40 rivoplus volumio[3566]: at ChildProcess.exithandler (node:child_process:421:12) Oct 15 11:10:40 rivoplus volumio[3566]: at ChildProcess.emit (node:events:514:28) Oct 15 11:10:40 rivoplus volumio[3566]: at maybeClose (node:internal/child_process:1105:16) Oct 15 11:10:40 rivoplus volumio[3566]: at Socket. (node:internal/child_process:457:11) Oct 15 11:10:40 rivoplus volumio[3566]: at Socket.emit (node:events:514:28) Oct 15 11:10:40 rivoplus volumio[3566]: at Pipe. (node:net:337:12) { Oct 15 11:10:40 rivoplus volumio[3566]: code: 1, Oct 15 11:10:40 rivoplus volumio[3566]: killed: false, Oct 15 11:10:40 rivoplus volumio[3566]: signal: null, Oct 15 11:10:40 rivoplus volumio[3566]: cmd: '/usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3', Oct 15 11:10:40 rivoplus volumio[3566]: stdout: '', Oct 15 11:10:40 rivoplus volumio[3566]: stderr: 'Job for vtcs.service canceled.\n' Oct 15 11:10:40 rivoplus volumio[3566]: } Oct 15 11:10:40 rivoplus volumio[3566]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 15 11:10:40 rivoplus sudo[5973]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:40 rivoplus sudo[5975]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:40 rivoplus sudo[5997]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:40 rivoplus sudo[6003]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:40 rivoplus sudo[6031]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 15 11:10:40 rivoplus sudo[6031]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:40 rivoplus sudo[6032]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 15 11:10:40 rivoplus sudo[6032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 11:10:40 rivoplus qobuz-connect[5777]: 20261015 11:10:40.648 [5777.5777] INFO SampleApp: shat down connection on UNIX socket Oct 15 11:10:40 rivoplus systemd[1]: qobuz-connect.service: Deactivated successfully. Oct 15 11:10:40 rivoplus systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Oct 15 11:10:40 rivoplus sudo[5989]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:40 rivoplus sudo[5981]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 15 11:10:40 rivoplus sudo[5981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 15 11:10:40 rivoplus sudo[5981]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:40 rivoplus sudo[5991]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:40 rivoplus systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Oct 15 11:10:40 rivoplus sudo[5964]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:40 rivoplus sudo[5965]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:40 rivoplus sudo[6032]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:40 rivoplus sudo[6031]: pam_unix(sudo:session): session closed for user root Oct 15 11:10:41 rivoplus sudo[6042]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-15 11:09' Oct 15 11:10:41 rivoplus sudo[6042]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="8ed05bf20f96eb8557ed5652c420f84f39d66325" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0a52c1fb90959ba1872a2fb0225e56fe615b19ac" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed Sep 16 16:52:40 UTC 2026" VOLUMIO_VERSION="4.208" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo Plus" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo Plus" VOLUMIO_HASH="ba37532a86808e19439a6278b2d45f47"