Feb 21 16:37:09 volumio volumio[1297]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 21 16:37:09 volumio volumio[1297]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 21 16:37:09 volumio volumio[1297]: info: Streaming services startup Feb 21 16:37:09 volumio volumio[1297]: info: Starting Streaming Daemon Feb 21 16:37:09 volumio sudo[1680]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 21 16:37:09 volumio volumio[1297]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 21 16:37:09 volumio sudo[1680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 16:37:10 volumio sudo[1680]: pam_unix(sudo:session): session closed for user root Feb 21 16:37:10 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 16:37:10 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 16:37:10 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 21 16:37:10 volumio volumio[1297]: error: Cannot start Volumio Streaming Daemon Feb 21 16:37:10 volumio volumio[1297]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 21 16:37:10 volumio volumio[1297]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 21 16:37:12 volumio volumio-remote-updater[725]: Test mode disabled Feb 21 16:37:12 volumio volumio-remote-updater[725]: Alpha mode disabled Feb 21 16:37:12 volumio volumio-remote-updater[725]: Alpha legacy test mode disabled Feb 21 16:37:12 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 21 16:37:12 volumio volumio[1297]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 21 16:37:12 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 21 16:37:12 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 21 16:37:12 volumio volumio[1297]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Feb 21 16:37:13 volumio volumio[1297]: info: CoreCommandRouter::volumioGetState Feb 21 16:37:13 volumio volumio[1297]: info: CorePlayQueue::getTrack 0 Feb 21 16:37:15 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:15.583Z level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.5.17:61069 Feb 21 16:37:15 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 16:37:15 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 16:37:15 volumio volumio[1297]: info: Discovery: Getting this device information Feb 21 16:37:15 volumio volumio[1297]: info: CoreCommandRouter::volumioGetState Feb 21 16:37:15 volumio volumio[1297]: info: CorePlayQueue::getTrack 0 Feb 21 16:37:15 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 16:37:16 volumio volumio[1297]: verbose: New Socket.io Connection to 192.168.5.32:3000 from 192.168.5.17 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 5 Feb 21 16:37:16 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 21 16:37:16 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 21 16:37:17 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 16:37:17 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 16:37:17 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 21 16:37:17 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 21 16:37:17 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 21 16:37:17 volumio volumio[1297]: info: CoreCommandRouter::volumioGetBrowseSources Feb 21 16:37:17 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 16:37:17 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0001, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0001/char0002, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0001/char0004, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0006, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0006/char0007, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0006/char0007/desc0009, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service000a, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service000a/char000b, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service000a/char000d, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service000f, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service000f/char0010, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service000f/char0010/desc0012, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0013, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0013/char0014, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0013/char0014/desc0016, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0013/char0017, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0019, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0019/char001a, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0019/char001a/desc001c, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0019/char001d, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0019/char001d/desc001f, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0019/char0020, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0019/char0020/desc0022, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0023, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0023/char0024, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0023/char0024/desc0026, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0023/char0024/desc0027, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0023/char0028, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0023/char0028/desc002a, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0023/char0028/desc002b, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0023/char002c, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0023/char002c/desc002e, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service002f, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service002f/char0030, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service002f/char0030/desc0032, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service002f/char0030/desc0033, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0034, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0034/char0035, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0034/char0035/desc0037, ...) Feb 21 16:37:19 volumio bluealsa[998]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6E_A5_85_32_AA_9B/service0034/char0035/desc0038, ...) Feb 21 16:37:19 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:19.607Z level=INFO msg="new address was allocated" component=ble/conn old=1 new=2 Feb 21 16:37:19 volumio dbus-daemon[709]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.15" (uid=0 pid=1455 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.4" (uid=0 pid=906 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Feb 21 16:37:21 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:21.979Z level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.5.17:61069 @ 0x1bc8b40" latency=-3.344467ms timeout=10s Feb 21 16:37:21 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:21.979Z level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.5.17:61069 @ 0x1bc8b40" latency=-478.842µs platform=PLATFORM_IOS version=5.260120.0 Feb 21 16:37:21 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:21.979Z level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.5.17:61069 @ 0x1bc8b40" Feb 21 16:37:21 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 21 16:37:21 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 21 16:37:21 volumio volumio[1297]: info: Received Get System Info Feb 21 16:37:21 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 16:37:21 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 16:37:21 volumio volumio[1297]: info: Discovery: Getting this device information Feb 21 16:37:21 volumio volumio[1297]: info: CoreCommandRouter::volumioGetState Feb 21 16:37:21 volumio volumio[1297]: info: CorePlayQueue::getTrack 0 Feb 21 16:37:21 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 16:37:22 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:22.001Z level=INFO msg="updating device settings from app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.5.17:61069 @ 0x1bc8b40" latency=-478.842µs language=en timezone=Europe/Warsaw Feb 21 16:37:22 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:22.054Z level=INFO msg="emitting device name changed event" component=server peer="192.168.5.17:61069 @ 0x1bc8b40" name=Volumio Feb 21 16:37:22 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:22.056Z level=INFO msg="emitting device language changed event" component=server peer="192.168.5.17:61069 @ 0x1bc8b40" language=en Feb 21 16:37:22 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Feb 21 16:37:22 volumio volumio[1297]: info: Loading i18n strings for locale en Feb 21 16:37:22 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Feb 21 16:37:22 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:22.287Z level=INFO msg="emitting device timezone changed event" component=server peer="192.168.5.17:61069 @ 0x1bc8b40" timezone=UTC Feb 21 16:37:22 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:22.289Z level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.5.17:61069 @ 0x1bc8b40" available=true connected=true macAddress=b8:27:eb:25:1c:59 ip4Address=192.168.5.32/24 ip6Address= Feb 21 16:37:22 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:22.293Z level=INFO msg="emitting wifi info changed event" component=server peer="192.168.5.17:61069 @ 0x1bc8b40" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Feb 21 16:37:22 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:22.295Z level=INFO msg="emitting device setup status changed event" component=server peer="192.168.5.17:61069 @ 0x1bc8b40" setupComplete=false Feb 21 16:37:22 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Feb 21 16:37:22 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 21 16:37:22 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 16:37:22 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 21 16:37:22 volumio volumio[1297]: amixer -c 0 info | grep "bcm2835 ALSA" Feb 21 16:37:22 volumio volumio[1297]: amixer -c 0 info | grep "bcm2835 ALSA" Feb 21 16:37:23 volumio volumio[1297]: amixer -c 1 info | grep "bcm2835 Headphones" Feb 21 16:37:23 volumio volumio[1297]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Feb 21 16:37:23 volumio volumio[1297]: info: Fetching Streaming Services browse cache Feb 21 16:37:23 volumio volumio[1297]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Feb 21 16:37:23 volumio volumio[1297]: /bin/sh: 1: /usr/local/bin/alsacap: not found Feb 21 16:37:23 volumio volumio[1297]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\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)"} Feb 21 16:37:23 volumio volumio[1297]: amixer -c 5 info | grep "USB Audio Device" Feb 21 16:37:23 volumio volumio[1297]: Card sysdefault:5 'Device'/'GeneralPlus USB Audio Device at usb-3f980000.usb-1.5, full speed' Feb 21 16:37:23 volumio volumio[1297]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 2 Feb 21 16:37:23 volumio volumio[1297]: /bin/sh: 1: /usr/local/bin/alsacap: not found Feb 21 16:37:23 volumio volumio[1297]: {"cmd":"/usr/local/bin/alsacap -C 2","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 2\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)"} Feb 21 16:37:23 volumio volumio[1297]: amixer -c 2 info | grep "vc4-hdmi" Feb 21 16:37:23 volumio volumio[1297]: Card sysdefault:2 'vc4hdmi'/'vc4-hdmi' Feb 21 16:37:23 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:23.941Z level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.5.17:61069 @ 0x1bc8b40" selectedOutputId=0 Feb 21 16:37:24 volumio volumio[1297]: info: Received Get System Info Feb 21 16:37:24 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 16:37:24 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 16:37:24 volumio volumio[1297]: info: Discovery: Getting this device information Feb 21 16:37:24 volumio volumio[1297]: info: CoreCommandRouter::volumioGetState Feb 21 16:37:24 volumio volumio[1297]: info: CorePlayQueue::getTrack 0 Feb 21 16:37:24 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 16:37:24 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:24.167Z level=INFO msg="emitting software info changed event" component=server peer="192.168.5.17:61069 @ 0x1bc8b40" currentVersion=4.096 latestVersion=4.096 Feb 21 16:37:24 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:24.168Z level=INFO msg="emitting software update progress event" component=server peer="192.168.5.17:61069 @ 0x1bc8b40" status=UPDATE_STATUS_NONE progress=0 Feb 21 16:37:24 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:24.169Z level=INFO msg="emitting user changed event" component=server peer="192.168.5.17:61069 @ 0x1bc8b40" userId= Feb 21 16:37:24 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:24.170Z level=INFO msg="emitting music providers changed event" component=server peer="192.168.5.17:61069 @ 0x1bc8b40" providers=3 Feb 21 16:37:24 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:24.221Z level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" latency=-6.150926ms platform=PLATFORM_IOS version=5.260120.0 Feb 21 16:37:24 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:24.221Z level=INFO msg="updating device settings from app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" latency=-6.150926ms language=en timezone=Europe/Warsaw Feb 21 16:37:24 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:24.222Z level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" latency=-6.01952ms timeout=10s Feb 21 16:37:24 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:24.222Z level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" Feb 21 16:37:24 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:24.238Z level=INFO msg="emitting device language changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" language=en Feb 21 16:37:24 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:24.243Z level=INFO msg="emitting device language changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" language=en Feb 21 16:37:24 volumio volumio[1297]: Updating browse sources language Feb 21 16:37:24 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 16:37:24 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 21 16:37:24 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Feb 21 16:37:24 volumio volumio[1297]: info: Loading i18n strings for locale en Feb 21 16:37:24 volumio volumio[1297]: info: Received Get System Info Feb 21 16:37:24 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 16:37:24 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 16:37:24 volumio volumio[1297]: info: Discovery: Getting this device information Feb 21 16:37:24 volumio volumio[1297]: info: CoreCommandRouter::volumioGetState Feb 21 16:37:24 volumio volumio[1297]: info: CorePlayQueue::getTrack 0 Feb 21 16:37:24 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 16:37:24 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Feb 21 16:37:24 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Feb 21 16:37:24 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:24.781Z level=INFO msg="emitting plugins changed event" component=server peer="192.168.5.17:61069 @ 0x1bc8b40" plugins=0 Feb 21 16:37:24 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:24.801Z level=INFO msg="emitting device name changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" name=Volumio Feb 21 16:37:24 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:24.802Z level=INFO msg="emitting device language changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" language=en Feb 21 16:37:25 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Feb 21 16:37:25 volumio volumio[1297]: info: Setting timezone to Europe/Warsaw Feb 21 16:37:25 volumio sudo[1735]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Feb 21 16:37:25 volumio sudo[1735]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 16:37:25 volumio sudo[1735]: pam_unix(sudo:session): session closed for user root Feb 21 16:37:25 volumio sudo[1739]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Europe/Warsaw /etc/localtime Feb 21 16:37:25 volumio sudo[1739]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 16:37:26 volumio sudo[1739]: pam_unix(sudo:session): session closed for user root Feb 21 16:37:26 volumio sudo[1743]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Feb 21 16:37:26 volumio sudo[1743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 16:37:26 volumio sudo[1743]: pam_unix(sudo:session): session closed for user root Feb 21 16:37:26 volumio sudo[1747]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Europe/Warsaw Feb 21 16:37:26 volumio sudo[1747]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 16:37:26 volumio dbus-daemon[709]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.18' (uid=0 pid=1748 comm="/usr/bin/timedatectl set-timezone Europe/Warsaw") Feb 21 16:37:27 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... Feb 21 16:37:27 volumio dbus-daemon[709]: [system] Successfully activated service 'org.freedesktop.timedate1' Feb 21 16:37:27 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. Feb 21 16:37:27 volumio sudo[1747]: pam_unix(sudo:session): session closed for user root Feb 21 16:37:27 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Feb 21 16:37:27 volumio volumio[1297]: info: Setting timezone to Europe/Warsaw Feb 21 16:37:27 volumio sudo[1752]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Feb 21 16:37:27 volumio sudo[1752]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 16:37:27 volumio sudo[1752]: pam_unix(sudo:session): session closed for user root Feb 21 16:37:28 volumio sudo[1756]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Europe/Warsaw /etc/localtime Feb 21 16:37:28 volumio sudo[1756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 16:37:28 volumio sudo[1756]: pam_unix(sudo:session): session closed for user root Feb 21 16:37:28 volumio sudo[1760]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Feb 21 16:37:28 volumio sudo[1760]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 16:37:28 volumio sudo[1760]: pam_unix(sudo:session): session closed for user root Feb 21 16:37:29 volumio sudo[1764]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Europe/Warsaw Feb 21 16:37:29 volumio sudo[1764]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 16:37:29 volumio sudo[1764]: pam_unix(sudo:session): session closed for user root Feb 21 16:37:29 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Feb 21 16:37:29 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:29.320Z level=INFO msg="emitting device timezone changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" timezone=Europe/Warsaw Feb 21 16:37:29 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:29.323Z level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" available=true connected=true macAddress=b8:27:eb:25:1c:59 ip4Address=192.168.5.32/24 ip6Address= Feb 21 16:37:29 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:29.324Z level=INFO msg="emitting wifi info changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Feb 21 16:37:29 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:29.325Z level=INFO msg="emitting device setup status changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" setupComplete=false Feb 21 16:37:29 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Feb 21 16:37:29 volumio volumio[1297]: info: CoreCommandRouter::volumioGetState Feb 21 16:37:29 volumio volumio[1297]: info: CorePlayQueue::getTrack 0 Feb 21 16:37:29 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Feb 21 16:37:29 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:29.361Z level=INFO msg="emitting device timezone changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" timezone=Europe/Warsaw Feb 21 16:37:29 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:29.361Z level=INFO msg="emitting device timezone changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" timezone=Europe/Warsaw Feb 21 16:37:29 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:29.439Z level=INFO msg="emitting player state changed event" component=server peer="192.168.5.17:61069 @ 0x1bc8b40" state=STATUS_STOPPED positionMs=0 volume=86 Feb 21 16:37:29 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:29.443Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.5.17:61069 @ 0x1bc8b40" id= title= Feb 21 16:37:29 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:29.450Z level=INFO msg="emitting device language changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" language=en Feb 21 16:37:29 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:29.973Z level=INFO msg="emitting wifi scan event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" networks=2 Feb 21 16:37:30 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:30.477Z level=INFO msg="emitting wifi info changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Feb 21 16:37:30 volumio volumio[1297]: info: Fetching Streaming Services browse cache Feb 21 16:37:30 volumio volumio[1297]: error: MyVolumio Plugin failed to authenticate in a timely fashion Feb 21 16:37:30 volumio volumio[1297]: info: Completed starting MyVolumio Plugin Feb 21 16:37:30 volumio volumio[1297]: [Metrics] CommandRouter: 77s 99.37ms Feb 21 16:37:30 volumio volumio[1297]: info: CoreCommandRouter::volumiosetStartupVolume Feb 21 16:37:30 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 16:37:30 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 16:37:30 volumio volumio[1297]: info: CoreCommandRouter::Close All Modals sent Feb 21 16:37:30 volumio volumio[1297]: info: CoreCommandRouter::Close All Modals sent Feb 21 16:37:30 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Feb 21 16:37:30 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:30.766Z level=INFO msg="emitting device timezone changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" timezone=Europe/Warsaw Feb 21 16:37:30 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:30.766Z level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" latency=-6.40322ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_SETUP_V1_INTRO Feb 21 16:37:30 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Feb 21 16:37:30 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Feb 21 16:37:30 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:30.892Z level=INFO msg="emitting device language changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" language=en Feb 21 16:37:31 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 21 16:37:31 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 16:37:31 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 21 16:37:31 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Feb 21 16:37:31 volumio volumio[1297]: info: Received Get System Info Feb 21 16:37:31 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 16:37:31 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 16:37:31 volumio volumio[1297]: info: Discovery: Getting this device information Feb 21 16:37:31 volumio volumio[1297]: info: CoreCommandRouter::volumioGetState Feb 21 16:37:31 volumio volumio[1297]: info: CorePlayQueue::getTrack 0 Feb 21 16:37:31 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 16:37:31 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:31.039Z level=INFO msg="emitting device timezone changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" timezone=Europe/Warsaw Feb 21 16:37:31 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:31.040Z level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" latency=-453.637µs timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_SETUP_V1_INTRO Feb 21 16:37:31 volumio volumio[1297]: amixer -c 0 info | grep "bcm2835 ALSA" Feb 21 16:37:31 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:31.411Z level=INFO msg="emitting wifi scan event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" networks=2 Feb 21 16:37:31 volumio volumio[1297]: amixer -c 0 info | grep "bcm2835 ALSA" Feb 21 16:37:31 volumio volumio[1297]: amixer -c 1 info | grep "bcm2835 Headphones" Feb 21 16:37:31 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:31.914Z level=INFO msg="emitting wifi info changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Feb 21 16:37:32 volumio volumio[1297]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Feb 21 16:37:32 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:32.555Z level=INFO msg="set device language" component=server type=REQUEST_TYPE_SET_DEVICE_LANGUAGE peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" latency=-5.033534ms timeout=10s language=pl Feb 21 16:37:32 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Feb 21 16:37:32 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 21 16:37:33 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Feb 21 16:37:33 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Feb 21 16:37:33 volumio volumio[1297]: info: Received Get System Info Feb 21 16:37:33 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 16:37:33 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 16:37:33 volumio volumio[1297]: info: Discovery: Getting this device information Feb 21 16:37:33 volumio volumio[1297]: info: CoreCommandRouter::volumioGetState Feb 21 16:37:33 volumio volumio[1297]: info: CorePlayQueue::getTrack 0 Feb 21 16:37:33 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 16:37:33 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 21 16:37:33 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 21 16:37:33 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 21 16:37:33 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 21 16:37:33 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Feb 21 16:37:33 volumio volumio[1297]: info: Loading i18n strings for locale pl Feb 21 16:37:33 volumio volumio[1297]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Feb 21 16:37:33 volumio volumio[1297]: /bin/sh: 1: /usr/local/bin/alsacap: not found Feb 21 16:37:33 volumio volumio[1297]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\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)"} Feb 21 16:37:33 volumio volumio[1297]: amixer -c 5 info | grep "USB Audio Device" Feb 21 16:37:33 volumio volumio[1297]: Card sysdefault:5 'Device'/'GeneralPlus USB Audio Device at usb-3f980000.usb-1.5, full speed' Feb 21 16:37:33 volumio volumio[1297]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 2 Feb 21 16:37:33 volumio volumio[1297]: /bin/sh: 1: /usr/local/bin/alsacap: not found Feb 21 16:37:33 volumio volumio[1297]: {"cmd":"/usr/local/bin/alsacap -C 2","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 2\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)"} Feb 21 16:37:33 volumio volumio[1297]: amixer -c 2 info | grep "vc4-hdmi" Feb 21 16:37:34 volumio volumio[1297]: Card sysdefault:2 'vc4hdmi'/'vc4-hdmi' Feb 21 16:37:34 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:34.138Z level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" selectedOutputId=0 Feb 21 16:37:34 volumio volumio[1297]: info: Fetching Streaming Services browse cache Feb 21 16:37:34 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:34.223Z level=ERROR msg="failed to notify all device data" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" latency=-6.01952ms timeout=10s error="failed to get system info: could not get system info: context deadline exceeded" Feb 21 16:37:34 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:34.310Z level=INFO msg="emitting device language changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" language=en Feb 21 16:37:34 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:34.318Z level=INFO msg="set device timezone" component=server type=REQUEST_TYPE_SET_DEVICE_TIMEZONE peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" latency=-5.442545ms timeout=10s timezone=Europe/Warsaw Feb 21 16:37:34 volumio volumio[1297]: Updating browse sources language Feb 21 16:37:34 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 16:37:34 volumio volumio[1297]: info: Received Get System Info Feb 21 16:37:34 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 16:37:34 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 16:37:34 volumio volumio[1297]: info: Discovery: Getting this device information Feb 21 16:37:34 volumio volumio[1297]: info: CoreCommandRouter::volumioGetState Feb 21 16:37:34 volumio volumio[1297]: info: CorePlayQueue::getTrack 0 Feb 21 16:37:34 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 16:37:34 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Feb 21 16:37:35 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Feb 21 16:37:35 volumio volumio[1297]: info: Setting timezone to Europe/Warsaw Feb 21 16:37:35 volumio sudo[1814]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Feb 21 16:37:35 volumio sudo[1814]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 16:37:35 volumio sudo[1814]: pam_unix(sudo:session): session closed for user root Feb 21 16:37:35 volumio systemd[1]: Starting apt-daily-upgrade.service - Daily apt upgrade and clean activities... Feb 21 16:37:35 volumio sudo[1819]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Europe/Warsaw /etc/localtime Feb 21 16:37:35 volumio sudo[1819]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 16:37:35 volumio sudo[1819]: pam_unix(sudo:session): session closed for user root Feb 21 16:37:36 volumio upmpdcli[1826]: writing RSA key Feb 21 16:37:36 volumio sudo[1827]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Feb 21 16:37:36 volumio sudo[1827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 16:37:36 volumio sudo[1827]: pam_unix(sudo:session): session closed for user root Feb 21 16:37:36 volumio sudo[1837]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Europe/Warsaw Feb 21 16:37:36 volumio sudo[1837]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 16:37:36 volumio sudo[1837]: pam_unix(sudo:session): session closed for user root Feb 21 16:37:36 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Feb 21 16:37:36 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Feb 21 16:37:36 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:36.997Z level=INFO msg="emitting device timezone changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" timezone=Europe/Warsaw Feb 21 16:37:37 volumio systemd[1]: apt-daily-upgrade.service: Deactivated successfully. Feb 21 16:37:37 volumio systemd[1]: Finished apt-daily-upgrade.service - Daily apt upgrade and clean activities. Feb 21 16:37:37 volumio volumio[1297]: Updating browse sources language Feb 21 16:37:37 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 16:37:37 volumio volumio[1297]: info: Received Get System Info Feb 21 16:37:37 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 16:37:37 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 16:37:37 volumio volumio[1297]: info: Discovery: Getting this device information Feb 21 16:37:37 volumio volumio[1297]: info: CoreCommandRouter::volumioGetState Feb 21 16:37:37 volumio volumio[1297]: info: CorePlayQueue::getTrack 0 Feb 21 16:37:37 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 16:37:37 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:37.364Z level=INFO msg="emitting device name changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" name=Volumio Feb 21 16:37:37 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:37.365Z level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" latency=21.164746ms timeout=10s from=APP_PAGE_SETUP_V1_INTRO to=APP_PAGE_SETUP_V1_NAME Feb 21 16:37:37 volumio volumio[1297]: info: BOOT COMPLETED Feb 21 16:37:56 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:56.527Z level=INFO msg="set device name" component=server type=REQUEST_TYPE_SET_DEVICE_NAME peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" latency=-2.245991ms timeout=10s name=Volumio_Gabriel Feb 21 16:37:56 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , saveGeneralSettings Feb 21 16:37:56 volumio volumio[1297]: info: System name has changed, restarting Shairport Sync Feb 21 16:37:56 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 16:37:56 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 16:37:56 volumio volumio[1297]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 16:37:56 volumio volumio[1297]: info: Discovery: Restarting Advertising Feb 21 16:37:56 volumio volumio[1297]: info: Discovery: Stopping existing advertisement Feb 21 16:37:56 volumio volumio[1297]: info: Received Get System Info Feb 21 16:37:56 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 16:37:56 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 16:37:56 volumio volumio[1297]: info: Discovery: Getting this device information Feb 21 16:37:56 volumio volumio[1297]: info: CoreCommandRouter::volumioGetState Feb 21 16:37:56 volumio volumio[1297]: info: CorePlayQueue::getTrack 0 Feb 21 16:37:56 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 16:37:56 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:56.820Z level=INFO msg="emitting device name changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" name=Volumio_Gabriel Feb 21 16:37:56 volumio sudo[1931]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli Feb 21 16:37:56 volumio sudo[1931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 16:37:56 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:56.874Z level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" available=true connected=true macAddress=b8:27:eb:25:1c:59 ip4Address=192.168.5.32/24 ip6Address= Feb 21 16:37:56 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:56.875Z level=INFO msg="emitting wifi info changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Feb 21 16:37:56 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:56.876Z level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" latency=3.197342ms timeout=10s from=APP_PAGE_SETUP_V1_NAME to=APP_PAGE_SETUP_V1_INTERNET Feb 21 16:37:56 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:56.895Z level=INFO msg="run WiFi scan" component=server type=REQUEST_TYPE_RUN_WIFI_SCAN peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" latency=-5.04521ms timeout=1m0s Feb 21 16:37:56 volumio sudo[1931]: pam_unix(sudo:session): session closed for user root Feb 21 16:37:57 volumio volumio[1297]: info: Starting Shairport Sync Feb 21 16:37:57 volumio sudo[1934]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/hosts Feb 21 16:37:57 volumio sudo[1934]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 16:37:57 volumio sudo[1934]: pam_unix(sudo:session): session closed for user root Feb 21 16:37:57 volumio volumio[1297]: info: Permissions for /etc/hosts set Feb 21 16:37:57 volumio sudo[1937]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 16:37:57 volumio sudo[1937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 16:37:57 volumio sudo[1939]: volumio : unable to resolve host volumio: System error Feb 21 16:37:57 volumio volumio[1297]: info: Hostname now is volumio_gabriel Feb 21 16:37:57 volumio sudo[1939]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/hostname volumio_gabriel Feb 21 16:37:57 volumio sudo[1939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 16:37:57 volumio sudo[1939]: pam_unix(sudo:session): session closed for user root Feb 21 16:37:57 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:57.409Z level=INFO msg="emitting wifi scan event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" networks=2 Feb 21 16:37:57 volumio systemd[1]: upmpdcli.service: Deactivated successfully. Feb 21 16:37:57 volumio systemd[1]: upmpdcli.service: Consumed 49.708s CPU time. Feb 21 16:37:57 volumio sudo[1943]: volumio : unable to resolve host volumio: System error Feb 21 16:37:57 volumio sudo[1943]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /etc/avahi/services/ Feb 21 16:37:57 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 21 16:37:57 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 21 16:37:57 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 16:37:57 volumio systemd[1]: shairport-sync.service: Consumed 1.950s CPU time. Feb 21 16:37:57 volumio volumio[1297]: error: Cannot set new hostname: Error: Command failed: /usr/bin/sudo /bin/hostname volumio_gabriel Feb 21 16:37:57 volumio volumio[1297]: sudo: unable to resolve host volumio: System error Feb 21 16:37:57 volumio volumio[1297]: hostname: the specified hostname is invalid Feb 21 16:37:57 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Feb 21 16:37:57 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 21 16:37:57 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 21 16:37:57 volumio sudo[1943]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 16:37:57 volumio sudo[1937]: pam_unix(sudo:session): session closed for user root Feb 21 16:37:57 volumio volumio[1297]: info: Shairport-Sync Started Feb 21 16:37:57 volumio sudo[1943]: pam_unix(sudo:session): session closed for user root Feb 21 16:37:57 volumio volumio-remote-updater[725]: Test mode disabled Feb 21 16:37:57 volumio volumio-remote-updater[725]: Alpha mode disabled Feb 21 16:37:57 volumio volumio-remote-updater[725]: Alpha legacy test mode disabled Feb 21 16:37:57 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 21 16:37:57 volumio volumio[1297]: info: Permissions for /etc/avahi/services/volumio.service Feb 21 16:37:57 volumio volumio[1297]: info: Discovery: A device disappeared from network Feb 21 16:37:57 volumio volumio[1297]: info: Discovery: Device volumio disappeared from network Feb 21 16:37:57 volumio volumio[1297]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 21 16:37:57 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 21 16:37:57 volumio avahi-daemon[708]: Files changed, reloading. Feb 21 16:37:57 volumio avahi-daemon[708]: Loading service file /services/volumio.service. Feb 21 16:37:57 volumio volumio5-onboarding[1455]: time=2026-02-21T15:37:57.914Z level=INFO msg="emitting wifi info changed event" component=server peer="192.168.5.17:61069,00:00:00:00:00:00%01 @ 0x1bc8b40" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Feb 21 16:37:57 volumio volumio[1297]: info: Discovery: A device disappeared from network Feb 21 16:37:57 volumio volumio[1297]: info: Avahi name changed to volumio_gabriel Feb 21 16:37:58 volumio volumio[1297]: info: Received Get System Info Feb 21 16:37:58 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 16:37:58 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 16:37:58 volumio volumio[1297]: info: Discovery: Getting this device information Feb 21 16:37:58 volumio volumio[1297]: info: CoreCommandRouter::volumioGetState Feb 21 16:37:58 volumio volumio[1297]: info: CorePlayQueue::getTrack 0 Feb 21 16:37:58 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 16:37:58 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 21 16:37:58 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 21 16:37:58 volumio avahi-daemon[708]: Service "Volumio_Gabriel" (/services/volumio.service) successfully established. Feb 21 16:37:59 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Feb 21 16:37:59 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 21 16:37:59 volumio volumio-remote-updater[725]: Test mode disabled Feb 21 16:37:59 volumio volumio-remote-updater[725]: Alpha mode disabled Feb 21 16:37:59 volumio volumio-remote-updater[725]: Alpha legacy test mode disabled Feb 21 16:37:59 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 21 16:37:59 volumio volumio[1297]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 21 16:37:59 volumio volumio[1297]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 21 16:38:01 volumio volumio[1297]: info: Discovery: Started advertising with name: Volumio_Gabriel Feb 21 16:38:02 volumio volumio[1297]: compat.c: read() failed: Resource temporarily unavailable Feb 21 16:38:02 volumio volumio[1297]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 16:38:02 volumio volumio[1297]: Error: dns service error: unknown Feb 21 16:38:02 volumio volumio[1297]: at MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { Feb 21 16:38:02 volumio volumio[1297]: errorCode: -65537 Feb 21 16:38:02 volumio volumio[1297]: } Feb 21 16:38:02 volumio volumio[1297]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 16:38:06 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. Feb 21 16:38:09 volumio sudo[1994]: volumio : unable to resolve host volumio: System error Feb 21 16:38:09 volumio sudo[1994]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-21 16:37' Feb 21 16:38:09 volumio sudo[1994]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"