Aug 31 18:10:21 volumio-kali systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 31 18:10:21 volumio-kali systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 31 18:10:21 volumio-kali systemd[1]: setdatetime-helper.service: Consumed 1.741s CPU time. Aug 31 18:10:21 volumio-kali wireless.js[674]: WIRELESS.JS - INFO: Notified systemd about wireless ready Aug 31 18:10:21 volumio-kali kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 31 18:10:21 volumio-kali systemd[1]: Started wireless.service - Wireless Services. Aug 31 18:10:21 volumio-kali systemd[1]: Started volumio.service - Volumio Backend Module. Aug 31 18:10:21 volumio-kali systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... Aug 31 18:10:21 volumio-kali systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker. Aug 31 18:10:21 volumio-kali systemd[1]: Received SIGRTMIN+21 from PID 297 (plymouthd). Aug 31 18:10:21 volumio-kali systemd[1]: Received SIGRTMIN+21 from PID 297 (plymouthd). Aug 31 18:10:21 volumio-kali systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. Aug 31 18:10:21 volumio-kali systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. Aug 31 18:10:21 volumio-kali systemd[1]: Started getty@tty1.service - Getty on tty1. Aug 31 18:10:21 volumio-kali systemd[1]: Reached target getty.target - Login Prompts. Aug 31 18:10:21 volumio-kali systemd[1]: Reached target multi-user.target - Multi-User System. Aug 31 18:10:21 volumio-kali systemd[1]: Reached target graphical.target - Graphical Interface. Aug 31 18:10:21 volumio-kali systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Aug 31 18:10:21 volumio-kali volumio-cpu-tweak[1254]: Setting RT Priority for mpd Aug 31 18:10:21 volumio-kali volumio-cpu-tweak[1270]: pid 35's current scheduling policy: SCHED_OTHER Aug 31 18:10:21 volumio-kali volumio-cpu-tweak[1270]: pid 35's current scheduling priority: 0 Aug 31 18:10:21 volumio-kali volumio-cpu-tweak[1254]: Setting MPD Affinity Aug 31 18:10:21 volumio-kali volumio-cpu-tweak[1271]: pid 3's current affinity mask: f Aug 31 18:10:21 volumio-kali systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Aug 31 18:10:21 volumio-kali systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Aug 31 18:10:21 volumio-kali systemd[1]: Startup finished in 15.499s (kernel) + 17.441s (userspace) = 32.941s. Aug 31 18:10:21 volumio-kali volumio-cpu-tweak[1254]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Aug 31 18:10:21 volumio-kali volumio-cpu-tweak[1254]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Aug 31 18:10:21 volumio-kali systemd[1]: volumio_cpu_tweak.service: Deactivated successfully. Aug 31 18:10:21 volumio-kali ntpd[874]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 31 18:10:21 volumio-kali ntpd[874]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Aug 31 18:10:21 volumio-kali ntpd[874]: DNS: Pool taking: 185.157.229.254 Aug 31 18:10:21 volumio-kali ntpd[874]: DNS: Pool taking: 172.232.208.229 Aug 31 18:10:21 volumio-kali ntpd[874]: DNS: Pool skipping: 162.159.200.1 Aug 31 18:10:21 volumio-kali ntpd[874]: DNS: Pool taking: 93.94.88.51 Aug 31 18:10:21 volumio-kali ntpd[874]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Aug 31 18:10:23 volumio-kali volumio-remote-updater[667]: [2026-08-31 18:10:23] [info] asio async_connect error: asio.system:111 (Connection refused) Aug 31 18:10:23 volumio-kali volumio-remote-updater[667]: [2026-08-31 18:10:23] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Aug 31 18:10:23 volumio-kali volumio-remote-updater[667]: [2026-08-31 18:10:23] [error] handle_connect error: Connection refused Aug 31 18:10:26 volumio-kali volumio[1252]: info: ------------------------------------------- Aug 31 18:10:26 volumio-kali volumio[1252]: info: ----- Volumio3 ---- Aug 31 18:10:26 volumio-kali volumio[1252]: info: ------------------------------------------- Aug 31 18:10:26 volumio-kali volumio[1252]: info: ----- System startup ---- Aug 31 18:10:26 volumio-kali volumio[1252]: info: ------------------------------------------- Aug 31 18:10:26 volumio-kali systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Aug 31 18:10:26 volumio-kali systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 31 18:10:26 volumio-kali systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 31 18:10:26 volumio-kali upmpdcli[1282]: Could not open config: /tmp/upmpdcli.conf Aug 31 18:10:26 volumio-kali systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:10:26 volumio-kali systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 31 18:10:28 volumio-kali ntpd[874]: CLOCK: time stepped by 0.577046 Aug 31 18:10:28 volumio-kali ntpd[874]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Aug 31 18:10:28 volumio-kali volumio[1252]: info: MYVOLUMIO Environment detected Aug 31 18:10:28 volumio-kali volumio[1252]: info: Plugin folders cleanup Aug 31 18:10:28 volumio-kali volumio[1252]: info: Scanning into folder /volumio/app/plugins/ Aug 31 18:10:28 volumio-kali volumio[1252]: info: Scanning category audio_interface Aug 31 18:10:28 volumio-kali volumio[1252]: info: Scanning category miscellanea Aug 31 18:10:28 volumio-kali volumio[1252]: info: Scanning category music_service Aug 31 18:10:28 volumio-kali volumio[1252]: info: Scanning category plugins.json Aug 31 18:10:28 volumio-kali volumio[1252]: info: Scanning category system_controller Aug 31 18:10:28 volumio-kali volumio[1252]: info: Scanning category user_interface Aug 31 18:10:28 volumio-kali volumio[1252]: info: Scanning into folder /data/plugins/ Aug 31 18:10:28 volumio-kali volumio[1252]: info: Scanning category system_controller Aug 31 18:10:28 volumio-kali volumio[1252]: info: Scanning category system_hardware Aug 31 18:10:28 volumio-kali volumio[1252]: info: Plugin folders cleanup completed Aug 31 18:10:28 volumio-kali volumio[1252]: info: ------------------------------------------- Aug 31 18:10:28 volumio-kali volumio[1252]: info: ----- Core plugins startup ---- Aug 31 18:10:28 volumio-kali volumio[1252]: info: ------------------------------------------- Aug 31 18:10:28 volumio-kali volumio[1252]: info: Loading plugins from folder /volumio/app/plugins/ Aug 31 18:10:28 volumio-kali volumio[1252]: info: Adding plugin upnp to MyMusic Plugins Aug 31 18:10:28 volumio-kali volumio[1252]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 31 18:10:28 volumio-kali volumio[1252]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 31 18:10:28 volumio-kali volumio[1252]: info: Loading plugins from folder /data/plugins/ Aug 31 18:10:28 volumio-kali volumio[1252]: info: Loading plugin "system"... Aug 31 18:10:28 volumio-kali volumio[1252]: info: Loading plugin "appearance"... Aug 31 18:10:30 volumio-kali volumio[1252]: info: Loading plugin "network"... Aug 31 18:10:30 volumio-kali volumio[1252]: info: Refreshing Cached IP Addresses Aug 31 18:10:30 volumio-kali sudo[1290]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 18:10:30 volumio-kali volumio[1252]: info: Loading plugin "services"... Aug 31 18:10:30 volumio-kali sudo[1290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:30 volumio-kali volumio[1252]: info: Loading plugin "volumio5onboarding"... Aug 31 18:10:30 volumio-kali sudo[1290]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:30 volumio-kali volumio[1252]: info: Loading plugin "alsa_controller"... Aug 31 18:10:30 volumio-kali sudo[1300]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 31 18:10:30 volumio-kali sudo[1300]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:31 volumio-kali sudo[1292]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 18:10:31 volumio-kali sudo[1292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:31 volumio-kali sudo[1292]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:31 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 18:10:31 volumio-kali volumio[1252]: info: Loading plugin "wizard"... Aug 31 18:10:31 volumio-kali volumio[1252]: info: Loading plugin "networkfs"... Aug 31 18:10:31 volumio-kali volumio[1252]: info: Starting Udev Watcher for removable devices Aug 31 18:10:31 volumio-kali volumio[1252]: info: Ignoring mount for partition: boot Aug 31 18:10:31 volumio-kali volumio[1252]: info: Ignoring mount for partition: volumio Aug 31 18:10:31 volumio-kali volumio[1252]: info: Ignoring mount for partition: volumio_data Aug 31 18:10:31 volumio-kali volumio[1252]: info: Mounting Device Volume_m-sata Aug 31 18:10:31 volumio-kali sudo[1326]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Volume_m-sata -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Aug 31 18:10:31 volumio-kali sudo[1326]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:32 volumio-kali ntfs-3g[1329]: Version 2022.10.3 integrated FUSE 28 Aug 31 18:10:32 volumio-kali ntfs-3g[1329]: Mounted /dev/sda1 (Read-Write, label "Volume m-sata", NTFS 3.1) Aug 31 18:10:32 volumio-kali ntfs-3g[1329]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Aug 31 18:10:32 volumio-kali ntfs-3g[1329]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda1,blkdev,blksize=4096 Aug 31 18:10:32 volumio-kali ntfs-3g[1329]: Global ownership and permissions enforced, configuration type 7 Aug 31 18:10:32 volumio-kali sudo[1326]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:32 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 18:10:32 volumio-kali volumio[1252]: info: Loading plugin "volumio_command_line_client"... Aug 31 18:10:32 volumio-kali volumio[1252]: info: Loading plugin "upnp"... Aug 31 18:10:32 volumio-kali volumio[1252]: info: [1788192632114] Starting Upmpd Daemon Aug 31 18:10:32 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 18:10:32 volumio-kali volumio[1252]: info: Loading plugin "my_music"... Aug 31 18:10:32 volumio-kali volumio[1252]: info: Loading plugin "mpd"... Aug 31 18:10:33 volumio-kali kernel: hwmon hwmon1: Undervoltage detected! Aug 31 18:10:33 volumio-kali volumio[1252]: info: Loading plugin "upnp_browser"... Aug 31 18:10:33 volumio-kali sudo[1300]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:34 volumio-kali volumio-remote-updater[667]: [2026-08-31 18:10:34] [connect] Successful connection Aug 31 18:10:36 volumio-kali volumio[1252]: info: Starting UPNP Browser Aug 31 18:10:36 volumio-kali volumio[1252]: info: Loading plugin "alarm-clock"... Aug 31 18:10:36 volumio-kali volumio[1252]: info: Loading plugin "airplay_emulation"... Aug 31 18:10:36 volumio-kali volumio[1252]: info: Starting Shairport Sync Aug 31 18:10:36 volumio-kali volumio[1252]: info: Loading plugin "last_100"... Aug 31 18:10:36 volumio-kali volumio[1252]: info: Loading plugin "webradio"... Aug 31 18:10:36 volumio-kali volumio[1252]: info: Loading plugin "i2s_dacs"... Aug 31 18:10:36 volumio-kali volumio[1252]: info: Loading plugin "volumiodiscovery"... Aug 31 18:10:37 volumio-kali volumio[1252]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 18:10:37 volumio-kali volumio[1252]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 18:10:37 volumio-kali volumio[1252]: *** WARNING *** For more information see Aug 31 18:10:37 volumio-kali volumio[1252]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 18:10:37 volumio-kali volumio[1252]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 18:10:37 volumio-kali volumio[1252]: *** WARNING *** For more information see Aug 31 18:10:37 volumio-kali node[1252]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 18:10:37 volumio-kali node[1252]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 18:10:37 volumio-kali node[1252]: *** WARNING *** For more information see Aug 31 18:10:37 volumio-kali node[1252]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 18:10:37 volumio-kali node[1252]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 18:10:37 volumio-kali node[1252]: *** WARNING *** For more information see Aug 31 18:10:37 volumio-kali volumio[1252]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 31 18:10:37 volumio-kali volumio[1252]: info: Discovery: Started advertising with name: Volumio Kali Aug 31 18:10:37 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 18:10:37 volumio-kali volumio[1252]: info: Loading plugin "autostart"... Aug 31 18:10:37 volumio-kali kernel: hwmon hwmon1: Voltage normalised Aug 31 18:10:37 volumio-kali volumio[1252]: info: Applying required configuration parameters for plugin autostart Aug 31 18:10:37 volumio-kali volumio[1252]: info: AutoStart - onVolumioStart - read config.json Aug 31 18:10:37 volumio-kali volumio[1252]: info: Loading plugin "gpio-buttons"... Aug 31 18:10:38 volumio-kali volumio[1252]: gpiox_arm32 V2.2.1 Aug 31 18:10:38 volumio-kali systemd[1]: systemd-fsckd.service: Deactivated successfully. Aug 31 18:10:38 volumio-kali volumio[1252]: info: gpio-buttons: Initialized Aug 31 18:10:38 volumio-kali volumio[1252]: info: Loading plugin "gpio_button_led"... Aug 31 18:10:39 volumio-kali volumio[1252]: gpiox_arm32 V2.2.1 Aug 31 18:10:39 volumio-kali volumio[1252]: info: Loading plugin "outputs"... Aug 31 18:10:39 volumio-kali volumio[1252]: info: Loading plugin "albumart"... Aug 31 18:10:39 volumio-kali volumio[1252]: info: Plugin example_plugin is not enabled Aug 31 18:10:39 volumio-kali volumio[1252]: info: Loading plugin "inputs"... Aug 31 18:10:39 volumio-kali volumio[1252]: info: Loading plugin "updater_comm"... Aug 31 18:10:39 volumio-kali volumio[1252]: info: Plugin mpdemulation is not enabled Aug 31 18:10:39 volumio-kali volumio[1252]: info: Loading plugin "rest_api"... Aug 31 18:10:39 volumio-kali volumio[1252]: info: Loading plugin "websocket"... Aug 31 18:10:40 volumio-kali volumio[1252]: info: Starting Socket.io Server version 1.7.4 Aug 31 18:10:40 volumio-kali volumio[1252]: info: Loading i18n strings for locale it Aug 31 18:10:40 volumio-kali volumio[1252]: Updating browse sources language Aug 31 18:10:40 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 18:10:40 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 18:10:40 volumio-kali volumio[1252]: info: CoreCommandRouter::initPlayerControls Aug 31 18:10:40 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:10:40 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:10:40 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:10:40 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:10:40 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:10:40 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:10:40 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:10:40 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:10:40 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 18:10:40 volumio-kali volumio[1252]: Express server listening on port 3000 Aug 31 18:10:40 volumio-kali volumio[1252]: [Metrics] WebUI: 15s 407.99ms Aug 31 18:10:41 volumio-kali volumio[1252]: info: CoreStateMachine::resetVolumioState Aug 31 18:10:41 volumio-kali volumio[1252]: info: CoreStateMachine::getcurrentVolume Aug 31 18:10:41 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 18:10:41 volumio-kali volumio[1252]: info: CoreStateMachine::pushState Aug 31 18:10:41 volumio-kali volumio[1252]: info: CorePlayQueue::getTrack 0 Aug 31 18:10:41 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 18:10:41 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioPushState Aug 31 18:10:41 volumio-kali volumio[1335]: Forking 3 albumart workers Aug 31 18:10:41 volumio-kali volumio[1252]: info: Volumio Network Manager: Network status updated: 1 Aug 31 18:10:42 volumio-kali systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Aug 31 18:10:42 volumio-kali systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 31 18:10:42 volumio-kali systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 31 18:10:42 volumio-kali upmpdcli[1393]: Could not open config: /tmp/upmpdcli.conf Aug 31 18:10:42 volumio-kali systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:10:42 volumio-kali systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 31 18:10:42 volumio-kali sudo[1395]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 18:10:42 volumio-kali sudo[1395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:42 volumio-kali sudo[1395]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:42 volumio-kali sudo[1397]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 18:10:42 volumio-kali sudo[1397]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:42 volumio-kali sudo[1397]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:42 volumio-kali volumio[1252]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 31 18:10:43 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:10:43 volumio-kali volumio[1252]: info: Executing start script for DAC BassFly-uHAT with I2S Mic Aug 31 18:10:43 volumio-kali volumio[1252]: info: Reloading queue from file Aug 31 18:10:43 volumio-kali sudo[1408]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6c 0x00 0x2000 w Aug 31 18:10:43 volumio-kali sudo[1408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:43 volumio-kali sudo[1408]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:43 volumio-kali sudo[1410]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6c 0x13 0x3016 w Aug 31 18:10:43 volumio-kali sudo[1410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:43 volumio-kali sudo[1410]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:43 volumio-kali volumio[1252]: info: CoreStateMachine::setRepeat true single undefined Aug 31 18:10:43 volumio-kali volumio[1252]: info: CoreStateMachine::pushState Aug 31 18:10:43 volumio-kali volumio[1252]: info: CorePlayQueue::getTrack 0 Aug 31 18:10:43 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 18:10:43 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioPushState Aug 31 18:10:43 volumio-kali volumio[1252]: info: CoreStateMachine::setRandom null Aug 31 18:10:44 volumio-kali volumio[1252]: info: CoreStateMachine::pushState Aug 31 18:10:44 volumio-kali volumio[1252]: info: CorePlayQueue::getTrack 0 Aug 31 18:10:44 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioPushState Aug 31 18:10:44 volumio-kali sudo[1412]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6c 0x01 0xD805 w Aug 31 18:10:44 volumio-kali sudo[1412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:44 volumio-kali volumio[1252]: info: Setting Device type: Raspberry PI Aug 31 18:10:44 volumio-kali sudo[1412]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:44 volumio-kali sudo[1414]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6c 0x00 0x0900 w Aug 31 18:10:44 volumio-kali sudo[1414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:44 volumio-kali sudo[1414]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:44 volumio-kali volumio[1252]: info: Discovery: adding 04135292-3f45-4e02-b5c9-55717680aac2 Aug 31 18:10:44 volumio-kali volumio[1252]: info: Discovery: Found device Volumio Kali Aug 31 18:10:44 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioGetState Aug 31 18:10:44 volumio-kali volumio[1252]: info: CorePlayQueue::getTrack 0 Aug 31 18:10:44 volumio-kali sudo[1417]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6d 0x00 0x2000 w Aug 31 18:10:44 volumio-kali sudo[1417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:44 volumio-kali sudo[1417]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:44 volumio-kali sudo[1419]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6d 0x13 0x3016 w Aug 31 18:10:44 volumio-kali sudo[1419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:44 volumio-kali sudo[1419]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:45 volumio-kali systemd[1]: systemd-hostnamed.service: Deactivated successfully. Aug 31 18:10:45 volumio-kali sudo[1421]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6d 0x01 0xD801 w Aug 31 18:10:45 volumio-kali volumio[1252]: info: gpio-buttons: Socket connected to Volumio Aug 31 18:10:45 volumio-kali sudo[1421]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:45 volumio-kali volumio[1252]: info: Discovery: this is already registered, 04135292-3f45-4e02-b5c9-55717680aac2 Aug 31 18:10:45 volumio-kali volumio[1252]: info: Discovery: Found device Volumio Kali Aug 31 18:10:45 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioGetState Aug 31 18:10:45 volumio-kali volumio[1252]: info: CorePlayQueue::getTrack 0 Aug 31 18:10:45 volumio-kali sudo[1421]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:45 volumio-kali sudo[1427]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 31 18:10:45 volumio-kali sudo[1427]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:45 volumio-kali sudo[1428]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6d 0x00 0x0900 w Aug 31 18:10:45 volumio-kali sudo[1428]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:45 volumio-kali sudo[1428]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:45 volumio-kali sudo[1431]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6c 0x05 0xDD59 w Aug 31 18:10:45 volumio-kali sudo[1431]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:45 volumio-kali sudo[1431]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:46 volumio-kali sudo[1433]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6c 0x06 0x24CC w Aug 31 18:10:46 volumio-kali sudo[1433]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:46 volumio-kali sudo[1433]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:46 volumio-kali sudo[1435]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6c 0x07 0x1A65 w Aug 31 18:10:46 volumio-kali sudo[1435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:46 volumio-kali sudo[1435]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:46 volumio-kali sudo[1437]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6c 0x08 0x2CDB w Aug 31 18:10:46 volumio-kali sudo[1437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:46 volumio-kali sudo[1437]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:46 volumio-kali sudo[1439]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6c 0x09 0x1646 w Aug 31 18:10:46 volumio-kali sudo[1439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:46 volumio-kali sudo[1439]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:47 volumio-kali sudo[1441]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6c 0x0A 0x3AEA w Aug 31 18:10:47 volumio-kali sudo[1441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:47 volumio-kali sudo[1441]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:47 volumio-kali sudo[1443]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6c 0x0B 0xF34D w Aug 31 18:10:47 volumio-kali sudo[1443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:47 volumio-kali sudo[1443]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:47 volumio-kali sudo[1445]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6c 0x0C 0x3EF9 w Aug 31 18:10:47 volumio-kali sudo[1445]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:47 volumio-kali sudo[1445]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:47 volumio-kali sudo[1447]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6c 0x0D 0xE05E w Aug 31 18:10:47 volumio-kali sudo[1447]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:48 volumio-kali sudo[1447]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:48 volumio-kali sudo[1449]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6c 0x0E 0x34F8 w Aug 31 18:10:48 volumio-kali sudo[1449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:48 volumio-kali sudo[1449]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:48 volumio-kali sudo[1451]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6c 0x0F 0x9A00 w Aug 31 18:10:48 volumio-kali sudo[1451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:48 volumio-kali sudo[1451]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:48 volumio-kali sudo[1453]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6c 0x11 0x2E13 w Aug 31 18:10:48 volumio-kali sudo[1453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:48 volumio-kali sudo[1453]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:48 volumio-kali sudo[1455]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6d 0x05 0xDD59 w Aug 31 18:10:48 volumio-kali sudo[1455]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:49 volumio-kali sudo[1455]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:49 volumio-kali volumio-remote-updater[667]: [2026-08-31 18:10:49] [connect] Successful connection Aug 31 18:10:49 volumio-kali volumio-remote-updater[667]: [2026-08-31 18:10:49] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788192649 101 Aug 31 18:10:49 volumio-kali volumio[1252]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 18:10:49 volumio-kali sudo[1457]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6d 0x06 0x24CC w Aug 31 18:10:49 volumio-kali sudo[1457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:49 volumio-kali sudo[1457]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:49 volumio-kali sudo[1459]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6d 0x07 0x1A65 w Aug 31 18:10:49 volumio-kali sudo[1459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:49 volumio-kali sudo[1459]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:49 volumio-kali sudo[1461]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6d 0x08 0x2CDB w Aug 31 18:10:49 volumio-kali sudo[1461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:49 volumio-kali sudo[1461]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:50 volumio-kali sudo[1463]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6d 0x09 0x1646 w Aug 31 18:10:50 volumio-kali sudo[1463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:50 volumio-kali sudo[1463]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:50 volumio-kali sudo[1465]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6d 0x0A 0x3AEA w Aug 31 18:10:50 volumio-kali sudo[1465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:50 volumio-kali sudo[1465]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:50 volumio-kali sudo[1467]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6d 0x0B 0xF34D w Aug 31 18:10:50 volumio-kali sudo[1467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:50 volumio-kali sudo[1467]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:50 volumio-kali sudo[1469]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6d 0x0C 0x3EF9 w Aug 31 18:10:50 volumio-kali sudo[1469]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:50 volumio-kali sudo[1469]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:51 volumio-kali sudo[1471]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6d 0x0D 0xE05E w Aug 31 18:10:51 volumio-kali sudo[1471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:51 volumio-kali sudo[1471]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:51 volumio-kali sudo[1473]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6d 0x0E 0x34F8 w Aug 31 18:10:51 volumio-kali sudo[1473]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:51 volumio-kali sudo[1473]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:51 volumio-kali sudo[1479]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6d 0x0F 0x9A00 w Aug 31 18:10:51 volumio-kali sudo[1479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:51 volumio-kali sudo[1479]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:51 volumio-kali sudo[1491]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -y 1 0x6d 0x11 0x2E13 w Aug 31 18:10:51 volumio-kali sudo[1491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:52 volumio-kali sudo[1491]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:52 volumio-kali volumio[1252]: info: DAC script executed Aug 31 18:10:52 volumio-kali volumio[1252]: info: Completed loading Core Plugins Aug 31 18:10:52 volumio-kali volumio[1252]: info: Preparing to generate the ALSA configuration file Aug 31 18:10:52 volumio-kali volumio[1252]: info: Asound.conf file unchanged, so no further update is needed Aug 31 18:10:52 volumio-kali volumio[1252]: info: Output device has changed, restarting MPD Aug 31 18:10:52 volumio-kali volumio[1252]: info: Output device has changed, restarting Shairport Sync Aug 31 18:10:52 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:10:52 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:10:52 volumio-kali sudo[1494]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 18:10:52 volumio-kali sudo[1494]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:52 volumio-kali sudo[1494]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:52 volumio-kali volumio[1252]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 18:10:52 volumio-kali volumio[1252]: info: ___________ START PLUGINS ___________ Aug 31 18:10:52 volumio-kali volumio[1363]: Starting albumart workers Aug 31 18:10:52 volumio-kali volumio[1362]: Starting albumart workers Aug 31 18:10:52 volumio-kali sudo[1496]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 18:10:52 volumio-kali sudo[1496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:52 volumio-kali volumio[1252]: info: ControllerMpd::onStart: Initializing MPD Aug 31 18:10:52 volumio-kali volumio[1252]: info: Creating MPD Configuration file Aug 31 18:10:52 volumio-kali systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Aug 31 18:10:53 volumio-kali systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 18:10:53 volumio-kali systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 18:10:53 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 18:10:53 volumio-kali sudo[1507]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 18:10:53 volumio-kali sudo[1507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:53 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 18:10:53 volumio-kali volumio[1252]: info: [1788192653187] CoreMusicLibrary::Adding element Server multimediali Aug 31 18:10:53 volumio-kali sudo[1507]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:53 volumio-kali volumio[1364]: Starting albumart workers Aug 31 18:10:53 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 18:10:53 volumio-kali sudo[1516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 18:10:53 volumio-kali sudo[1516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:53 volumio-kali sudo[1504]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 31 18:10:53 volumio-kali sudo[1517]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 18:10:53 volumio-kali sudo[1517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 31 18:10:53 volumio-kali sudo[1527]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 31 18:10:53 volumio-kali sudo[1517]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:53 volumio-kali sudo[1504]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:10:53 volumio-kali volumio[1252]: info: UPNP Browser: Client initialized successfully Aug 31 18:10:53 volumio-kali systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 31 18:10:53 volumio-kali systemd[1]: mpd.service: Deactivated successfully. Aug 31 18:10:53 volumio-kali systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 18:10:53 volumio-kali sudo[1504]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:53 volumio-kali systemd[1]: mpd.socket: Deactivated successfully. Aug 31 18:10:53 volumio-kali systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 18:10:53 volumio-kali systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 18:10:53 volumio-kali systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 18:10:53 volumio-kali systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 18:10:53 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:10:53 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:10:54 volumio-kali sudo[1534]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 18:10:54 volumio-kali sudo[1534]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 31 18:10:54 volumio-kali sudo[1544]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 31 18:10:54 volumio-kali sudo[1534]: pam_unix(sudo:session): session closed for user root Aug 31 18:10:54 volumio-kali volumio[1252]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 18:10:54 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:10:54 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:10:54 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:10:54.402+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 31 18:10:54 volumio-kali volumio[1252]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 18:10:54 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 18:10:54 volumio-kali volumio[1252]: info: [1788192654606] CoreMusicLibrary::Adding element Last_100 Aug 31 18:10:54 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 18:10:54 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 18:10:54 volumio-kali volumio[1252]: info: [1788192654610] CoreMusicLibrary::Adding element Webradio Aug 31 18:10:54 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 18:10:54 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 18:10:54 volumio-kali volumio[1252]: info: Initializing BBC Radios Aug 31 18:10:55 volumio-kali systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 31 18:10:55 volumio-kali systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 31 18:10:55 volumio-kali systemd[1]: setdatetime-helper.service: Consumed 1.311s CPU time. Aug 31 18:10:55 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 18:10:55 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:10:55 volumio-kali volumio[1252]: info: AutoStart - onStart - waiting for system ready state Aug 31 18:10:55 volumio-kali volumio[1252]: info: AutoStart - Polling config: interval=5000ms, maxAttempts=60 Aug 31 18:10:55 volumio-kali volumio[1252]: info: AutoStart - Maximum wait time: 300 seconds Aug 31 18:10:55 volumio-kali volumio[1252]: info: AutoStart - Startup volume disabled Aug 31 18:10:55 volumio-kali volumio[1252]: info: AutoStart - Check #1/60 - VOLUMIO_SYSTEM_STATUS = starting Aug 31 18:10:55 volumio-kali volumio[1252]: info: gpio-buttons: Creating GPIO triggers... Aug 31 18:10:55 volumio-kali volumio[1252]: info: gpio-buttons: GPIO3 configured: button6 -> shutdown Aug 31 18:10:55 volumio-kali volumio[1252]: info: GPIOButtonLED: Starting plugin Aug 31 18:10:55 volumio-kali volumio[1252]: info: Volumio Calling Home Aug 31 18:10:56 volumio-kali volumio[1252]: info: gpio-buttons: Started successfully Aug 31 18:10:57 volumio-kali systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Aug 31 18:10:57 volumio-kali systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 31 18:10:57 volumio-kali systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 31 18:10:57 volumio-kali sudo[1427]: pam_unix(sudo:session): session closed for user root Aug 31 18:11:02 volumio-kali volumio[1252]: info: AutoStart - Check #2/60 - VOLUMIO_SYSTEM_STATUS = starting Aug 31 18:11:02 volumio-kali volumio[1252]: info: MPD Permissions set Aug 31 18:11:02 volumio-kali volumio[1252]: info: MPD Permissions set Aug 31 18:11:02 volumio-kali volumio[1252]: info: Upmpdcli Daemon Started Aug 31 18:11:02 volumio-kali volumio[1252]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Aug 31 18:11:02 volumio-kali volumio[1252]: info: Volumio called home Aug 31 18:11:02 volumio-kali volumio[1252]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Aug 31 18:11:02 volumio-kali volumio[1252]: info: Received Get System Info Aug 31 18:11:02 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 18:11:02 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 18:11:02 volumio-kali volumio[1252]: info: Discovery: Getting this device information Aug 31 18:11:02 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioGetState Aug 31 18:11:02 volumio-kali volumio[1252]: info: CorePlayQueue::getTrack 0 Aug 31 18:11:02 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 18:11:02 volumio-kali mpd[1545]: 2026-08-31T18:11:02 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 18:11:03 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:03.068+02:00 level=INFO msg="system info for 5e8be1d24545549684f3f18e102a347c" deviceName="Volumio Kali" deviceVariant=volumio deviceModel= softwareVersion=4.119 Aug 31 18:11:03 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:03.120+02:00 level=INFO msg="bootstrapping state" hasInternet=true Aug 31 18:11:03 volumio-kali volumio[1252]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Aug 31 18:11:03 volumio-kali volumio[1252]: info: GPIOButtonLED: dtoverlay already correct Aug 31 18:11:03 volumio-kali volumio[1252]: info: GPIOButtonLED: LED+ on GPIO 22 Aug 31 18:11:03 volumio-kali volumio[1252]: info: GPIOButtonLED: LED- on GPIO 4 Aug 31 18:11:03 volumio-kali volumio[1252]: info: GPIOButtonLED: LED polarity = normal Aug 31 18:11:03 volumio-kali systemd[1]: Started mpd.service - Music Player Daemon. Aug 31 18:11:03 volumio-kali sudo[1496]: pam_unix(sudo:session): session closed for user root Aug 31 18:11:03 volumio-kali volumio[1252]: info: GPIOButtonLED: LED blink slow Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:03 volumio-kali sudo[1516]: pam_unix(sudo:session): session closed for user root Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:03 volumio-kali volumio[1252]: info: Received Get System Info Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 18:11:03 volumio-kali volumio[1252]: info: Discovery: Getting this device information Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioGetState Aug 31 18:11:03 volumio-kali volumio[1252]: info: CorePlayQueue::getTrack 0 Aug 31 18:11:03 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 18:11:04 volumio-kali volumio-remote-updater[667]: Test mode disabled Aug 31 18:11:04 volumio-kali volumio-remote-updater[667]: Alpha mode disabled Aug 31 18:11:04 volumio-kali volumio-remote-updater[667]: Alpha legacy test mode disabled Aug 31 18:11:05 volumio-kali volumio[1252]: info: Completed starting Core Plugins Aug 31 18:11:05 volumio-kali volumio[1252]: info: ------------------------------------------- Aug 31 18:11:05 volumio-kali volumio[1252]: info: ----- MyVolumio plugins startup ---- Aug 31 18:11:05 volumio-kali volumio[1252]: info: ------------------------------------------- Aug 31 18:11:05 volumio-kali volumio[1252]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 31 18:11:05 volumio-kali volumio[1252]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 31 18:11:05 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 31 18:11:05 volumio-kali volumio[1252]: info: GPIOButtonLED: Boot complete - LED solid Aug 31 18:11:05 volumio-kali volumio[1252]: info: Starting Shairport Sync Aug 31 18:11:05 volumio-kali volumio[1252]: info: Starting Shairport Sync Aug 31 18:11:05 volumio-kali volumio[1252]: info: Starting Shairport Sync Aug 31 18:11:05 volumio-kali sudo[1644]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 18:11:05 volumio-kali sudo[1644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:11:05 volumio-kali sudo[1646]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 18:11:05 volumio-kali sudo[1646]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:11:05 volumio-kali sudo[1648]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 18:11:05 volumio-kali sudo[1648]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:11:05 volumio-kali systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 31 18:11:05 volumio-kali systemd[1]: shairport-sync.service: Deactivated successfully. Aug 31 18:11:05 volumio-kali systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 18:11:05 volumio-kali systemd[1]: shairport-sync.service: Consumed 1.930s CPU time. Aug 31 18:11:05 volumio-kali systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 18:11:05 volumio-kali sudo[1644]: pam_unix(sudo:session): session closed for user root Aug 31 18:11:05 volumio-kali systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 31 18:11:05 volumio-kali systemd[1]: shairport-sync.service: Deactivated successfully. Aug 31 18:11:05 volumio-kali systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 18:11:06 volumio-kali systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 18:11:06 volumio-kali sudo[1646]: pam_unix(sudo:session): session closed for user root Aug 31 18:11:06 volumio-kali systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 31 18:11:06 volumio-kali systemd[1]: shairport-sync.service: Deactivated successfully. Aug 31 18:11:06 volumio-kali systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 18:11:06 volumio-kali systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 18:11:06 volumio-kali sudo[1648]: pam_unix(sudo:session): session closed for user root Aug 31 18:11:06 volumio-kali volumio[1252]: error: MPD error: The expression evaluated to a falsy value: Aug 31 18:11:06 volumio-kali volumio[1252]: assert.ok(self.idling) Aug 31 18:11:06 volumio-kali volumio[1252]: error: The expression evaluated to a falsy value: Aug 31 18:11:06 volumio-kali volumio[1252]: assert.ok(self.idling) Aug 31 18:11:06 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 31 18:11:06 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:06.453+02:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Aug 31 18:11:06 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:06.455+02:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Aug 31 18:11:06 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:06.465+02:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Aug 31 18:11:06 volumio-kali volumio[1252]: info: MPD running with PID1545 Aug 31 18:11:06 volumio-kali volumio[1252]: ,establishing connection Aug 31 18:11:06 volumio-kali volumio[1252]: error: updateQueue error: null Aug 31 18:11:06 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 31 18:11:06 volumio-kali volumio[1252]: info: Shairport-Sync Started Aug 31 18:11:06 volumio-kali volumio[1252]: Error adding Membership: Error: addMembership EINVAL Aug 31 18:11:06 volumio-kali volumio[1252]: info: Shairport-Sync Started Aug 31 18:11:06 volumio-kali volumio[1252]: info: Shairport-Sync Started Aug 31 18:11:06 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 31 18:11:07 volumio-kali volumio[1252]: info: Received Get System Info Aug 31 18:11:07 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 18:11:07 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 18:11:07 volumio-kali volumio[1252]: info: Discovery: Getting this device information Aug 31 18:11:07 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioGetState Aug 31 18:11:07 volumio-kali volumio[1252]: info: CorePlayQueue::getTrack 0 Aug 31 18:11:07 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 18:11:07 volumio-kali volumio[1252]: error: updateQueue error: null Aug 31 18:11:07 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 31 18:11:07 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 31 18:11:07 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:07.423+02:00 level=INFO msg="enabling local network discovery" Aug 31 18:11:07 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:07.479+02:00 level=INFO msg="enabling BLE discovery" Aug 31 18:11:07 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 18:11:07 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 18:11:07 volumio-kali volumio[1252]: info: Discovery: Getting this device information Aug 31 18:11:07 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioGetState Aug 31 18:11:07 volumio-kali volumio[1252]: info: CorePlayQueue::getTrack 0 Aug 31 18:11:07 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 18:11:07 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioGetState Aug 31 18:11:07 volumio-kali volumio[1252]: info: CorePlayQueue::getTrack 0 Aug 31 18:11:07 volumio-kali volumio[1252]: info: AutoStart - Check #3/60 - VOLUMIO_SYSTEM_STATUS = starting Aug 31 18:11:07 volumio-kali volumio[1252]: verbose: New Socket.io Connection to 192.168.1.6:3000 from 192.168.1.4 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 5 Aug 31 18:11:08 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 31 18:11:08 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 31 18:11:08 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:08.506+02:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 31 18:11:08 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:08.654+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.4:58320 Aug 31 18:11:08 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:08.688+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.4:58320 @ 0x20d1800" latency=153.087536ms timeout=20s Aug 31 18:11:08 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:08.688+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.4:58320 @ 0x20d1800" Aug 31 18:11:08 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:08.689+02:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.4:58320 @ 0x20d1800" latency=155.121597ms platform=PLATFORM_IOS version=6.260807.0 Aug 31 18:11:08 volumio-kali volumio[1252]: info: Received Get System Info Aug 31 18:11:08 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 18:11:08 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 18:11:08 volumio-kali volumio[1252]: info: Discovery: Getting this device information Aug 31 18:11:08 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioGetState Aug 31 18:11:08 volumio-kali volumio[1252]: info: CorePlayQueue::getTrack 0 Aug 31 18:11:08 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 18:11:08 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 31 18:11:08 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 31 18:11:08 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:08.798+02:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.1.4:58320 @ 0x20d1800" name="Volumio Kali" Aug 31 18:11:08 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:08.809+02:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.1.4:58320 @ 0x20d1800" language=it Aug 31 18:11:08 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Aug 31 18:11:08 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:08.940+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.1.4:58320 @ 0x20d1800" timezone=Europe/Berlin Aug 31 18:11:08 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:08.941+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.4:58320 @ 0x20d1800" available=true connected=true macAddress=b8:27:eb:29:1f:07 ip4Address=192.168.1.6/24 ip6Address= Aug 31 18:11:08 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:08.944+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.4:58320 @ 0x20d1800" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 31 18:11:08 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:08.945+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.1.4:58320 @ 0x20d1800" setupComplete=true Aug 31 18:11:09 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Aug 31 18:11:09 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 31 18:11:09 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:11:09 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 31 18:11:09 volumio-kali volumio[1252]: amixer -c 0 info | grep "bcm2835 ALSA" Aug 31 18:11:09 volumio-kali volumio[1252]: amixer -c 1 info | grep "bcm2835 Headphones" Aug 31 18:11:09 volumio-kali volumio[1252]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Aug 31 18:11:10 volumio-kali volumio[1252]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 2 Aug 31 18:11:10 volumio-kali volumio[1252]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 31 18:11:10 volumio-kali volumio[1252]: {"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)"} Aug 31 18:11:10 volumio-kali volumio[1252]: amixer -c 2 info | grep "vc4-hdmi" Aug 31 18:11:10 volumio-kali volumio[1252]: Card sysdefault:2 'vc4hdmi'/'vc4-hdmi' Aug 31 18:11:10 volumio-kali volumio[1252]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 3 Aug 31 18:11:10 volumio-kali volumio[1252]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 31 18:11:10 volumio-kali volumio[1252]: {"cmd":"/usr/local/bin/alsacap -C 3","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 3\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)"} Aug 31 18:11:10 volumio-kali volumio[1252]: amixer -c 3 info | grep "BassFly-uHAT with I2S Mic" Aug 31 18:11:10 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:10.627+02:00 level=INFO msg="new address was allocated" component=ble/conn old=1 new=2 Aug 31 18:11:10 volumio-kali dbus-daemon[637]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.15" (uid=0 pid=1530 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=933 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Aug 31 18:11:10 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:10.976+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m35.196800676s timeout=20s Aug 31 18:11:10 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:10.977+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" Aug 31 18:11:11 volumio-kali volumio[1252]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 3 Aug 31 18:11:11 volumio-kali volumio[1252]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 31 18:11:11 volumio-kali volumio[1252]: {"cmd":"/usr/local/bin/alsacap -C 3","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 3\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)"} Aug 31 18:11:11 volumio-kali volumio[1252]: amixer -c 3 info | grep "snd_rpi_googlevoicehat_soundcar" Aug 31 18:11:11 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:11.277+02:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m32.159210471s platform=PLATFORM_IOS version=6.260807.0 Aug 31 18:11:11 volumio-kali volumio[1252]: Card sysdefault:3 'sndrpigooglevoi'/'snd_rpi_googlevoicehat_soundcard' Aug 31 18:11:11 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:11.347+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.1.4:58320 @ 0x20d1800" selectedOutputId=3 Aug 31 18:11:11 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:11.408+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m32.289737246s timeout=20s Aug 31 18:11:11 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:11.409+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" Aug 31 18:11:12 volumio-kali volumio[1252]: info: Received Get System Info Aug 31 18:11:12 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 18:11:12 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 18:11:12 volumio-kali volumio[1252]: info: Discovery: Getting this device information Aug 31 18:11:12 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioGetState Aug 31 18:11:12 volumio-kali volumio[1252]: info: CorePlayQueue::getTrack 0 Aug 31 18:11:12 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 18:11:12 volumio-kali volumio[1252]: info: Received Get System Info Aug 31 18:11:12 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 18:11:12 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 18:11:12 volumio-kali volumio[1252]: info: Discovery: Getting this device information Aug 31 18:11:12 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioGetState Aug 31 18:11:12 volumio-kali volumio[1252]: info: CorePlayQueue::getTrack 0 Aug 31 18:11:12 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 18:11:12 volumio-kali volumio[1252]: info: Received Get System Info Aug 31 18:11:12 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 18:11:12 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 18:11:12 volumio-kali volumio[1252]: info: Discovery: Getting this device information Aug 31 18:11:12 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioGetState Aug 31 18:11:12 volumio-kali volumio[1252]: info: CorePlayQueue::getTrack 0 Aug 31 18:11:12 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 18:11:12 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:12.403+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m13.192127158s timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Aug 31 18:11:12 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:12.455+02:00 level=INFO msg="emitting device name changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" name="Volumio Kali" Aug 31 18:11:12 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:12.455+02:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.1.4:58320 @ 0x20d1800" currentVersion=4.119 latestVersion=4.119 Aug 31 18:11:12 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:12.456+02:00 level=INFO msg="emitting device name changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" name="Volumio Kali" Aug 31 18:11:12 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:12.456+02:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.1.4:58320 @ 0x20d1800" status=UPDATE_STATUS_NONE progress=0 Aug 31 18:11:12 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:12.457+02:00 level=INFO msg="emitting user changed event" component=server peer="192.168.1.4:58320 @ 0x20d1800" userId= Aug 31 18:11:12 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:12.458+02:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.1.4:58320 @ 0x20d1800" providers=3 Aug 31 18:11:12 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:12.480+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m13.254759145s timeout=10s Aug 31 18:11:12 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:12.660+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m13.254759145s timeout=10s endpoint=http://pushupdates.volumio.org duration=174.317813ms Aug 31 18:11:12 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:12.716+02:00 level=INFO msg="emitting device language changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" language=it Aug 31 18:11:12 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:12.815+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m11.634362745s timeout=20s Aug 31 18:11:12 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:12.815+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" Aug 31 18:11:12 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:12.836+02:00 level=INFO msg="emitting device language changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" language=it Aug 31 18:11:13 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:13.080+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m13.254759145s timeout=10s endpoint=http://cddb.volumio.org duration=590.982977ms Aug 31 18:11:13 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:13.195+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m0.477924259s timeout=10s Aug 31 18:11:13 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:13.348+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m0.477924259s timeout=10s endpoint=http://pushupdates.volumio.org duration=111.020577ms Aug 31 18:11:13 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:13.404+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m13.254759145s timeout=10s endpoint=http://plugins.volumio.org duration=917.310816ms Aug 31 18:11:13 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:13.465+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m13.254759145s timeout=10s endpoint=https://myvolumio.firebaseio.com duration=981.690488ms Aug 31 18:11:13 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:13.503+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m0.477924259s timeout=10s endpoint=http://cddb.volumio.org duration=278.74118ms Aug 31 18:11:13 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:13.580+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m0.477924259s timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=385.2213ms Aug 31 18:11:13 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:13.580+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m13.254759145s timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=1.099483183s Aug 31 18:11:13 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:13.635+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m0.477924259s timeout=10s endpoint=https://myvolumio.firebaseio.com duration=423.377262ms Aug 31 18:11:13 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:13.687+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m0.477924259s timeout=10s endpoint=https://www.googleapis.com duration=482.98565ms Aug 31 18:11:13 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:13.695+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m13.254759145s timeout=10s endpoint=https://www.googleapis.com duration=1.211093124s Aug 31 18:11:13 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:13.787+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m0.477924259s timeout=10s endpoint=http://plugins.volumio.org duration=549.035335ms Aug 31 18:11:14 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:14.011+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m0.477924259s timeout=10s endpoint=https://securetoken.googleapis.com duration=802.799341ms Aug 31 18:11:14 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:14.119+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m13.254759145s timeout=10s endpoint=https://securetoken.googleapis.com duration=1.635435423s Aug 31 18:11:14 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:14.781+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m13.254759145s timeout=10s endpoint=https://google.com duration=2.297706995s Aug 31 18:11:14 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:14.781+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m0.477924259s timeout=10s endpoint=https://google.com duration=1.583322301s Aug 31 18:11:16 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:16.134+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m13.254759145s timeout=10s endpoint=https://functions.volumio.cloud duration=3.644541978s Aug 31 18:11:16 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:16.135+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m13.254759145s timeout=10s endpoint=https://functions.volumio.cloud duration=3.650985038s Aug 31 18:11:16 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:16.242+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m0.477924259s timeout=10s endpoint=https://functions.volumio.cloud duration=3.026854214s Aug 31 18:11:16 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:16.243+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m0.477924259s timeout=10s endpoint=https://functions.volumio.cloud duration=3.018099071s Aug 31 18:11:16 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:16.519+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m0.477924259s timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=3.298087232s Aug 31 18:11:16 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:16.520+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m13.254759145s timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=4.034747771s Aug 31 18:11:16 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:16.583+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m13.254759145s timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=4.099285066s Aug 31 18:11:16 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:16.583+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m0.477924259s timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=3.364627136s Aug 31 18:11:16 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:16.705+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m0.477924259s timeout=10s endpoint=https://database.volumio.cloud duration=3.467537434s Aug 31 18:11:16 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:16.710+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m13.254759145s timeout=10s endpoint=https://database.volumio.cloud duration=4.222673455s Aug 31 18:11:16 volumio-kali volumio[1252]: info: AutoStart - Check #4/60 - VOLUMIO_SYSTEM_STATUS = starting Aug 31 18:11:17 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 31 18:11:17 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Aug 31 18:11:17 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:17.698+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" timezone=Europe/Berlin Aug 31 18:11:17 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:17.700+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" available=true connected=true macAddress=b8:27:eb:29:1f:07 ip4Address=192.168.1.6/24 ip6Address= Aug 31 18:11:17 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:17.698+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" timezone=Europe/Berlin Aug 31 18:11:17 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:17.705+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 31 18:11:17 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:17.705+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" setupComplete=true Aug 31 18:11:17 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:17.711+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" available=true connected=true macAddress=b8:27:eb:29:1f:07 ip4Address=192.168.1.6/24 ip6Address= Aug 31 18:11:17 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:17.719+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 31 18:11:17 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:17.721+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" setupComplete=true Aug 31 18:11:17 volumio-kali volumio[1252]: info: Received Get System Info Aug 31 18:11:17 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 18:11:17 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 18:11:17 volumio-kali volumio[1252]: info: Discovery: Getting this device information Aug 31 18:11:17 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioGetState Aug 31 18:11:17 volumio-kali volumio[1252]: info: CorePlayQueue::getTrack 0 Aug 31 18:11:17 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 18:11:17 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Aug 31 18:11:17 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:17.778+02:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.1.4:58320 @ 0x20d1800" plugins=0 Aug 31 18:11:17 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:17.796+02:00 level=INFO msg="emitting device name changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" name="Volumio Kali" Aug 31 18:11:17 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:17.797+02:00 level=INFO msg="emitting device language changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" language=it Aug 31 18:11:18 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Aug 31 18:11:18 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 31 18:11:18 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:11:18 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 31 18:11:18 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Aug 31 18:11:19 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 31 18:11:19 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:11:19 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 31 18:11:19 volumio-kali volumio[1252]: info: CoreCommandRouter::volumioGetState Aug 31 18:11:19 volumio-kali volumio[1252]: info: CorePlayQueue::getTrack 0 Aug 31 18:11:19 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Aug 31 18:11:19 volumio-kali volumio[1252]: amixer -c 0 info | grep "bcm2835 ALSA" Aug 31 18:11:19 volumio-kali volumio[1252]: amixer -c 1 info | grep "bcm2835 Headphones" Aug 31 18:11:19 volumio-kali volumio[1252]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Aug 31 18:11:19 volumio-kali volumio[1252]: amixer -c 0 info | grep "bcm2835 ALSA" Aug 31 18:11:19 volumio-kali volumio[1252]: amixer -c 1 info | grep "bcm2835 Headphones" Aug 31 18:11:20 volumio-kali volumio[1252]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.230+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" timezone=Europe/Berlin Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.245+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" available=true connected=true macAddress=b8:27:eb:29:1f:07 ip4Address=192.168.1.6/24 ip6Address= Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.247+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.247+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" setupComplete=true Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.258+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:58320 @ 0x20d1800" state=STATUS_STOPPED positionMs=0 volume=100 Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.258+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:58320 @ 0x20d1800" id= title= Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.274+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.4:58320 @ 0x2000c60" latency=139.011495ms timeout=10s Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.306+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.4:58320 @ 0x2000c60" latency=139.011495ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=31.606361ms Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.325+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.4:58320 @ 0x2000c60" latency=139.011495ms timeout=10s endpoint=http://pushupdates.volumio.org duration=50.717698ms Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.326+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.4:58320 @ 0x2000c60" latency=139.011495ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=50.560447ms Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.339+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.4:58320 @ 0x2000c60" latency=139.011495ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=63.163342ms Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.416+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.4:58320 @ 0x2000c60" latency=139.011495ms timeout=10s endpoint=https://www.googleapis.com duration=140.644028ms Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.440+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.4:58320 @ 0x2000c60" latency=139.011495ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=164.532744ms Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.451+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.4:58320 @ 0x2000c60" latency=139.011495ms timeout=10s endpoint=https://securetoken.googleapis.com duration=176.340061ms Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.454+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.4:58320 @ 0x2000c60" latency=139.011495ms timeout=10s endpoint=https://functions.volumio.cloud duration=179.142295ms Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.457+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.4:58320 @ 0x2000c60" latency=139.011495ms timeout=10s endpoint=https://functions.volumio.cloud duration=181.942603ms Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.536+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.4:58320 @ 0x2000c60" latency=139.011495ms timeout=10s endpoint=http://cddb.volumio.org duration=260.624314ms Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.548+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.4:58320 @ 0x2000c60" latency=139.011495ms timeout=10s endpoint=https://database.volumio.cloud duration=272.590809ms Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.749+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.4:58320 @ 0x2000c60" latency=139.011495ms timeout=10s endpoint=http://plugins.volumio.org duration=474.576797ms Aug 31 18:11:20 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:20.932+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.4:58320 @ 0x2000c60" latency=139.011495ms timeout=10s endpoint=https://google.com duration=657.686673ms Aug 31 18:11:25 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Aug 31 18:11:25 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 31 18:11:25 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:11:25 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 31 18:11:25 volumio-kali volumio[1252]: amixer -c 0 info | grep "bcm2835 ALSA" Aug 31 18:11:25 volumio-kali volumio[1252]: amixer -c 1 info | grep "bcm2835 Headphones" Aug 31 18:11:26 volumio-kali volumio[1252]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Aug 31 18:11:26 volumio-kali volumio[1252]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 3 Aug 31 18:11:26 volumio-kali volumio[1252]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 31 18:11:26 volumio-kali volumio[1252]: {"cmd":"/usr/local/bin/alsacap -C 3","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 3\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)"} Aug 31 18:11:26 volumio-kali volumio[1252]: amixer -c 3 info | grep "snd_rpi_googlevoicehat_soundcar" Aug 31 18:11:26 volumio-kali volumio[1252]: Card sysdefault:3 'sndrpigooglevoi'/'snd_rpi_googlevoicehat_soundcard' Aug 31 18:11:26 volumio-kali volumio[1252]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 2 Aug 31 18:11:26 volumio-kali volumio[1252]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 31 18:11:26 volumio-kali volumio[1252]: {"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)"} Aug 31 18:11:26 volumio-kali volumio[1252]: amixer -c 2 info | grep "vc4-hdmi" Aug 31 18:11:26 volumio-kali volumio[1252]: Card sysdefault:2 'vc4hdmi'/'vc4-hdmi' Aug 31 18:11:26 volumio-kali volumio[1252]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 3 Aug 31 18:11:26 volumio-kali volumio[1252]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 31 18:11:26 volumio-kali volumio[1252]: {"cmd":"/usr/local/bin/alsacap -C 3","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 3\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)"} Aug 31 18:11:26 volumio-kali volumio[1252]: amixer -c 3 info | grep "BassFly-uHAT with I2S Mic" Aug 31 18:11:27 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:27.102+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" selectedOutputId=3 Aug 31 18:11:27 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:27.103+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" selectedOutputId=3 Aug 31 18:11:27 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:27.104+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="00:00:00:00:00:00%01 @ 0x2000c60" selectedOutputId=3 Aug 31 18:11:27 volumio-kali volumio[1252]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 3 Aug 31 18:11:27 volumio-kali volumio[1252]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 31 18:11:27 volumio-kali volumio[1252]: {"cmd":"/usr/local/bin/alsacap -C 3","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 3\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)"} Aug 31 18:11:27 volumio-kali volumio[1252]: amixer -c 3 info | grep "snd_rpi_googlevoicehat_soundcar" Aug 31 18:11:27 volumio-kali volumio[1252]: Card sysdefault:3 'sndrpigooglevoi'/'snd_rpi_googlevoicehat_soundcard' Aug 31 18:11:27 volumio-kali volumio[1252]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 2 Aug 31 18:11:27 volumio-kali volumio[1252]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 31 18:11:27 volumio-kali volumio[1252]: {"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)"} Aug 31 18:11:27 volumio-kali volumio[1252]: amixer -c 2 info | grep "vc4-hdmi" Aug 31 18:11:27 volumio-kali volumio[1252]: Card sysdefault:2 'vc4hdmi'/'vc4-hdmi' Aug 31 18:11:27 volumio-kali volumio[1252]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 3 Aug 31 18:11:27 volumio-kali volumio[1252]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 31 18:11:27 volumio-kali volumio[1252]: {"cmd":"/usr/local/bin/alsacap -C 3","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 3\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)"} Aug 31 18:11:27 volumio-kali volumio[1252]: amixer -c 3 info | grep "BassFly-uHAT with I2S Mic" Aug 31 18:11:28 volumio-kali volumio[1252]: info: AutoStart - Check #5/60 - VOLUMIO_SYSTEM_STATUS = starting Aug 31 18:11:28 volumio-kali volumio[1252]: error: MyVolumio Plugin failed to start in a timely fashion Aug 31 18:11:28 volumio-kali volumio[1252]: [Metrics] CommandRouter: 61s 407.75ms Aug 31 18:11:28 volumio-kali volumio[1252]: info: CoreCommandRouter::volumiosetStartupVolume Aug 31 18:11:28 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:11:28 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:11:28 volumio-kali volumio[1252]: info: CoreCommandRouter::Close All Modals sent Aug 31 18:11:28 volumio-kali volumio[1252]: info: CoreCommandRouter::Close All Modals sent Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.281+02:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.1.4:58320 Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.282+02:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.1.4:58320 Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.288+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.4:58437 Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.316+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:58437 @ 0x21f2ae0" latency=143.067006ms timeout=10s Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.322+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.4:58437 @ 0x21f2ae0" latency=139.09839ms timeout=20s Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.322+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.4:58437 @ 0x21f2ae0" Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.343+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:58437 @ 0x21f2ae0" latency=143.067006ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=26.840741ms Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.361+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:58437 @ 0x21f2ae0" latency=143.067006ms timeout=10s endpoint=http://pushupdates.volumio.org duration=43.847591ms Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.362+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:58437 @ 0x21f2ae0" latency=143.067006ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=44.73837ms Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.376+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:58437 @ 0x21f2ae0" latency=143.067006ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=59.101945ms Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.453+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:58437 @ 0x21f2ae0" latency=143.067006ms timeout=10s endpoint=https://www.googleapis.com duration=136.014432ms Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.473+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:58437 @ 0x21f2ae0" latency=143.067006ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=157.394759ms Aug 31 18:11:28 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 18:11:28 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.489+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:58437 @ 0x21f2ae0" latency=143.067006ms timeout=10s endpoint=https://securetoken.googleapis.com duration=171.82141ms Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.512+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:58437 @ 0x21f2ae0" latency=143.067006ms timeout=10s endpoint=https://functions.volumio.cloud duration=194.605411ms Aug 31 18:11:28 volumio-kali volumio[1252]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.577+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:58437 @ 0x21f2ae0" latency=143.067006ms timeout=10s endpoint=http://cddb.volumio.org duration=258.628105ms Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.580+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:58437 @ 0x21f2ae0" latency=143.067006ms timeout=10s endpoint=https://database.volumio.cloud duration=261.705466ms Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.643+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:58437 @ 0x21f2ae0" latency=143.067006ms timeout=10s endpoint=https://functions.volumio.cloud duration=326.422938ms Aug 31 18:11:28 volumio-kali volumio[1252]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.788+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:58437 @ 0x21f2ae0" latency=143.067006ms timeout=10s endpoint=http://plugins.volumio.org duration=469.802736ms Aug 31 18:11:28 volumio-kali volumio[1252]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals. Aug 31 18:11:28 volumio-kali volumio[1252]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues Aug 31 18:11:28 volumio-kali volumio[1252]: at new NodeError (node:internal/errors:405:5) Aug 31 18:11:28 volumio-kali volumio[1252]: at assert (node:internal/assert:14:11) Aug 31 18:11:28 volumio-kali volumio[1252]: at internalConnectMultiple (node:net:1118:3) Aug 31 18:11:28 volumio-kali volumio[1252]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3) Aug 31 18:11:28 volumio-kali volumio[1252]: at listOnTimeout (node:internal/timers:575:11) Aug 31 18:11:28 volumio-kali volumio[1252]: at process.processTimers (node:internal/timers:514:7) { Aug 31 18:11:28 volumio-kali volumio[1252]: code: 'ERR_INTERNAL_ASSERTION' Aug 31 18:11:28 volumio-kali volumio[1252]: } Aug 31 18:11:28 volumio-kali volumio[1252]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 18:11:28 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:28.967+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:58437 @ 0x21f2ae0" latency=143.067006ms timeout=10s endpoint=https://google.com duration=650.142911ms Aug 31 18:11:29 volumio-kali kernel: voicehat-codec voicehat-codec: Enabling audio amp... Aug 31 18:11:30 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:30.977+02:00 level=ERROR msg="failed to notify all device data" component=server type=REQUEST_TYPE_DEVICE_DATA peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m35.196800676s timeout=20s error="failed to get system info: could not get system info: context deadline exceeded" Aug 31 18:11:31 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:31.409+02:00 level=ERROR msg="failed to notify all device data" component=server type=REQUEST_TYPE_DEVICE_DATA peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m32.289737246s timeout=20s error="failed to get system info: could not get system info: context deadline exceeded" Aug 31 18:11:32 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:32.815+02:00 level=ERROR msg="failed to notify all device data" component=server type=REQUEST_TYPE_DEVICE_DATA peer="00:00:00:00:00:00%01 @ 0x2000c60" latency=2m11.634362745s timeout=20s error="failed to get system info: could not get system info: context deadline exceeded" Aug 31 18:11:34 volumio-kali kernel: voicehat-codec voicehat-codec: Disabling audio amp... Aug 31 18:11:34 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:34.284+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Aug 31 18:11:34 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:34.286+02:00 level=ERROR msg="failed to send response" component=server dst="00:00:00:00:00:00%01 @ 0x2000c60" id=2057753365 status=STATUS_UNKNOWN error="peer is gone" Aug 31 18:11:37 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:37.592+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Aug 31 18:11:37 volumio-kali volumio5-onboarding[1530]: time=2026-08-31T18:11:37.592+02:00 level=ERROR msg="failed to send response" component=server dst="00:00:00:00:00:00%01 @ 0x2000c60" id=880025142 status=STATUS_UNKNOWN error="peer is gone" Aug 31 18:11:37 volumio-kali upmpdcli[1854]: writing RSA key Aug 31 18:11:38 volumio-kali sudo[1860]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 18:10' Aug 31 18:11:38 volumio-kali sudo[1860]: 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"