-- Logs begin at Thu 2019-02-14 15:41:58 IST, end at Thu 2026-03-26 21:55:33 IST. -- Mar 26 21:55:02 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:02.875+05:30 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.37:52717 Mar 26 21:55:02 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:02.892+05:30 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.37:52717 @ 0x15971a0" latency=40.033106ms timeout=10s Mar 26 21:55:02 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:02.892+05:30 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.37:52717 @ 0x15971a0" Mar 26 21:55:02 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:02.893+05:30 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.37:52717 @ 0x15971a0" latency=40.783915ms platform=PLATFORM_IOS version=5.260209.0 Mar 26 21:55:02 volumio volumio[1107]: info: Received Get System Info Mar 26 21:55:02 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 21:55:02 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 21:55:02 volumio volumio[1107]: info: Discovery: Getting this device information Mar 26 21:55:02 volumio volumio[1107]: info: CoreCommandRouter::volumioGetState Mar 26 21:55:02 volumio volumio[1107]: info: CorePlayQueue::getTrack 0 Mar 26 21:55:02 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 21:55:02 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 21:55:02 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 21:55:02 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:02.909+05:30 level=INFO msg="emitting device name changed event" component=server peer="192.168.1.37:52717 @ 0x15971a0" name=Volumio Mar 26 21:55:02 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:02.912+05:30 level=INFO msg="emitting device language changed event" component=server peer="192.168.1.37:52717 @ 0x15971a0" language=en Mar 26 21:55:02 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Mar 26 21:55:02 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:02.914+05:30 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.1.37:52717 @ 0x15971a0" timezone=Asia/Calcutta Mar 26 21:55:02 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:02.916+05:30 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.37:52717 @ 0x15971a0" available=true connected=true macAddress=2c:cf:67:05:4e:b2 ip4Address=192.168.1.34/24 ip6Address= Mar 26 21:55:02 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:02.917+05:30 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.37:52717 @ 0x15971a0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 26 21:55:02 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:02.918+05:30 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.1.37:52717 @ 0x15971a0" setupComplete=true Mar 26 21:55:02 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Mar 26 21:55:02 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Mar 26 21:55:02 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 21:55:02 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 26 21:55:03 volumio volumio[1107]: amixer -c 0 info | grep "bcm2835 ALSA" Mar 26 21:55:03 volumio volumio[1107]: amixer -c 1 info | grep "bcm2835 Headphones" Mar 26 21:55:03 volumio volumio[1107]: Card hw:1 'Headphones'/'bcm2835 Headphones' Mar 26 21:55:03 volumio volumio[1107]: amixer -c 2 info | grep "IQaudIODAC" Mar 26 21:55:03 volumio volumio[1107]: Card hw:2 'IQaudIODAC'/'IQaudIODAC' Mar 26 21:55:03 volumio volumio[1107]: amixer -c 2 info | grep "IQaudIO DAC Plus" Mar 26 21:55:03 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:03.203+05:30 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.1.37:52717 @ 0x15971a0" selectedOutputId=2 Mar 26 21:55:03 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 21:55:03 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 21:55:03 volumio volumio[1107]: info: Discovery: Getting this device information Mar 26 21:55:03 volumio volumio[1107]: info: CoreCommandRouter::volumioGetState Mar 26 21:55:03 volumio volumio[1107]: info: CorePlayQueue::getTrack 0 Mar 26 21:55:03 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 21:55:03 volumio volumio[1107]: info: Received Get System Info Mar 26 21:55:03 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 21:55:03 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 21:55:03 volumio volumio[1107]: info: Discovery: Getting this device information Mar 26 21:55:03 volumio volumio[1107]: info: CoreCommandRouter::volumioGetState Mar 26 21:55:03 volumio volumio[1107]: info: CorePlayQueue::getTrack 0 Mar 26 21:55:03 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 21:55:03 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:03.234+05:30 level=INFO msg="emitting software info changed event" component=server peer="192.168.1.37:52717 @ 0x15971a0" currentVersion=3.912 latestVersion=3.912 Mar 26 21:55:03 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:03.234+05:30 level=INFO msg="emitting software update progress event" component=server peer="192.168.1.37:52717 @ 0x15971a0" status=UPDATE_STATUS_NONE progress=0 Mar 26 21:55:03 volumio volumio[1107]: verbose: New Socket.io Connection to 192.168.1.34:3000 from 192.168.1.37 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Mar 26 21:55:03 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 21:55:03 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 21:55:03 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 21:55:03 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 21:55:04 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:04.203+05:30 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.37:52717 @ 0x15971a0" latency=39.960276ms platform=PLATFORM_IOS version=5.260209.0 Mar 26 21:55:04 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:04.205+05:30 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.37:52717 @ 0x15971a0" latency=40.187982ms timeout=10s Mar 26 21:55:04 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:04.205+05:30 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.37:52717 @ 0x15971a0" Mar 26 21:55:04 volumio volumio[1107]: info: Received Get System Info Mar 26 21:55:04 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 21:55:04 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 21:55:04 volumio volumio[1107]: info: Discovery: Getting this device information Mar 26 21:55:04 volumio volumio[1107]: info: CoreCommandRouter::volumioGetState Mar 26 21:55:04 volumio volumio[1107]: info: CorePlayQueue::getTrack 0 Mar 26 21:55:04 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 21:55:04 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:04.208+05:30 level=INFO msg="emitting device name changed event" component=server peer="192.168.1.37:52717 @ 0x15971a0" name=Volumio Mar 26 21:55:04 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:04.209+05:30 level=INFO msg="emitting device language changed event" component=server peer="192.168.1.37:52717 @ 0x15971a0" language=en Mar 26 21:55:04 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Mar 26 21:55:04 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:04.211+05:30 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.1.37:52717 @ 0x15971a0" timezone=Asia/Calcutta Mar 26 21:55:04 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:04.212+05:30 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.37:52717 @ 0x15971a0" available=true connected=true macAddress=2c:cf:67:05:4e:b2 ip4Address=192.168.1.34/24 ip6Address= Mar 26 21:55:04 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:04.214+05:30 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.37:52717 @ 0x15971a0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 26 21:55:04 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:04.214+05:30 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.1.37:52717 @ 0x15971a0" setupComplete=true Mar 26 21:55:04 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Mar 26 21:55:04 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Mar 26 21:55:04 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 21:55:04 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 26 21:55:04 volumio volumio[1107]: amixer -c 0 info | grep "bcm2835 ALSA" Mar 26 21:55:04 volumio volumio[1107]: amixer -c 1 info | grep "bcm2835 Headphones" Mar 26 21:55:04 volumio volumio[1107]: Card hw:1 'Headphones'/'bcm2835 Headphones' Mar 26 21:55:04 volumio volumio[1107]: amixer -c 2 info | grep "IQaudIODAC" Mar 26 21:55:04 volumio volumio[1107]: Card hw:2 'IQaudIODAC'/'IQaudIODAC' Mar 26 21:55:04 volumio volumio[1107]: amixer -c 2 info | grep "IQaudIO DAC Plus" Mar 26 21:55:04 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:04.483+05:30 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.1.37:52717 @ 0x15971a0" selectedOutputId=2 Mar 26 21:55:04 volumio volumio[1107]: info: Received Get System Info Mar 26 21:55:04 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 21:55:04 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 21:55:04 volumio volumio[1107]: info: Discovery: Getting this device information Mar 26 21:55:04 volumio volumio[1107]: info: CoreCommandRouter::volumioGetState Mar 26 21:55:04 volumio volumio[1107]: info: CorePlayQueue::getTrack 0 Mar 26 21:55:04 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 21:55:04 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:04.505+05:30 level=INFO msg="emitting software info changed event" component=server peer="192.168.1.37:52717 @ 0x15971a0" currentVersion=3.912 latestVersion=3.912 Mar 26 21:55:04 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:04.505+05:30 level=INFO msg="emitting software update progress event" component=server peer="192.168.1.37:52717 @ 0x15971a0" status=UPDATE_STATUS_NONE progress=0 Mar 26 21:55:04 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 21:55:04 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 21:55:05 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:05.722+05:30 level=INFO msg="new address was allocated" component=ble/conn old=1 new=2 Mar 26 21:55:05 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:06 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:06 volumio kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Mar 26 21:55:07 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:07.162+05:30 level=INFO msg="new address was allocated" component=ble/conn old=2 new=3 Mar 26 21:55:07 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:11 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:11.021+05:30 level=ERROR msg="failed to read message" component=conn/ws remoteAddr=192.168.1.37:52717 error="websocket: close 1006 (abnormal closure): unexpected EOF" Mar 26 21:55:11 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:11.021+05:30 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.1.37:52717 Mar 26 21:55:11 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:11.021+05:30 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.1.37:52717 Mar 26 21:55:11 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:12 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:12.893+05:30 level=ERROR msg="failed to notify all device data" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.37:52717 @ 0x15971a0" latency=40.033106ms timeout=10s error="failed to get logged user: could not get MyVolumio token: context deadline exceeded" Mar 26 21:55:14 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:14.205+05:30 level=ERROR msg="failed to notify all device data" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.37:52717 @ 0x15971a0" latency=40.187982ms timeout=10s error="failed to get logged user: could not get MyVolumio token: context deadline exceeded" Mar 26 21:55:14 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:14.589+05:30 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.37:53059 Mar 26 21:55:14 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:14.612+05:30 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.37:53059 @ 0x1760ba0" latency=38.761779ms platform=PLATFORM_IOS version=5.260209.0 Mar 26 21:55:14 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:14.613+05:30 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.37:53059 @ 0x1760ba0" latency=39.546977ms timeout=10s Mar 26 21:55:14 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:14.613+05:30 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" Mar 26 21:55:14 volumio volumio[1107]: info: Received Get System Info Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 21:55:14 volumio volumio[1107]: info: Discovery: Getting this device information Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::volumioGetState Mar 26 21:55:14 volumio volumio[1107]: info: CorePlayQueue::getTrack 0 Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 21:55:14 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:14.617+05:30 level=INFO msg="emitting device name changed event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" name=Volumio Mar 26 21:55:14 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:14.617+05:30 level=INFO msg="emitting device language changed event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" language=en Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Mar 26 21:55:14 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:14.619+05:30 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" timezone=Asia/Calcutta Mar 26 21:55:14 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:14.621+05:30 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" available=true connected=true macAddress=2c:cf:67:05:4e:b2 ip4Address=192.168.1.34/24 ip6Address= Mar 26 21:55:14 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:14.623+05:30 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 26 21:55:14 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:14.624+05:30 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" setupComplete=true Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 26 21:55:14 volumio volumio[1107]: amixer -c 0 info | grep "bcm2835 ALSA" Mar 26 21:55:14 volumio volumio[1107]: amixer -c 1 info | grep "bcm2835 Headphones" Mar 26 21:55:14 volumio volumio[1107]: Card hw:1 'Headphones'/'bcm2835 Headphones' Mar 26 21:55:14 volumio volumio[1107]: amixer -c 2 info | grep "IQaudIODAC" Mar 26 21:55:14 volumio volumio[1107]: Card hw:2 'IQaudIODAC'/'IQaudIODAC' Mar 26 21:55:14 volumio volumio[1107]: amixer -c 2 info | grep "IQaudIO DAC Plus" Mar 26 21:55:14 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:14.890+05:30 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" selectedOutputId=2 Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 21:55:14 volumio volumio[1107]: info: Discovery: Getting this device information Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::volumioGetState Mar 26 21:55:14 volumio volumio[1107]: info: CorePlayQueue::getTrack 0 Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 21:55:14 volumio volumio[1107]: verbose: New Socket.io Connection to 192.168.1.34:3000 from 192.168.1.37 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 21:55:14 volumio volumio[1107]: info: Received Get System Info Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 21:55:14 volumio volumio[1107]: info: Discovery: Getting this device information Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::volumioGetState Mar 26 21:55:14 volumio volumio[1107]: info: CorePlayQueue::getTrack 0 Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 21:55:14 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:14.912+05:30 level=INFO msg="emitting software info changed event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" currentVersion=3.912 latestVersion=3.912 Mar 26 21:55:14 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:14.912+05:30 level=INFO msg="emitting software update progress event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" status=UPDATE_STATUS_NONE progress=0 Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 21:55:14 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 21:55:15 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:15.708+05:30 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.37:53059 @ 0x1760ba0" latency=40.576834ms platform=PLATFORM_IOS version=5.260209.0 Mar 26 21:55:15 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:15.709+05:30 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.37:53059 @ 0x1760ba0" latency=39.087219ms timeout=10s Mar 26 21:55:15 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:15.709+05:30 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" Mar 26 21:55:15 volumio volumio[1107]: info: Received Get System Info Mar 26 21:55:15 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 21:55:15 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 21:55:15 volumio volumio[1107]: info: Discovery: Getting this device information Mar 26 21:55:15 volumio volumio[1107]: info: CoreCommandRouter::volumioGetState Mar 26 21:55:15 volumio volumio[1107]: info: CorePlayQueue::getTrack 0 Mar 26 21:55:15 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 21:55:15 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:15.712+05:30 level=INFO msg="emitting device name changed event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" name=Volumio Mar 26 21:55:15 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:15.713+05:30 level=INFO msg="emitting device language changed event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" language=en Mar 26 21:55:15 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Mar 26 21:55:15 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:15.715+05:30 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" timezone=Asia/Calcutta Mar 26 21:55:15 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:15.716+05:30 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" available=true connected=true macAddress=2c:cf:67:05:4e:b2 ip4Address=192.168.1.34/24 ip6Address= Mar 26 21:55:15 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:15.716+05:30 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 26 21:55:15 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:15.717+05:30 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" setupComplete=true Mar 26 21:55:15 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Mar 26 21:55:15 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Mar 26 21:55:15 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 21:55:15 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 26 21:55:15 volumio volumio[1107]: amixer -c 0 info | grep "bcm2835 ALSA" Mar 26 21:55:15 volumio volumio[1107]: amixer -c 1 info | grep "bcm2835 Headphones" Mar 26 21:55:15 volumio volumio[1107]: Card hw:1 'Headphones'/'bcm2835 Headphones' Mar 26 21:55:15 volumio volumio[1107]: amixer -c 2 info | grep "IQaudIODAC" Mar 26 21:55:15 volumio volumio[1107]: Card hw:2 'IQaudIODAC'/'IQaudIODAC' Mar 26 21:55:15 volumio volumio[1107]: amixer -c 2 info | grep "IQaudIO DAC Plus" Mar 26 21:55:15 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:15.984+05:30 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" selectedOutputId=2 Mar 26 21:55:16 volumio volumio[1107]: info: Received Get System Info Mar 26 21:55:16 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 21:55:16 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 21:55:16 volumio volumio[1107]: info: Discovery: Getting this device information Mar 26 21:55:16 volumio volumio[1107]: info: CoreCommandRouter::volumioGetState Mar 26 21:55:16 volumio volumio[1107]: info: CorePlayQueue::getTrack 0 Mar 26 21:55:16 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 21:55:16 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:16.007+05:30 level=INFO msg="emitting software info changed event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" currentVersion=3.912 latestVersion=3.912 Mar 26 21:55:16 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:16.008+05:30 level=INFO msg="emitting software update progress event" component=server peer="192.168.1.37:53059 @ 0x1760ba0" status=UPDATE_STATUS_NONE progress=0 Mar 26 21:55:16 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 21:55:16 volumio volumio[1107]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 21:55:16 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:16.201+05:30 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Mar 26 21:55:16 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:16.202+05:30 level=ERROR msg="failed to send response" component=server dst="00:00:00:00:00:00%02 @ 0x15971a0" id=1752807659 status=STATUS_UNKNOWN error="peer is gone" Mar 26 21:55:18 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:18.803+05:30 level=INFO msg="new address was allocated" component=ble/conn old=3 new=4 Mar 26 21:55:19 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:19 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:19 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:19.509+05:30 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Mar 26 21:55:19 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:19.509+05:30 level=ERROR msg="failed to send response" component=server dst="00:00:00:00:00:00%02 @ 0x15971a0" id=1460087518 status=STATUS_UNKNOWN error="peer is gone" Mar 26 21:55:21 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:21.802+05:30 level=INFO msg="new address was allocated" component=ble/conn old=4 new=5 Mar 26 21:55:22 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:22 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:23 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:23.542+05:30 level=INFO msg="new address was allocated" component=ble/conn old=5 new=6 Mar 26 21:55:23 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:23 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:24 volumio kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Mar 26 21:55:24 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:24.614+05:30 level=ERROR msg="failed to notify all device data" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.37:53059 @ 0x1760ba0" latency=39.546977ms timeout=10s error="failed to get logged user: could not get MyVolumio token: context deadline exceeded" Mar 26 21:55:25 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:25.102+05:30 level=INFO msg="new address was allocated" component=ble/conn old=6 new=7 Mar 26 21:55:25 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:25 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:25 volumio kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Mar 26 21:55:25 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:25.709+05:30 level=ERROR msg="failed to notify all device data" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.37:53059 @ 0x1760ba0" latency=39.087219ms timeout=10s error="failed to get logged user: could not get MyVolumio token: context deadline exceeded" Mar 26 21:55:25 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:25.923+05:30 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.1.37:53059 Mar 26 21:55:25 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:25.923+05:30 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.1.37:53059 Mar 26 21:55:25 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:25.933+05:30 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.37:53576 Mar 26 21:55:26 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:26.632+05:30 level=INFO msg="new address was allocated" component=ble/conn old=7 new=8 Mar 26 21:55:26 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:27 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:27 volumio kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Mar 26 21:55:28 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:28.102+05:30 level=INFO msg="new address was allocated" component=ble/conn old=8 new=9 Mar 26 21:55:28 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:28 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:29 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:29.722+05:30 level=INFO msg="new address was allocated" component=ble/conn old=9 new=10 Mar 26 21:55:29 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:30 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:30 volumio kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Mar 26 21:55:31 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:31.192+05:30 level=INFO msg="new address was allocated" component=ble/conn old=10 new=11 Mar 26 21:55:31 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:31 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:31 volumio kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Mar 26 21:55:32 volumio volumio5-onboarding[1320]: time=2026-03-26T21:55:32.632+05:30 level=INFO msg="new address was allocated" component=ble/conn old=11 new=12 Mar 26 21:55:32 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:33 volumio dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.14" (uid=0 pid=1320 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=790 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 26 21:55:33 volumio volumio[1107]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 21:55:33 volumio volumio[1107]: [t [Error]: A network error (such as timeout, interrupted connection or unreachable host) has occurred.] { Mar 26 21:55:33 volumio volumio[1107]: code: 'auth/network-request-failed', Mar 26 21:55:33 volumio volumio[1107]: a: null Mar 26 21:55:33 volumio volumio[1107]: } Mar 26 21:55:33 volumio volumio[1107]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 21:55:33 volumio sudo[9746]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-03-26 21:54 Mar 26 21:55:33 volumio sudo[9746]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"