Oct 02 17:14:00 crow volumio[1257]: info: Received Get System Info Oct 02 17:14:00 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 17:14:00 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 17:14:00 crow volumio[1257]: info: Discovery: Getting this device information Oct 02 17:14:00 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:00 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:00 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 17:14:00 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 02 17:14:00 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 02 17:14:00 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:00.209+09:00 level=INFO msg="enabling local network discovery" Oct 02 17:14:00 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:00.238+09:00 level=INFO msg="enabling BLE discovery" Oct 02 17:14:00 crow volumio[1257]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 02 17:14:00 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 02 17:14:00 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 02 17:14:00 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 02 17:14:00 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 02 17:14:00 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 02 17:14:00 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 02 17:14:00 crow volumio[1257]: info: CoreCommandRouter::volumioGetBrowseSources Oct 02 17:14:00 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 02 17:14:00 crow volumio[1257]: info: Updating MyVolumio device info Oct 02 17:14:00 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 02 17:14:00 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 02 17:14:00 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 02 17:14:00 crow volumio[1257]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 02 17:14:01 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:01.285+09:00 level=INFO msg="service successfully established" component=discovery/localnet Oct 02 17:14:01 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:01.385+09:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=172.30.1.28:54940 Oct 02 17:14:01 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:01.405+09:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="172.30.1.28:54940 @ 0x3137080" latency=32.322633ms timeout=20s Oct 02 17:14:01 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:01.405+09:00 level=INFO msg="emitting device capabilities changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" Oct 02 17:14:01 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:01.406+09:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="172.30.1.28:54940 @ 0x3137080" latency=32.943997ms platform=PLATFORM_ANDROID version=6.260930.0 Oct 02 17:14:01 crow volumio[1257]: info: Received Get System Info Oct 02 17:14:01 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 17:14:01 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 17:14:01 crow volumio[1257]: info: Discovery: Getting this device information Oct 02 17:14:01 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:01 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:01 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 17:14:01 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 02 17:14:01 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 02 17:14:01 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:01.416+09:00 level=INFO msg="emitting device name changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" name=Crow Oct 02 17:14:01 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:01.428+09:00 level=INFO msg="emitting device language changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" language=ko Oct 02 17:14:01 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Oct 02 17:14:01 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:01.467+09:00 level=INFO msg="emitting device timezone changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" timezone=Asia/Seoul Oct 02 17:14:01 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:01.468+09:00 level=INFO msg="emitting ethernet info changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" available=true connected=false macAddress= ip4Address= ip6Address= Oct 02 17:14:01 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:01.485+09:00 level=INFO msg="emitting wifi info changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" available=true connected=true macAddress=dc:a6:32:93:ce:4e ip4Address=172.30.1.45/24 ip6Address= ssid=KT_WLAN_7927_5GHz Oct 02 17:14:01 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:01.487+09:00 level=INFO msg="emitting device setup status changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" setupComplete=true Oct 02 17:14:01 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Oct 02 17:14:01 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 02 17:14:01 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 02 17:14:01 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 02 17:14:02 crow volumio[1257]: amixer -c 0 info | grep "bcm2835 ALSA" Oct 02 17:14:02 crow volumio[1257]: amixer -c 1 info | grep "bcm2835 Headphones" Oct 02 17:14:02 crow volumio[1257]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Oct 02 17:14:02 crow volumio[1257]: amixer -c 2 info | grep "vc4-hdmi-0" Oct 02 17:14:02 crow volumio[1257]: Card sysdefault:2 'vc4hdmi0'/'vc4-hdmi-0' Oct 02 17:14:02 crow volumio[1257]: amixer -c 3 info | grep "vc4-hdmi-1" Oct 02 17:14:02 crow volumio[1257]: Card sysdefault:3 'vc4hdmi1'/'vc4-hdmi-1' Oct 02 17:14:02 crow volumio[1257]: amixer -c 4 info | grep "snd_rpi_hifiberry_dacplus" Oct 02 17:14:02 crow volumio[1257]: Card sysdefault:4 'sndrpihifiberry'/'snd_rpi_hifiberry_dacplus' Oct 02 17:14:02 crow volumio[1257]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 4 Oct 02 17:14:02 crow volumio[1257]: /bin/sh: 1: /usr/local/bin/alsacap: not found Oct 02 17:14:02 crow volumio[1257]: {"cmd":"/usr/local/bin/alsacap -C 4","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 4\n/bin/sh: 1: /usr/local/bin/alsacap: not found\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)"} Oct 02 17:14:02 crow volumio[1257]: amixer -c 4 info | grep "HiFiBerry Amp2" Oct 02 17:14:03 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:03.094+09:00 level=INFO msg="emitting audio outputs changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" selectedOutputId=4 Oct 02 17:14:03 crow volumio[1257]: info: Received Get System Info Oct 02 17:14:03 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 17:14:03 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 17:14:03 crow volumio[1257]: info: Discovery: Getting this device information Oct 02 17:14:03 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:03 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:03 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 17:14:03 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:03.188+09:00 level=INFO msg="emitting software info changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" currentVersion=4.119 latestVersion=4.119 Oct 02 17:14:03 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:03.188+09:00 level=INFO msg="emitting software update progress event" component=server peer="172.30.1.28:54940 @ 0x3137080" status=UPDATE_STATUS_NONE progress=0 Oct 02 17:14:03 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:03.188+09:00 level=INFO msg="emitting user changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" userId=UjFQ3kxjihZcX4Qz9RMIJwx4pNy1 Oct 02 17:14:03 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:03.189+09:00 level=INFO msg="emitting music providers changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" providers=3 Oct 02 17:14:03 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 17:14:03 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 17:14:03 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 02 17:14:04 crow volumio[1257]: info: MYVOLUMIO: Adding device Oct 02 17:14:04 crow volumio[1257]: info: MYVOLUMIO: Evaluating Server Oct 02 17:14:04 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:04.995+09:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="172.30.1.28:54940 @ 0x3137080" latency=42.446961ms platform=PLATFORM_ANDROID version=6.260930.0 Oct 02 17:14:04 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:04.995+09:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="172.30.1.28:54940 @ 0x3137080" latency=41.582737ms timeout=20s Oct 02 17:14:04 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:04.995+09:00 level=INFO msg="emitting device capabilities changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" Oct 02 17:14:06 crow volumio[1257]: info: Received Get System Info Oct 02 17:14:06 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 17:14:06 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 17:14:06 crow volumio[1257]: info: Discovery: Getting this device information Oct 02 17:14:06 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:06 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:06 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 17:14:06 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:06.317+09:00 level=INFO msg="emitting device name changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" name=Crow Oct 02 17:14:06 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:06.318+09:00 level=INFO msg="emitting device language changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" language=ko Oct 02 17:14:06 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Oct 02 17:14:06 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:06.624+09:00 level=INFO msg="emitting device timezone changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" timezone=Asia/Seoul Oct 02 17:14:06 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:06.625+09:00 level=INFO msg="emitting ethernet info changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" available=true connected=false macAddress= ip4Address= ip6Address= Oct 02 17:14:06 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:06.629+09:00 level=INFO msg="emitting wifi info changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" available=true connected=true macAddress=dc:a6:32:93:ce:4e ip4Address=172.30.1.45/24 ip6Address= ssid=KT_WLAN_7927_5GHz Oct 02 17:14:06 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:06.629+09:00 level=INFO msg="emitting device setup status changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" setupComplete=true Oct 02 17:14:06 crow volumio[1257]: info: Setting Geolocation for MyVolumio to as1 Oct 02 17:14:06 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 02 17:14:06 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 02 17:14:06 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 02 17:14:06 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Oct 02 17:14:06 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 02 17:14:06 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 02 17:14:06 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 02 17:14:06 crow volumio[1257]: amixer -c 0 info | grep "bcm2835 ALSA" Oct 02 17:14:07 crow volumio[1257]: amixer -c 1 info | grep "bcm2835 Headphones" Oct 02 17:14:07 crow volumio[1257]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Oct 02 17:14:07 crow volumio[1257]: amixer -c 2 info | grep "vc4-hdmi-0" Oct 02 17:14:07 crow volumio[1257]: Card sysdefault:2 'vc4hdmi0'/'vc4-hdmi-0' Oct 02 17:14:07 crow volumio[1257]: amixer -c 3 info | grep "vc4-hdmi-1" Oct 02 17:14:07 crow volumio[1257]: Card sysdefault:3 'vc4hdmi1'/'vc4-hdmi-1' Oct 02 17:14:07 crow volumio[1257]: amixer -c 4 info | grep "snd_rpi_hifiberry_dacplus" Oct 02 17:14:07 crow volumio[1257]: Card sysdefault:4 'sndrpihifiberry'/'snd_rpi_hifiberry_dacplus' Oct 02 17:14:07 crow volumio[1257]: info: Updating MyVolumio device info Oct 02 17:14:07 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 02 17:14:07 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 02 17:14:07 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 02 17:14:08 crow volumio[1257]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 02 17:14:08 crow volumio[1257]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 4 Oct 02 17:14:08 crow volumio[1257]: /bin/sh: 1: /usr/local/bin/alsacap: not found Oct 02 17:14:08 crow volumio[1257]: {"cmd":"/usr/local/bin/alsacap -C 4","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 4\n/bin/sh: 1: /usr/local/bin/alsacap: not found\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)"} Oct 02 17:14:08 crow volumio[1257]: amixer -c 4 info | grep "HiFiBerry Amp2" Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.407+09:00 level=INFO msg="emitting audio outputs changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" selectedOutputId=4 Oct 02 17:14:08 crow volumio[1257]: info: Received Get System Info Oct 02 17:14:08 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 17:14:08 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 17:14:08 crow volumio[1257]: info: Discovery: Getting this device information Oct 02 17:14:08 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:08 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:08 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.539+09:00 level=INFO msg="emitting plugins changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" plugins=74 Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.556+09:00 level=INFO msg="emitting software info changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" currentVersion=4.119 latestVersion=4.119 Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.558+09:00 level=INFO msg="emitting software update progress event" component=server peer="172.30.1.28:54940 @ 0x3137080" status=UPDATE_STATUS_NONE progress=0 Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.559+09:00 level=INFO msg="emitting user changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" userId=UjFQ3kxjihZcX4Qz9RMIJwx4pNy1 Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.560+09:00 level=INFO msg="emitting music providers changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" providers=3 Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.566+09:00 level=INFO msg="emitting plugins changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" plugins=74 Oct 02 17:14:08 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:08 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.591+09:00 level=INFO msg="emitting player state changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" state=STATUS_STOPPED positionMs=0 volume=5 Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.591+09:00 level=INFO msg="emitting player state changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" state=STATUS_STOPPED positionMs=0 volume=5 Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.592+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99555531" title="DEEP FM - amgradio.ru" Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.593+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99555531" title="DEEP FM - amgradio.ru" Oct 02 17:14:08 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:08 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.639+09:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="172.30.1.28:54940 @ 0x3137080" latency=33.825426ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.642+09:00 level=INFO msg="emitting player state changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" state=STATUS_STOPPED positionMs=0 volume=5 Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.643+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99555531" title="DEEP FM - amgradio.ru" Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.658+09:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940 @ 0x3137080" latency=30.48863ms timeout=10s Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.850+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940 @ 0x3137080" latency=30.48863ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=190.547996ms Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.871+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940 @ 0x3137080" latency=30.48863ms timeout=10s endpoint=https://functions.volumio.cloud duration=210.393023ms Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.871+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940 @ 0x3137080" latency=30.48863ms timeout=10s endpoint=https://functions.volumio.cloud duration=210.913387ms Oct 02 17:14:08 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:08.911+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940 @ 0x3137080" latency=30.48863ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=252.493993ms Oct 02 17:14:09 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:09.232+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940 @ 0x3137080" latency=30.48863ms timeout=10s endpoint=http://pushupdates.volumio.org duration=571.192567ms Oct 02 17:14:09 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:09.471+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940 @ 0x3137080" latency=30.48863ms timeout=10s endpoint=https://www.googleapis.com duration=812.452367ms Oct 02 17:14:09 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:09.541+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940 @ 0x3137080" latency=30.48863ms timeout=10s endpoint=https://securetoken.googleapis.com duration=882.262002ms Oct 02 17:14:09 crow volumio[1257]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 02 17:14:09 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:09.691+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940 @ 0x3137080" latency=30.48863ms timeout=10s endpoint=http://plugins.volumio.org duration=1.031515332s Oct 02 17:14:10 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:10.009+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940 @ 0x3137080" latency=30.48863ms timeout=10s endpoint=https://google.com duration=1.351013898s Oct 02 17:14:10 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:10.015+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940 @ 0x3137080" latency=30.48863ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=1.353823664s Oct 02 17:14:10 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:10.138+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940 @ 0x3137080" latency=30.48863ms timeout=10s endpoint=https://database.volumio.cloud duration=1.477685955s Oct 02 17:14:10 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:10.176+09:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940 @ 0x3137080" latency=30.48863ms timeout=10s endpoint=http://cddb.volumio.org duration=1.516899086s error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 02 17:14:10 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:10.181+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940 @ 0x3137080" latency=30.48863ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=1.519143711s Oct 02 17:14:10 crow sudo[2017]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 02 17:14:10 crow sudo[2017]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 17:14:10 crow sudo[2017]: pam_unix(sudo:session): session closed for user root Oct 02 17:14:10 crow sudo[2020]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 02 17:14:10 crow sudo[2020]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 17:14:10 crow sudo[2020]: pam_unix(sudo:session): session closed for user root Oct 02 17:14:11 crow volumio[1257]: verbose: New Socket.io Connection to 172.30.1.45 from 172.30.1.28 UA: Mozilla/5.0 (Linux; Android 16; SM-S931N Build/BP4A.251205.006; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/153.0.8010.36 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 12 Oct 02 17:14:11 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 02 17:14:11 crow volumio[1257]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 02 17:14:11 crow volumio[1257]: info: Completed starting MyVolumio Plugin Oct 02 17:14:11 crow volumio[1257]: [Metrics] CommandRouter: 87s 600.27ms Oct 02 17:14:11 crow volumio[1257]: info: CoreCommandRouter::volumiosetStartupVolume Oct 02 17:14:11 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 02 17:14:11 crow volumio[1257]: info: VolumeController:: Setting startup Volume 5 Oct 02 17:14:11 crow volumio[1257]: info: VolumeController::SetAlsaVolume5 Oct 02 17:14:11 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 02 17:14:11 crow volumio[1257]: info: CoreCommandRouter::Close All Modals sent Oct 02 17:14:11 crow volumio[1257]: info: CoreCommandRouter::Close All Modals sent Oct 02 17:14:11 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:11 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:11 crow volumio[1257]: info: CoreStateMachine::pushState Oct 02 17:14:11 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:11 crow volumio[1257]: info: CoreCommandRouter::volumioPushState Oct 02 17:14:12 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:12.191+09:00 level=INFO msg="emitting player state changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" state=STATUS_STOPPED positionMs=0 volume=5 Oct 02 17:14:12 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:12.191+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="172.30.1.28:54940 @ 0x3137080" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99555531" title="DEEP FM - amgradio.ru" Oct 02 17:14:12 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 02 17:14:12 crow volumio[1257]: info: CoreCommandRouter::volumioGetVisibleSources Oct 02 17:14:12 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 02 17:14:12 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:12 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:12 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 02 17:14:12 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 02 17:14:12 crow volumio[1257]: info: Received Get System Info Oct 02 17:14:12 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 17:14:12 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 17:14:12 crow volumio[1257]: info: Discovery: Getting this device information Oct 02 17:14:12 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:12 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:12 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 17:14:12 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:12 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:12 crow volumio[1257]: info: Listing playlists Oct 02 17:14:12 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 02 17:14:12 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 02 17:14:12 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 02 17:14:12 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 02 17:14:12 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 02 17:14:13 crow sudo[2041]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 02 17:14:13 crow sudo[2041]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 17:14:13 crow sudo[2041]: pam_unix(sudo:session): session closed for user root Oct 02 17:14:13 crow sudo[2044]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 02 17:14:13 crow sudo[2044]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 17:14:13 crow sudo[2044]: pam_unix(sudo:session): session closed for user root Oct 02 17:14:13 crow volumio[1257]: verbose: New Socket.io Connection to 172.30.1.45 from 172.30.1.28 UA: Mozilla/5.0 (Linux; Android 16; SM-S931N Build/BP4A.251205.006; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/153.0.8010.36 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 12 Oct 02 17:14:13 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 02 17:14:13 crow volumio[1257]: info: CoreCommandRouter::volumioGetVisibleSources Oct 02 17:14:13 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 02 17:14:13 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:13 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:13 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 02 17:14:13 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 02 17:14:13 crow volumio[1257]: info: Received Get System Info Oct 02 17:14:13 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 17:14:13 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 17:14:13 crow volumio[1257]: info: Discovery: Getting this device information Oct 02 17:14:13 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:13 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:13 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 17:14:13 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:13 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:14 crow volumio[1257]: info: Listing playlists Oct 02 17:14:14 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 02 17:14:14 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 02 17:14:14 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 02 17:14:15 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 17:14:15 crow volumio[1257]: info: Received Get System Info Oct 02 17:14:15 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 17:14:15 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 17:14:15 crow volumio[1257]: info: Discovery: Getting this device information Oct 02 17:14:15 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:15 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:15 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 17:14:15 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 02 17:14:16 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 17:14:16 crow volumio[1257]: info: Received Get System Info Oct 02 17:14:16 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 17:14:16 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 17:14:16 crow volumio[1257]: info: Discovery: Getting this device information Oct 02 17:14:16 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:16 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:16 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 17:14:18 crow bluealsa[1000]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_7C_CF_18_5E_C0_D8, ...) Oct 02 17:14:18 crow volumio[1257]: info: BOOT COMPLETED Oct 02 17:14:19 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:19.821+09:00 level=INFO msg="new address was allocated" component=ble/conn old=1 new=2 Oct 02 17:14:19 crow dbus-daemon[778]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.24" (uid=0 pid=1853 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.3" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Oct 02 17:14:20 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 17:14:20 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 02 17:14:23 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 02 17:14:27 crow upmpdcli[2061]: writing RSA key Oct 02 17:14:28 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:28.608+09:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="172.30.1.28:54940,00:00:00:00:00:00%01 @ 0x3137080" latency=49.026199ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Oct 02 17:14:28 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:28.641+09:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940,00:00:00:00:00:00%01 @ 0x3137080" latency=38.655726ms timeout=10s Oct 02 17:14:28 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:28.655+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940,00:00:00:00:00:00%01 @ 0x3137080" latency=38.655726ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=13.625316ms Oct 02 17:14:28 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:28.742+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940,00:00:00:00:00:00%01 @ 0x3137080" latency=38.655726ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=98.521527ms Oct 02 17:14:28 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:28.744+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940,00:00:00:00:00:00%01 @ 0x3137080" latency=38.655726ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=101.152925ms Oct 02 17:14:28 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:28.770+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940,00:00:00:00:00:00%01 @ 0x3137080" latency=38.655726ms timeout=10s endpoint=https://www.googleapis.com duration=128.972699ms Oct 02 17:14:28 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:28.830+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940,00:00:00:00:00:00%01 @ 0x3137080" latency=38.655726ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=187.066775ms Oct 02 17:14:28 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:28.837+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940,00:00:00:00:00:00%01 @ 0x3137080" latency=38.655726ms timeout=10s endpoint=https://database.volumio.cloud duration=193.607926ms Oct 02 17:14:28 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:28.839+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940,00:00:00:00:00:00%01 @ 0x3137080" latency=38.655726ms timeout=10s endpoint=https://functions.volumio.cloud duration=196.503691ms Oct 02 17:14:28 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:28.851+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940,00:00:00:00:00:00%01 @ 0x3137080" latency=38.655726ms timeout=10s endpoint=https://functions.volumio.cloud duration=208.041159ms Oct 02 17:14:28 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:28.868+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940,00:00:00:00:00:00%01 @ 0x3137080" latency=38.655726ms timeout=10s endpoint=https://securetoken.googleapis.com duration=226.499626ms Oct 02 17:14:28 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:28.871+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940,00:00:00:00:00:00%01 @ 0x3137080" latency=38.655726ms timeout=10s endpoint=https://google.com duration=229.587722ms Oct 02 17:14:28 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:28.887+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940,00:00:00:00:00:00%01 @ 0x3137080" latency=38.655726ms timeout=10s endpoint=http://pushupdates.volumio.org duration=244.491951ms Oct 02 17:14:29 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:29.206+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940,00:00:00:00:00:00%01 @ 0x3137080" latency=38.655726ms timeout=10s endpoint=http://plugins.volumio.org duration=562.931249ms Oct 02 17:14:29 crow sudo[2067]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 02 17:14:29 crow sudo[2069]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 02 17:14:29 crow sudo[2067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 17:14:29 crow sudo[2069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 17:14:29 crow sudo[2067]: pam_unix(sudo:session): session closed for user root Oct 02 17:14:29 crow sudo[2069]: pam_unix(sudo:session): session closed for user root Oct 02 17:14:29 crow volumio5-onboarding[1853]: time=2026-10-02T17:14:29.657+09:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="172.30.1.28:54940,00:00:00:00:00:00%01 @ 0x3137080" latency=38.655726ms timeout=10s endpoint=http://cddb.volumio.org duration=1.014688811s error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 02 17:14:29 crow volumio[1257]: verbose: New Socket.io Connection to 172.30.1.45 from 172.30.1.28 UA: Mozilla/5.0 (Linux; Android 16; SM-S931N Build/BP4A.251205.006; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/153.0.8010.36 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 9 Oct 02 17:14:29 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 02 17:14:29 crow volumio[1257]: info: CoreCommandRouter::volumioGetVisibleSources Oct 02 17:14:29 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 02 17:14:30 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:30 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:30 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 02 17:14:30 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 02 17:14:30 crow volumio[1257]: info: Received Get System Info Oct 02 17:14:30 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 17:14:30 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 17:14:30 crow volumio[1257]: info: Discovery: Getting this device information Oct 02 17:14:30 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:30 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:30 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 17:14:30 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:30 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:30 crow volumio[1257]: info: Listing playlists Oct 02 17:14:30 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 02 17:14:30 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 02 17:14:30 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 02 17:14:30 crow sudo[2073]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 02 17:14:30 crow sudo[2073]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 17:14:30 crow sudo[2073]: pam_unix(sudo:session): session closed for user root Oct 02 17:14:30 crow sudo[2075]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 02 17:14:30 crow sudo[2075]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 17:14:30 crow sudo[2075]: pam_unix(sudo:session): session closed for user root Oct 02 17:14:30 crow volumio[1257]: verbose: New Socket.io Connection to 172.30.1.45 from 172.30.1.28 UA: Mozilla/5.0 (Linux; Android 16; SM-S931N Build/BP4A.251205.006; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/153.0.8010.36 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 10 Oct 02 17:14:31 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 02 17:14:31 crow volumio[1257]: info: CoreCommandRouter::volumioGetVisibleSources Oct 02 17:14:31 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 02 17:14:31 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:31 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:31 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 02 17:14:31 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 02 17:14:31 crow volumio[1257]: info: Received Get System Info Oct 02 17:14:31 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 17:14:31 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 17:14:31 crow volumio[1257]: info: Discovery: Getting this device information Oct 02 17:14:31 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:31 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:31 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 17:14:31 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:31 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:31 crow volumio[1257]: info: Listing playlists Oct 02 17:14:31 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 02 17:14:31 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 02 17:14:31 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 02 17:14:31 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 02 17:14:31 crow volumio[1257]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 02 17:14:31 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 02 17:14:32 crow volumio[1257]: info: Received Get System Version Oct 02 17:14:32 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 02 17:14:32 crow volumio[1257]: info: Received Get System Info Oct 02 17:14:32 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 17:14:32 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 17:14:32 crow volumio[1257]: info: Discovery: Getting this device information Oct 02 17:14:32 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:32 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:32 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 17:14:32 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 17:14:32 crow volumio[1257]: info: Received Get System Info Oct 02 17:14:32 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 17:14:32 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 17:14:32 crow volumio[1257]: info: Discovery: Getting this device information Oct 02 17:14:32 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:32 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:32 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 17:14:32 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 02 17:14:33 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 17:14:33 crow volumio[1257]: info: Received Get System Info Oct 02 17:14:33 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 17:14:33 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 17:14:33 crow volumio[1257]: info: Discovery: Getting this device information Oct 02 17:14:33 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:33 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:33 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 17:14:34 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 17:14:34 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 02 17:14:40 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 02 17:14:48 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 02 17:14:48 crow volumio[1257]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 02 17:14:48 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 02 17:14:48 crow volumio[1257]: info: Received Get System Version Oct 02 17:14:48 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 02 17:14:48 crow volumio[1257]: info: Received Get System Info Oct 02 17:14:48 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 17:14:48 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 17:14:48 crow volumio[1257]: info: Discovery: Getting this device information Oct 02 17:14:48 crow volumio[1257]: info: CoreCommandRouter::volumioGetState Oct 02 17:14:48 crow volumio[1257]: info: CorePlayQueue::getTrack 0 Oct 02 17:14:48 crow volumio[1257]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 17:15:01 crow volumio[1257]: info: Starting Uninstall of plugin user_interface - touch_display Oct 02 17:15:01 crow volumio[1257]: info: Uninstalling plugin touch_display Oct 02 17:15:01 crow volumio[1257]: info: touch_display: Un-/commenting gpu_mem settings in /boot/config.txt. Oct 02 17:15:01 crow volumio[1257]: info: touch_display: Using /boot/config.txt instead of /boot/userconfig.txt. Oct 02 17:15:01 crow sudo[2127]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumio-kiosk.service Oct 02 17:15:01 crow sudo[2128]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl enable getty@tty1.service Oct 02 17:15:01 crow sudo[2127]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 17:15:01 crow sudo[2128]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 17:15:01 crow sudo[2122]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Oct 02 17:15:01 crow sudo[2122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 17:15:01 crow sudo[2122]: pam_unix(sudo:session): session closed for user root Oct 02 17:15:01 crow volumio[1257]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Oct 02 17:15:01 crow sudo[2127]: pam_unix(sudo:session): session closed for user root Oct 02 17:15:01 crow systemd[1]: Reloading. Oct 02 17:15:01 crow volumio[1257]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 02 17:15:01 crow sudo[2124]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start getty@tty1.service Oct 02 17:15:01 crow sudo[2124]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 17:15:01 crow volumio[1257]: TypeError: Cannot read properties of undefined (reading 'split') Oct 02 17:15:01 crow volumio[1257]: at /data/plugins/user_interface/touch_display/index.js:1298:37 Oct 02 17:15:01 crow volumio[1257]: at ChildProcess.exithandler (node:child_process:413:7) Oct 02 17:15:01 crow volumio[1257]: at ChildProcess.emit (node:events:514:28) Oct 02 17:15:01 crow volumio[1257]: at maybeClose (node:internal/child_process:1105:16) Oct 02 17:15:01 crow volumio[1257]: at ChildProcess._handle.onexit (node:internal/child_process:305:5) Oct 02 17:15:01 crow volumio[1257]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 02 17:15:03 crow systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 02 17:15:03 crow systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 02 17:15:03 crow systemd[1]: Created slice system-getty.slice - Slice /system/getty. Oct 02 17:15:03 crow sudo[2128]: pam_unix(sudo:session): session closed for user root Oct 02 17:15:03 crow systemd[1]: Started getty@tty1.service - Getty on tty1. Oct 02 17:15:03 crow sudo[2124]: pam_unix(sudo:session): session closed for user root Oct 02 17:15:08 crow sudo[2179]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-02 17:14' Oct 02 17:15:08 crow sudo[2179]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"