-- Logs begin at Fri 2025-06-27 19:28:51 CEST, end at Fri 2025-06-27 19:30:20 CEST. -- Jun 27 19:29:00 rivo mpd[3123]: Jun 27 19:29 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 27 19:29:00 rivo volumio-time-update[2851]: volumio-time-update-util: Fetching time from Volumio... Jun 27 19:29:00 rivo volumio-time-update[2851]: volumio-time-update-util: Date not found in response Jun 27 19:29:00 rivo volumio-time-update[2851]: volumio-time-update-util: Retrying in 5 seconds... Jun 27 19:29:00 rivo ntpd[3096]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jun 27 19:29:01 rivo sudo[3167]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:01 rivo wireless.js[2869]: Start wireless flow Jun 27 19:29:01 rivo wireless.js[2869]: Stopped hotspot (if there).. Jun 27 19:29:01 rivo sudo[3177]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jun 27 19:29:01 rivo sudo[3177]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:01 rivo sudo[3177]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:01 rivo sudo[3180]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jun 27 19:29:01 rivo sudo[3180]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:01 rivo kernel: dhd_stop: Enter ffffffc04ed0a000 Jun 27 19:29:01 rivo kernel: CFGP2P-ERROR) wl_cfgp2p_disable_discovery : do nothing, not initialized Jun 27 19:29:01 rivo kernel: CFGP2P-ERROR) wl_cfgp2p_deinit_priv : In Jun 27 19:29:01 rivo kernel: dhd_tcpack_suppress_set: TCP ACK Suppress mode 1 -> mode 0 Jun 27 19:29:01 rivo kernel: wl_android_wifi_off in 1 Jun 27 19:29:01 rivo kernel: wl_android_wifi_off in 2: g_wifi_on=1, on_failure=1 Jun 27 19:29:01 rivo kernel: dhd_dbg_detach_pkt_monitor, 2204 Jun 27 19:29:01 rivo kernel: dhd_bus_devreset: == Power OFF == Jun 27 19:29:01 rivo kernel: bcmsdh_oob_intr_unregister: Enter Jun 27 19:29:01 rivo kernel: dhd_txglom_enable: enable 0 Jun 27 19:29:01 rivo kernel: dhd_conf_set_txglom_params: txglom_mode=copy Jun 27 19:29:01 rivo kernel: dhd_conf_set_txglom_params: txglomsize=0, deferred_tx_len=0 Jun 27 19:29:01 rivo kernel: dhd_conf_set_txglom_params: txinrx_thres=128, dhd_txminmax=-1 Jun 27 19:29:01 rivo kernel: dhd_conf_set_txglom_params: tx_max_offset=0, txctl_tmo_fix=300 Jun 27 19:29:01 rivo kernel: dhd_bus_devreset: WLAN OFF DONE Jun 27 19:29:01 rivo kernel: wifi_platform_set_power = 0 Jun 27 19:29:01 rivo kernel: ======== PULL WL_REG_ON(-1) LOW! ======== Jun 27 19:29:01 rivo kernel: aml_wifi wifi: [extern_wifi_set_enable] WIFI Disable! 482 Jun 27 19:29:01 rivo dhcpcd[2873]: wlan0: carrier lost Jun 27 19:29:01 rivo kernel: wl_android_wifi_off out Jun 27 19:29:01 rivo kernel: wl_ext_iapsta_dettach_netdev: Enter Jun 27 19:29:01 rivo kernel: dhd_stop: Exit Jun 27 19:29:01 rivo dhcpcd[2873]: wlan0: carrier lost Jun 27 19:29:01 rivo volumio-remote-updater[2853]: [2025-06-27 19:29:01] [info] asio async_connect error: system:111 (Connection refused) Jun 27 19:29:01 rivo volumio-remote-updater[2853]: [2025-06-27 19:29:01] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jun 27 19:29:01 rivo volumio-remote-updater[2853]: [2025-06-27 19:29:01] [error] handle_connect error: Underlying Transport Error Jun 27 19:29:01 rivo sudo[3180]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:01 rivo wireless.js[2869]: DHCP IP Jun 27 19:29:01 rivo wireless.js[2869]: Start ap Jun 27 19:29:01 rivo wpa_supplicant[3185]: Successfully initialized wpa_supplicant Jun 27 19:29:01 rivo kernel: dhd_open: Enter ffffffc04ed0a000 Jun 27 19:29:01 rivo kernel: dhd_open : no mutex held. set lock Jun 27 19:29:01 rivo kernel: Dongle Host Driver, version 1.579.77.41.10 (r) Jun 27 19:29:01 rivo kernel: wl_ext_iapsta_attach_netdev: ifidx=0, bssidx=0 Jun 27 19:29:01 rivo kernel: wl_android_wifi_on in 1 Jun 27 19:29:01 rivo kernel: wl_android_wifi_on in 2: g_wifi_on=0 Jun 27 19:29:01 rivo kernel: wifi_platform_set_power = 1 Jun 27 19:29:01 rivo kernel: ======== PULL WL_REG_ON(-1) HIGH! ======== Jun 27 19:29:01 rivo kernel: aml_wifi wifi: [extern_wifi_set_enable] WIFI Disable! 482 Jun 27 19:29:01 rivo kernel: aml_wifi wifi: [extern_wifi_set_enable] WIFI Enable! 482 Jun 27 19:29:02 rivo kernel: sdio_reset_comm(): Jun 27 19:29:02 rivo kernel: meson-mmc: actual_clock :400000, HHI_nand: 0x80 Jun 27 19:29:02 rivo kernel: meson-mmc: [meson_mmc_clk_set_rate_v3] after clock: 0x1000023c Jun 27 19:29:02 rivo kernel: meson-mmc: actual_clock :0, HHI_nand: 0x80 Jun 27 19:29:02 rivo kernel: meson-mmc: [meson_mmc_clk_set_rate_v3] after clock: 0x1000023c Jun 27 19:29:02 rivo kernel: meson-mmc: actual_clock :400000, HHI_nand: 0x80 Jun 27 19:29:02 rivo kernel: meson-mmc: [meson_mmc_clk_set_rate_v3] after clock: 0x1000023c Jun 27 19:29:02 rivo kernel: sdio: queuing unknown CIS tuple 0x80 (2 bytes) Jun 27 19:29:02 rivo kernel: sdio: queuing unknown CIS tuple 0x80 (3 bytes) Jun 27 19:29:02 rivo kernel: sdio: queuing unknown CIS tuple 0x80 (3 bytes) Jun 27 19:29:02 rivo kernel: sdio: queuing unknown CIS tuple 0x80 (7 bytes) Jun 27 19:29:02 rivo kernel: meson-aml-mmc ffe03000.sdio: divider requested rate 200000000 != actual rate 199999997: ret=0 Jun 27 19:29:02 rivo kernel: meson-mmc: actual_clock :199999997, HHI_nand: 0x80 Jun 27 19:29:02 rivo kernel: meson-mmc: [meson_mmc_clk_set_rate_v3] after clock: 0x10000245 Jun 27 19:29:02 rivo kernel: meson-mmc: Data 1 aligned delay is 0 Jun 27 19:29:02 rivo kernel: meson-mmc: sdio: clk 199999997 tuning start Jun 27 19:29:02 rivo kernel: meson-mmc: Tuning transfer error: nmatch=0 tuning_err:0xffffffac Jun 27 19:29:02 rivo kernel: meson-mmc: sdio: rx_tuning_result[1] = 40 Jun 27 19:29:02 rivo kernel: meson-mmc: sdio: rx_tuning_result[2] = 40 Jun 27 19:29:02 rivo kernel: meson-mmc: sdio: rx_tuning_result[3] = 40 Jun 27 19:29:02 rivo kernel: meson-mmc: sdio: rx_tuning_result[4] = 40 Jun 27 19:29:02 rivo kernel: meson-mmc: [prev_map] fixed_adj_win_map:30 Jun 27 19:29:02 rivo kernel: meson-mmc: [0]=0 Jun 27 19:29:02 rivo kernel: meson-mmc: [1]=1 Jun 27 19:29:02 rivo kernel: meson-mmc: [2]=1 Jun 27 19:29:02 rivo kernel: meson-mmc: [3]=1 Jun 27 19:29:02 rivo kernel: meson-mmc: [4]=1 Jun 27 19:29:02 rivo kernel: meson-mmc: [_find_fixed_adj_valid_win]retry test fixed adj... Jun 27 19:29:02 rivo kernel: meson-mmc: step:4, delay1:0x4104104, delay2:0x4004104 Jun 27 19:29:02 rivo kernel: meson-mmc: Tuning transfer error: nmatch=0 tuning_err:0xffffffac Jun 27 19:29:02 rivo kernel: meson-mmc: sdio: rx_tuning_result[1] = 40 Jun 27 19:29:02 rivo kernel: meson-mmc: sdio: rx_tuning_result[2] = 40 Jun 27 19:29:02 rivo kernel: meson-mmc: sdio: rx_tuning_result[3] = 40 Jun 27 19:29:02 rivo kernel: meson-mmc: sdio: rx_tuning_result[4] = 40 Jun 27 19:29:02 rivo kernel: meson-mmc: [_find_fixed_adj_valid_win]retry test fixed adj... Jun 27 19:29:02 rivo kernel: meson-mmc: step:8, delay1:0x8208208, delay2:0x8008208 Jun 27 19:29:02 rivo kernel: meson-mmc: Tuning transfer error: nmatch=0 tuning_err:0xffffffac Jun 27 19:29:02 rivo kernel: meson-mmc: sdio: rx_tuning_result[1] = 40 Jun 27 19:29:02 rivo kernel: meson-mmc: sdio: rx_tuning_result[2] = 40 Jun 27 19:29:02 rivo kernel: meson-mmc: sdio: rx_tuning_result[3] = 40 Jun 27 19:29:02 rivo kernel: meson-mmc: sdio: rx_tuning_result[4] = 40 Jun 27 19:29:02 rivo kernel: meson-mmc: [_find_fixed_adj_valid_win]retry test fixed adj... Jun 27 19:29:02 rivo kernel: meson-mmc: step:12, delay1:0xc30c30c, delay2:0xc00c30c Jun 27 19:29:02 rivo kernel: meson-mmc: sdio: rx_tuning_result[0] = 40 Jun 27 19:29:02 rivo kernel: meson-mmc: Tuning transfer error: nmatch=2 tuning_err:0xffffffac Jun 27 19:29:02 rivo kernel: meson-mmc: sdio: rx_tuning_result[2] = 40 Jun 27 19:29:02 rivo kernel: meson-mmc: sdio: rx_tuning_result[3] = 40 Jun 27 19:29:02 rivo kernel: meson-mmc: sdio: rx_tuning_result[4] = 40 Jun 27 19:29:02 rivo kernel: meson-mmc: [>>>>>>>>bitmap_xor_dst] fixed_adj_win_map:2 Jun 27 19:29:02 rivo kernel: meson-mmc: [0]=0 Jun 27 19:29:02 rivo kernel: meson-mmc: [1]=1 Jun 27 19:29:02 rivo kernel: meson-mmc: [2]=0 Jun 27 19:29:02 rivo kernel: meson-mmc: [3]=0 Jun 27 19:29:02 rivo kernel: meson-mmc: [4]=0 Jun 27 19:29:02 rivo kernel: meson-mmc: [_find_fixed_adj_valid_win] fir_adj:1 Jun 27 19:29:02 rivo kernel: meson-mmc: [>>>>>>>>prev_map_range] fixed_adj_win_map:495 Jun 27 19:29:02 rivo kernel: meson-mmc: [1]=1 Jun 27 19:29:02 rivo kernel: meson-mmc: [2]=1 Jun 27 19:29:02 rivo kernel: meson-mmc: [3]=1 Jun 27 19:29:02 rivo kernel: meson-mmc: [4]=1 Jun 27 19:29:02 rivo kernel: meson-mmc: [0]=0 Jun 27 19:29:02 rivo kernel: meson-mmc: left:3, right:0, mid:4, size:4 Jun 27 19:29:02 rivo kernel: meson-mmc: step:0, delay1:0x0, delay2:0x0 Jun 27 19:29:02 rivo kernel: meson-mmc: sdio: sd_emmc_regs->gclock=0x10000245,sd_emmc_regs->gadjust=0x32000 Jun 27 19:29:02 rivo kernel: meson-mmc: delay1:0x0, delay2:0x0 Jun 27 19:29:02 rivo kernel: sdioh_start: set sd_f2_blocksize 256 Jun 27 19:29:02 rivo kernel: dhd_bus_devreset: == WLAN ON == Jun 27 19:29:02 rivo kernel: F1 signature read @0x18000000=0x17294359 Jun 27 19:29:02 rivo kernel: F1 signature OK, socitype:0x1 chip:0x4359 rev:0x9 pkg:0x2 Jun 27 19:29:02 rivo kernel: DHD: dongle ram size is set to 917504(orig 917504) at 0x160000 Jun 27 19:29:02 rivo kernel: dhd_bus_set_default_min_res_mask: Unhandled chip id Jun 27 19:29:02 rivo kernel: dhd_os_open_image: /lib/firmware/brcm/config_bcm4359c0_ag.txt (185 bytes) open success Jun 27 19:29:02 rivo kernel: dhd_conf_read_sdio_params: dhd_slpauto = 0 Jun 27 19:29:02 rivo kernel: dhd_conf_read_others: ccode = ALL Jun 27 19:29:02 rivo kernel: dhd_conf_read_others: regrev = 38 Jun 27 19:29:02 rivo kernel: dhd_conf_read_nv_by_chip: nv_by_chip_count=5 Jun 27 19:29:02 rivo kernel: dhd_conf_read_nv_by_chip: chip=0xa9a6, chiprev=0, name=nvram_ap6212.txt Jun 27 19:29:02 rivo kernel: dhd_conf_read_nv_by_chip: chip=0xa9a6, chiprev=1, name=nvram_ap6212a.txt Jun 27 19:29:02 rivo kernel: dhd_conf_read_nv_by_chip: chip=0x4345, chiprev=6, name=nvram_ap6255.txt Jun 27 19:29:02 rivo kernel: dhd_conf_read_nv_by_chip: chip=0x4354, chiprev=2, name=nvram_ap6356.txt Jun 27 19:29:02 rivo kernel: dhd_conf_read_nv_by_chip: chip=0x4359, chiprev=9, name=nvram_ap6359sa.txt Jun 27 19:29:02 rivo kernel: Final fw_path=/lib/firmware/brcm/fw_bcm4359c0_ag.bin Jun 27 19:29:02 rivo kernel: Final nv_path=/lib/firmware/brcm/nvram_ap6359sa.txt Jun 27 19:29:02 rivo kernel: Final clm_path=/lib/firmware/brcm/clm.blob Jun 27 19:29:02 rivo kernel: Final conf_path=/lib/firmware/brcm/config_bcm4359c0_ag.txt Jun 27 19:29:02 rivo kernel: dhd_os_open_image: /lib/firmware/brcm/fw_bcm4359c0_ag.bin (595758 bytes) open success Jun 27 19:29:02 rivo wireless.js[2869]: trying... Jun 27 19:29:02 rivo kernel: dhd_os_open_image: /lib/firmware/brcm/nvram_ap6359sa.txt (5861 bytes) open success Jun 27 19:29:02 rivo kernel: [43B blob data] Jun 27 19:29:02 rivo kernel: dhdsdio_write_vars: Download, Upload and compare of NVRAM succeeded. Jun 27 19:29:02 rivo kernel: dhd_bus_init: enable 0x06, ready 0x06 (waited 0us) Jun 27 19:29:02 rivo kernel: si_get_pmu_reg_addr: addrRET: 18000670 Jun 27 19:29:02 rivo kernel: bcmsdh_oob_intr_register: HW_OOB irq=70 flags=0x8 Jun 27 19:29:02 rivo kernel: dhd_get_memdump_info: File [/data/misc/wifi/.memdump.info] doesn't exist Jun 27 19:29:02 rivo kernel: dhd_get_memdump_info: MEMDUMP ENABLED = 2 Jun 27 19:29:02 rivo kernel: dhd_tcpack_suppress_set: TCP ACK Suppress mode 0 -> mode 1 Jun 27 19:29:02 rivo kernel: dhd_apply_default_clm: Ignore clm file /lib/firmware/brcm/clm.blob Jun 27 19:29:02 rivo kernel: Firmware up: op_mode=0x0405, MAC=54:78:c9:8f:f5:9c Jun 27 19:29:02 rivo kernel: Driver: 1.579.77.41.10 (r) Firmware: wl0: Jan 19 2018 12:14:30 version 9.87.51.11.8 (a85e25e@shgit) (r) FWID 01-cb5aa0a5 CLM: 9.7.5 Jun 27 19:29:02 rivo kernel: dhd_txglom_enable: enable 1 Jun 27 19:29:02 rivo kernel: dhd_conf_set_txglom_params: txglom_mode=copy Jun 27 19:29:02 rivo kernel: dhd_conf_set_txglom_params: txglomsize=36, deferred_tx_len=0 Jun 27 19:29:02 rivo kernel: dhd_conf_set_txglom_params: txinrx_thres=128, dhd_txminmax=-1 Jun 27 19:29:02 rivo kernel: dhd_conf_set_txglom_params: tx_max_offset=0, txctl_tmo_fix=300 Jun 27 19:29:02 rivo kernel: dhd_conf_get_disable_proptx: fw_proptx=0, disable_proptx=1 Jun 27 19:29:02 rivo kernel: dhd_pno_init: Support Android Location Service Jun 27 19:29:02 rivo kernel: rtt_do_get_ioctl: failed to send getbuf proxd iovar (CMD ID : 1), status=-23 Jun 27 19:29:02 rivo kernel: dhd_rtt_init : FTM is not supported Jun 27 19:29:02 rivo kernel: dhd_preinit_ioctls: SensorHub diabled 0 Jun 27 19:29:02 rivo kernel: dhd_preinit_ioctls failed to set ShubHub disable Jun 27 19:29:02 rivo kernel: failed to set WNM capabilities Jun 27 19:29:02 rivo kernel: dhd_conf_set_country: set country ALL, revision 38 Jun 27 19:29:02 rivo kernel: CONFIG-ERROR) dhd_conf_set_bufiovar: country setting failed -2 Jun 27 19:29:02 rivo kernel: Country code: US (US/0) Jun 27 19:29:02 rivo kernel: CONFIG-ERROR) dhd_conf_set_intiovar: txbf setting failed -23 Jun 27 19:29:02 rivo kernel: wl_android_wifi_on: Success Jun 27 19:29:02 rivo dhcpcd[2873]: wlan0: carrier acquired Jun 27 19:29:02 rivo kernel: dhd_open : the lock is released. Jun 27 19:29:02 rivo kernel: dhd_open: Exit ret=0 Jun 27 19:29:02 rivo dhcpcd[2873]: wlan0: carrier acquired Jun 27 19:29:02 rivo sudo[3200]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 27 19:29:02 rivo sudo[3189]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Jun 27 19:29:02 rivo sudo[3189]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:02 rivo sudo[3200]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:02 rivo dhcpcd[3203]: sending commands to master dhcpcd process Jun 27 19:29:02 rivo sudo[3189]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:02 rivo dhcpcd[2873]: wlan0: IAID c9:8f:f5:9c Jun 27 19:29:02 rivo dhcpcd[2873]: wlan0: IAID c9:8f:f5:9c Jun 27 19:29:02 rivo dhcpcd[2873]: wlan0: carrier lost Jun 27 19:29:02 rivo dhcpcd[2873]: wlan0: carrier lost Jun 27 19:29:02 rivo sudo[3200]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:02 rivo dhcpcd[2873]: control command: /sbin/dhcpcd Jun 27 19:29:02 rivo dhcpcd[2873]: control command: /sbin/dhcpcd Jun 27 19:29:02 rivo systemd[1]: systemd-rfkill.service: Succeeded. Jun 27 19:29:02 rivo kernel: P2P interface registered Jun 27 19:29:02 rivo kernel: wl_cfgp2p_add_p2p_disc_if: wdev: ffffffc04642ec00, wdev->net: (null) Jun 27 19:29:02 rivo kernel: [35B blob data] Jun 27 19:29:02 rivo kernel: P2P interface started Jun 27 19:29:03 rivo wireless.js[2869]: trying... Jun 27 19:29:03 rivo sudo[3216]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 27 19:29:03 rivo sudo[3216]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:03 rivo sudo[3216]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:04 rivo wireless.js[2869]: trying... Jun 27 19:29:04 rivo sudo[3219]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 27 19:29:04 rivo sudo[3219]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:04 rivo sudo[3219]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:05 rivo wpa_supplicant[3214]: wlan0: Trying to associate with 88:1f:a1:36:1f:c1 (SSID='NASA WIFI NETWORK' freq=5500 MHz) Jun 27 19:29:05 rivo kernel: Connecting with 88:1f:a1:36:1f:c1 ssid "NASA WIFI NETWORK", len (17) channel=100 Jun 27 19:29:05 rivo kernel: dhd_dbg_start_pkt_monitor, 1724 Jun 27 19:29:05 rivo kernel: wl_iw_event: Link UP with 88:1f:a1:36:1f:c1 Jun 27 19:29:05 rivo kernel: wl_bss_connect_done succeeded with 88:1f:a1:36:1f:c1 Jun 27 19:29:05 rivo kernel: CFG80211-ERROR) wl_cfg80211_scan_abort : scan abort failed Jun 27 19:29:05 rivo wpa_supplicant[3214]: wlan0: Associated with 88:1f:a1:36:1f:c1 Jun 27 19:29:05 rivo wpa_supplicant[3214]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jun 27 19:29:05 rivo wpa_supplicant[3214]: wlan0: WPA: Key negotiation completed with 88:1f:a1:36:1f:c1 [PTK=CCMP GTK=CCMP] Jun 27 19:29:05 rivo wpa_supplicant[3214]: wlan0: CTRL-EVENT-CONNECTED - Connection to 88:1f:a1:36:1f:c1 completed [id=0 id_str=] Jun 27 19:29:05 rivo dhcpcd[2873]: wlan0: carrier acquired Jun 27 19:29:05 rivo dhcpcd[2873]: wlan0: carrier acquired Jun 27 19:29:05 rivo wpa_supplicant[3214]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=IT Jun 27 19:29:05 rivo dhcpcd[2873]: wlan0: IAID c9:8f:f5:9c Jun 27 19:29:05 rivo dhcpcd[2873]: wlan0: IAID c9:8f:f5:9c Jun 27 19:29:05 rivo kernel: wl_bss_connect_done succeeded with 88:1f:a1:36:1f:c1 vndr_oui: 00-17-F2 00-10-18 Jun 27 19:29:05 rivo volumio-time-update[2851]: volumio-time-update-util: Fetching time from Volumio... Jun 27 19:29:05 rivo volumio-time-update[2851]: volumio-time-update-util: Date not found in response Jun 27 19:29:05 rivo volumio-time-update[2851]: volumio-time-update-util: Retrying in 5 seconds... Jun 27 19:29:05 rivo wireless.js[2869]: trying... Jun 27 19:29:05 rivo sudo[3229]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 27 19:29:05 rivo sudo[3229]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:05 rivo sudo[3229]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:05 rivo dhcpcd[2873]: wlan0: soliciting a DHCP lease Jun 27 19:29:05 rivo dhcpcd[2873]: wlan0: soliciting a DHCP lease Jun 27 19:29:06 rivo dhcpcd[2873]: wlan0: soliciting an IPv6 router Jun 27 19:29:06 rivo dhcpcd[2873]: wlan0: soliciting an IPv6 router Jun 27 19:29:06 rivo kernel: meson_uart ffd24000.serial: ttyS1 use xtal(24M) 24000000 change 115200 to 2000000 Jun 27 19:29:06 rivo systemd[1]: Starting Load/Save RF Kill Switch Status... Jun 27 19:29:06 rivo systemd[1]: Started Load/Save RF Kill Switch Status. Jun 27 19:29:06 rivo systemd[1]: Starting Bluetooth service... Jun 27 19:29:06 rivo bluetoothd[3235]: Bluetooth daemon 5.50 Jun 27 19:29:06 rivo bluetoothd[3235]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Jun 27 19:29:06 rivo systemd[1]: Started Bluetooth service. Jun 27 19:29:06 rivo systemd[1]: Reached target Bluetooth. Jun 27 19:29:06 rivo bluetoothd[3235]: Starting SDP server Jun 27 19:29:06 rivo bluetoothd[3235]: Excluding (cli) sap Jun 27 19:29:06 rivo bluetoothd[3235]: Bluetooth management interface 1.14 initialized Jun 27 19:29:06 rivo dbus-daemon[2866]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=3235 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap " label="kernel") Jun 27 19:29:06 rivo systemd[1]: Starting Hostname Service... Jun 27 19:29:06 rivo kernel: IPVS: Creating netns size=1928 id=2 Jun 27 19:29:06 rivo wireless.js[2869]: trying... Jun 27 19:29:06 rivo sudo[3242]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 27 19:29:06 rivo sudo[3242]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:06 rivo sudo[3242]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:06 rivo dhcpcd[2873]: wlan0: offered 192.168.0.36 from 192.168.0.254 Jun 27 19:29:06 rivo dhcpcd[2873]: wlan0: offered 192.168.0.36 from 192.168.0.254 Jun 27 19:29:06 rivo dbus-daemon[2866]: [system] Successfully activated service 'org.freedesktop.hostname1' Jun 27 19:29:06 rivo systemd[1]: Started Hostname Service. Jun 27 19:29:07 rivo dhcpcd[2873]: wlan0: probing address 192.168.0.36/24 Jun 27 19:29:07 rivo dhcpcd[2873]: wlan0: probing address 192.168.0.36/24 Jun 27 19:29:07 rivo wireless.js[2869]: trying... Jun 27 19:29:07 rivo sudo[3245]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 27 19:29:07 rivo sudo[3245]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:07 rivo sudo[3245]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:08 rivo wireless.js[2869]: trying... Jun 27 19:29:08 rivo sudo[3248]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 27 19:29:08 rivo sudo[3248]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:08 rivo sudo[3248]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:09 rivo volumio-remote-updater[2853]: [2025-06-27 19:29:09] [info] asio async_connect error: system:111 (Connection refused) Jun 27 19:29:09 rivo volumio-remote-updater[2853]: [2025-06-27 19:29:09] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jun 27 19:29:09 rivo volumio-remote-updater[2853]: [2025-06-27 19:29:09] [error] handle_connect error: Underlying Transport Error Jun 27 19:29:09 rivo wireless.js[2869]: trying... Jun 27 19:29:09 rivo sudo[3251]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 27 19:29:09 rivo sudo[3251]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:09 rivo sudo[3251]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:10 rivo volumio-time-update[2851]: volumio-time-update-util: Fetching time from Volumio... Jun 27 19:29:10 rivo volumio-time-update[2851]: volumio-time-update-util: Date not found in response Jun 27 19:29:10 rivo volumio-time-update[2851]: volumio-time-update-util: Retrying in 5 seconds... Jun 27 19:29:10 rivo wireless.js[2869]: trying... Jun 27 19:29:10 rivo sudo[3259]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 27 19:29:10 rivo sudo[3259]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:10 rivo sudo[3259]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:11 rivo systemd[1]: systemd-rfkill.service: Succeeded. Jun 27 19:29:11 rivo wireless.js[2869]: trying... Jun 27 19:29:11 rivo sudo[3262]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 27 19:29:11 rivo sudo[3262]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:11 rivo sudo[3262]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:12 rivo wireless.js[2869]: trying... Jun 27 19:29:12 rivo sudo[3265]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 27 19:29:12 rivo sudo[3265]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:12 rivo sudo[3265]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:12 rivo dhcpcd[2873]: wlan0: leased 192.168.0.36 for 86400 seconds Jun 27 19:29:12 rivo dhcpcd[2873]: wlan0: leased 192.168.0.36 for 86400 seconds Jun 27 19:29:12 rivo avahi-daemon[2855]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.36. Jun 27 19:29:12 rivo avahi-daemon[2855]: New relevant interface wlan0.IPv4 for mDNS. Jun 27 19:29:12 rivo dhcpcd[2873]: wlan0: adding route to 192.168.0.0/24 Jun 27 19:29:12 rivo dhcpcd[2873]: wlan0: adding default route via 192.168.0.254 Jun 27 19:29:12 rivo dhcpcd[2873]: wlan0: adding route to 192.168.0.0/24 Jun 27 19:29:12 rivo avahi-daemon[2855]: Registering new address record for 192.168.0.36 on wlan0.IPv4. Jun 27 19:29:12 rivo dhcpcd[2873]: wlan0: adding default route via 192.168.0.254 Jun 27 19:29:13 rivo ntpd[3096]: ntpd exiting on signal 15 (Terminated) Jun 27 19:29:13 rivo systemd[1]: Stopping Network Time Service... Jun 27 19:29:13 rivo systemd[1]: ntp.service: Succeeded. Jun 27 19:29:13 rivo systemd[1]: Stopped Network Time Service. Jun 27 19:29:13 rivo systemd[1]: Starting Network Time Service... Jun 27 19:29:13 rivo ntpd[3303]: ntpd 4.2.8p12@1.3728-o (1): Starting Jun 27 19:29:13 rivo ntpd[3303]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Jun 27 19:29:13 rivo systemd[1]: Started Network Time Service. Jun 27 19:29:13 rivo dhcpcd[2873]: forked to background, child pid 3315 Jun 27 19:29:13 rivo dhcpcd[2873]: forked to background, child pid 3315 Jun 27 19:29:13 rivo ntpd[3314]: proto: precision = 1.250 usec (-20) Jun 27 19:29:13 rivo ntpd[3314]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jun 27 19:29:13 rivo systemd[1]: Started DHCP Client Daemon. Jun 27 19:29:13 rivo ntpd[3314]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Jun 27 19:29:13 rivo ntpd[3314]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 913 days ago Jun 27 19:29:13 rivo ntpd[3314]: Listen and drop on 0 v6wildcard [::]:123 Jun 27 19:29:13 rivo ntpd[3314]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jun 27 19:29:13 rivo ntpd[3314]: Listen normally on 2 lo 127.0.0.1:123 Jun 27 19:29:13 rivo ntpd[3314]: Listen normally on 3 wlan0 192.168.0.36:123 Jun 27 19:29:13 rivo ntpd[3314]: Listening on routing socket on fd #20 for interface updates Jun 27 19:29:13 rivo ntpd[3314]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 27 19:29:13 rivo ntpd[3314]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 27 19:29:13 rivo wireless.js[2869]: trying... Jun 27 19:29:13 rivo sudo[3318]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 27 19:29:13 rivo sudo[3318]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:13 rivo sudo[3318]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:13 rivo wireless.js[2869]: Connected to: ----NASA WIFI NETWORK Jun 27 19:29:13 rivo wireless.js[2869]: ---- Jun 27 19:29:13 rivo sudo[3321]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 27 19:29:13 rivo sudo[3321]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:13 rivo sudo[3321]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:13 rivo wireless.js[2869]: ... joined AP, wlan0 IPv4 is 192.168.0.36, ipV6 is undefined Jun 27 19:29:13 rivo wireless.js[2869]: It's done! AP Jun 27 19:29:13 rivo systemd[1]: Started Wireless Services. Jun 27 19:29:13 rivo systemd[1]: Started Volumio Backend Module. Jun 27 19:29:13 rivo systemd[1]: Started Start Volumio Kiosk. Jun 27 19:29:13 rivo systemd[1]: Started Volumio Cpu Tweaker. Jun 27 19:29:13 rivo startkiosk.sh[3328]: Starting Volumio Kiosk with arguments for cursor display Jun 27 19:29:13 rivo volumio-cpu-tweak[3329]: Setting RT Priority for mpd Jun 27 19:29:13 rivo volumio-cpu-tweak[3329]: Setting MPD Affinity Jun 27 19:29:13 rivo systemd[1]: Started Samba NMB Daemon. Jun 27 19:29:13 rivo kernel: nf_conntrack: default automatic helper assignment has been turned off for security reasons and CT-based firewall rule not found. Use the iptables CT target to attach helpers instead. Jun 27 19:29:13 rivo nmbd[3092]: [2025/06/27 19:29:13.908468, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 27 19:29:13 rivo nmbd[3092]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Jun 27 19:29:13 rivo systemd[1]: Starting Samba Winbind Daemon... Jun 27 19:29:14 rivo startkiosk.sh[3328]: X.Org X Server 1.20.4 Jun 27 19:29:14 rivo startkiosk.sh[3328]: X Protocol Version 11, Revision 0 Jun 27 19:29:14 rivo startkiosk.sh[3328]: Build Operating System: Linux 4.19.0-18-armmp-lpae armv7l Debian Jun 27 19:29:14 rivo startkiosk.sh[3328]: Current Operating System: Linux rivo 4.9.241 #4 SMP PREEMPT Wed Jun 4 18:07:40 CEST 2025 aarch64 Jun 27 19:29:14 rivo startkiosk.sh[3328]: Kernel command line: imgpart=UUID=9671d1cc-4482-4e1f-bf35-ff8647e93a01 imgfile=/volumio_current.sqsh bootpart=UUID=004F-1E40 datapart=UUID=a6b605b4-4ae7-4c34-b625-7dde672f7201 uuidconfig=env.system.txt hwdevice=VIM3 console=tty0 console=ttyS0,115200n8 no_console_suspend consoleblank=0 logo=osd0,loaded,0x3d800000,panel vout=panel,enable hdmimode=1080p60hz fsck.repair=yes net.ifnames=0 ddr_size= wol_enable= mac=02:00:00:18:0c:01 fan=auto hwver=VIM3.V11 coherent_pool=2M quiet loglevel=0 splash plymouth.ignore-serial-consoles initramfs.clear splash bootdelay=7 Jun 27 19:29:14 rivo startkiosk.sh[3328]: Build Date: 18 December 2021 09:05:36AM Jun 27 19:29:14 rivo startkiosk.sh[3328]: xorg-server 2:1.20.4-1+deb10u4 (https://www.debian.org/support) Jun 27 19:29:14 rivo startkiosk.sh[3328]: Current version of pixman: 0.36.0 Jun 27 19:29:14 rivo startkiosk.sh[3328]: Before reporting problems, check http://wiki.x.org Jun 27 19:29:14 rivo startkiosk.sh[3328]: to make sure that you have the latest version. Jun 27 19:29:14 rivo startkiosk.sh[3328]: Markers: (--) probed, (**) from config file, (==) default setting, Jun 27 19:29:14 rivo startkiosk.sh[3328]: (++) from command line, (!!) notice, (II) informational, Jun 27 19:29:14 rivo startkiosk.sh[3328]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Jun 27 19:29:14 rivo startkiosk.sh[3328]: (==) Log file: "/var/log/Xorg.0.log", Time: Fri Jun 27 19:29:14 2025 Jun 27 19:29:14 rivo startkiosk.sh[3328]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Jun 27 19:29:14 rivo volumio-cpu-tweak[3329]: pid 3123's current affinity mask: f Jun 27 19:29:14 rivo volumio-cpu-tweak[3329]: pid 3123's new affinity mask: 3 Jun 27 19:29:14 rivo volumio-cpu-tweak[3329]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Jun 27 19:29:14 rivo volumio-cpu-tweak[3329]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Jun 27 19:29:14 rivo systemd[1]: volumio_cpu_tweak.service: Succeeded. Jun 27 19:29:14 rivo kernel: usb 1-1.2: reset high-speed USB device number 4 using xhci-hcd Jun 27 19:29:14 rivo ntpd[3314]: Soliciting pool server 195.32.70.195 Jun 27 19:29:14 rivo kernel: fb: osd[0] canvas.idx =0x40 Jun 27 19:29:14 rivo kernel: fb: osd[0] canvas.addr=0x70000000 Jun 27 19:29:14 rivo kernel: fb: osd[0] canvas.width=7680 Jun 27 19:29:14 rivo kernel: fb: osd[0] canvas.height=1080 Jun 27 19:29:14 rivo kernel: fb: osd[0] frame.width=1920 Jun 27 19:29:14 rivo kernel: fb: osd[0] frame.height=1080 Jun 27 19:29:14 rivo kernel: fb: osd[0] out_addr_id =0x1 Jun 27 19:29:14 rivo kernel: fb: osd[0] enable: 0 (Xorg) Jun 27 19:29:14 rivo winbindd[3362]: [2025/06/27 19:29:14.356793, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Jun 27 19:29:14 rivo winbindd[3362]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jun 27 19:29:14 rivo winbindd[3362]: [2025/06/27 19:29:14.374948, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 27 19:29:14 rivo winbindd[3362]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jun 27 19:29:14 rivo systemd[1]: Started Samba Winbind Daemon. Jun 27 19:29:14 rivo systemd[1]: Starting Samba SMB Daemon... Jun 27 19:29:15 rivo systemd[1]: Started Samba SMB Daemon. Jun 27 19:29:15 rivo smbd[3375]: [2025/06/27 19:29:15.121747, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 27 19:29:15 rivo smbd[3375]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jun 27 19:29:15 rivo ntpd[3314]: Soliciting pool server 212.45.144.88 Jun 27 19:29:15 rivo ntpd[3314]: Soliciting pool server 212.45.144.3 Jun 27 19:29:15 rivo volumio-time-update[2851]: volumio-time-update-util: Fetching time from Volumio... Jun 27 19:29:15 rivo volumio-time-update[2851]: volumio-time-update-util: Setting system time to: 2025-06-27 19:29:14 Jun 27 19:29:15 rivo sudo[3394]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-06-27 19:29:14 Jun 27 19:29:15 rivo sudo[3394]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:15 rivo dbus-daemon[2866]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.9' (uid=0 pid=3395 comm="timedatectl set-time 2025-06-27 19:29:14 " label="kernel") Jun 27 19:29:15 rivo kernel: fb: osd[0] enable: 1 (Xorg) Jun 27 19:29:15 rivo systemd[1]: Starting Time & Date Service... Jun 27 19:29:16 rivo dbus-daemon[2866]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 27 19:29:16 rivo systemd[1]: Started Time & Date Service. Jun 27 19:29:14 rivo systemd-timedated[3397]: Changed local time to Fri Jun 27 19:29:14 2025 Jun 27 19:29:14 rivo systemd[1]: Started Volumio Time Update Utility. Jun 27 19:29:14 rivo volumio-time-update[2851]: volumio-time-update-util: System time updated successfully. Jun 27 19:29:14 rivo sudo[3394]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:14 rivo systemd[1]: Reached target Multi-User System. Jun 27 19:29:14 rivo systemd[1]: Reached target Graphical Interface. Jun 27 19:29:14 rivo systemd[1]: Starting Update UTMP about System Runlevel Changes... Jun 27 19:29:14 rivo ntpd[3314]: Soliciting pool server 95.110.135.141 Jun 27 19:29:14 rivo ntpd[3314]: Soliciting pool server 151.22.209.90 Jun 27 19:29:14 rivo systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jun 27 19:29:14 rivo systemd[1]: Started Update UTMP about System Runlevel Changes. Jun 27 19:29:15 rivo volumio[3327]: info: ------------------------------------------- Jun 27 19:29:15 rivo volumio[3327]: info: ----- Volumio3 ---- Jun 27 19:29:15 rivo volumio[3327]: info: ------------------------------------------- Jun 27 19:29:15 rivo volumio[3327]: info: ----- System startup ---- Jun 27 19:29:15 rivo volumio[3327]: info: ------------------------------------------- Jun 27 19:29:15 rivo ntpd[3314]: Soliciting pool server 95.110.254.234 Jun 27 19:29:15 rivo ntpd[3314]: Soliciting pool server 162.159.200.1 Jun 27 19:29:15 rivo ntpd[3314]: Soliciting pool server 129.152.16.145 Jun 27 19:29:15 rivo ntpd[3314]: Soliciting pool server 185.157.229.254 Jun 27 19:29:16 rivo ntpd[3314]: Soliciting pool server 89.46.74.148 Jun 27 19:29:16 rivo ntpd[3314]: Soliciting pool server 162.159.200.123 Jun 27 19:29:16 rivo ntpd[3314]: Soliciting pool server 85.199.214.99 Jun 27 19:29:16 rivo ntpd[3314]: Soliciting pool server 212.45.144.206 Jun 27 19:29:16 rivo kernel: fb: osd[0] enable: 1 (Xorg) Jun 27 19:29:16 rivo volumio[3327]: info: MYVOLUMIO Environment detected Jun 27 19:29:16 rivo volumio[3327]: info: Plugin folders cleanup Jun 27 19:29:16 rivo volumio[3327]: info: Scanning into folder /volumio/app/plugins/ Jun 27 19:29:16 rivo volumio[3327]: info: Scanning category audio_interface Jun 27 19:29:16 rivo volumio[3327]: info: Scanning category miscellanea Jun 27 19:29:16 rivo volumio[3327]: info: Scanning category music_service Jun 27 19:29:16 rivo volumio[3327]: info: Scanning category plugins.json Jun 27 19:29:16 rivo volumio[3327]: info: Scanning category system_controller Jun 27 19:29:16 rivo volumio[3327]: info: Scanning category user_interface Jun 27 19:29:16 rivo volumio[3327]: info: Scanning into folder /data/plugins/ Jun 27 19:29:16 rivo volumio[3327]: info: Plugin folders cleanup completed Jun 27 19:29:16 rivo volumio[3327]: info: ------------------------------------------- Jun 27 19:29:16 rivo volumio[3327]: info: ----- Core plugins startup ---- Jun 27 19:29:16 rivo volumio[3327]: info: ------------------------------------------- Jun 27 19:29:16 rivo volumio[3327]: info: Loading plugins from folder /volumio/app/plugins/ Jun 27 19:29:16 rivo volumio[3327]: info: Adding plugin bluetooth to MyMusic Plugins Jun 27 19:29:16 rivo volumio[3327]: info: Adding plugin multiroom to MyMusic Plugins Jun 27 19:29:16 rivo volumio[3327]: info: Adding plugin upnp to MyMusic Plugins Jun 27 19:29:16 rivo volumio[3327]: info: Adding plugin metavolumio to MyMusic Plugins Jun 27 19:29:16 rivo volumio[3327]: info: Adding plugin airplay_emulation to MyMusic Plugins Jun 27 19:29:16 rivo volumio[3327]: info: Adding plugin cd_controller to MyMusic Plugins Jun 27 19:29:16 rivo volumio[3327]: info: Adding plugin qobuzconnect to MyMusic Plugins Jun 27 19:29:16 rivo volumio[3327]: info: Adding plugin raat to MyMusic Plugins Jun 27 19:29:16 rivo volumio[3327]: info: Adding plugin smart_inputs to MyMusic Plugins Jun 27 19:29:16 rivo volumio[3327]: info: Adding plugin tidalconnect to MyMusic Plugins Jun 27 19:29:16 rivo volumio[3327]: info: Adding plugin upnp_browser to MyMusic Plugins Jun 27 19:29:16 rivo volumio[3327]: info: Loading plugins from folder /data/plugins/ Jun 27 19:29:16 rivo volumio[3327]: info: Loading plugin "system"... Jun 27 19:29:16 rivo volumio[3327]: info: Loading plugin "appearance"... Jun 27 19:29:17 rivo ntpd[3314]: Soliciting pool server 37.247.53.178 Jun 27 19:29:17 rivo ntpd[3314]: Soliciting pool server 93.94.88.50 Jun 27 19:29:17 rivo ntpd[3314]: Soliciting pool server 185.19.184.35 Jun 27 19:29:17 rivo kernel: usb 1-1.2: device descriptor read/64, error -110 Jun 27 19:29:17 rivo kernel: usb 1-1.2: Device no response Jun 27 19:29:18 rivo ntpd[3314]: Soliciting pool server 93.94.88.51 Jun 27 19:29:18 rivo ntpd[3314]: Soliciting pool server 81.56.230.156 Jun 27 19:29:18 rivo volumio[3327]: info: Loading plugin "network"... Jun 27 19:29:18 rivo volumio[3327]: info: Refreshing Cached IP Addresses Jun 27 19:29:18 rivo sudo[3461]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 27 19:29:18 rivo sudo[3461]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:18 rivo sudo[3463]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 27 19:29:18 rivo sudo[3463]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:18 rivo sudo[3461]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:18 rivo volumio[3327]: info: Loading plugin "services"... Jun 27 19:29:18 rivo volumio[3327]: info: Loading plugin "alsa_controller"... Jun 27 19:29:18 rivo sudo[3463]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:18 rivo sudo[3474]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jun 27 19:29:18 rivo sudo[3474]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:18 rivo kernel: wl_escan_set_scan: ioctl_ver=2 Jun 27 19:29:18 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04ed0a000 drv_status 0x0 e_type 69 e_states 8 Jun 27 19:29:18 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04ed0a000 drv_status 0x0 e_type 69 e_states 8 Jun 27 19:29:18 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04ed0a000 drv_status 0x0 e_type 69 e_states 8 Jun 27 19:29:18 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 27 19:29:18 rivo volumio[3327]: info: Loading plugin "wizard"... Jun 27 19:29:18 rivo volumio[3327]: info: Loading plugin "networkfs"... Jun 27 19:29:18 rivo volumio[3327]: info: Starting Udev Watcher for removable devices Jun 27 19:29:18 rivo sudo[3492]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,vers=1.0 //192.168.0.20/FEDE /mnt/NAS/FEDE Jun 27 19:29:18 rivo sudo[3492]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:19 rivo volumio[3327]: info: Ignoring mount for partition: BOOT Jun 27 19:29:19 rivo volumio[3327]: info: Ignoring mount for partition: volumio Jun 27 19:29:19 rivo volumio[3327]: info: Ignoring mount for partition: volumio_data Jun 27 19:29:19 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 27 19:29:19 rivo volumio[3327]: info: Loading plugin "volumio_command_line_client"... Jun 27 19:29:19 rivo volumio[3327]: info: Loading plugin "upnp"... Jun 27 19:29:19 rivo volumio-remote-updater[2853]: [2025-06-27 19:29:19] [connect] Successful connection Jun 27 19:29:19 rivo volumio[3327]: info: [1751045359032] Starting Upmpd Daemon Jun 27 19:29:19 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 27 19:29:19 rivo volumio[3327]: info: Loading plugin "my_music"... Jun 27 19:29:19 rivo volumio[3327]: info: Loading plugin "mpd"... Jun 27 19:29:19 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04ed0a000 drv_status 0x0 e_type 69 e_states 8 Jun 27 19:29:19 rivo sudo[3492]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:19 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04ed0a000 drv_status 0x0 e_type 69 e_states 8 Jun 27 19:29:19 rivo volumio[3327]: info: Loading plugin "upnp_browser"... Jun 27 19:29:19 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04ed0a000 drv_status 0x0 e_type 69 e_states 8 Jun 27 19:29:20 rivo ntpd[3314]: receive: Unexpected origin timestamp 0xec095370.115310fd does not match aorg 0000000000.00000000 from server@185.157.229.254 xmt 0xec095370.eaa114c9 Jun 27 19:29:20 rivo volumio[3327]: info: Loading plugin "bluetooth"... Jun 27 19:29:21 rivo ntpd[3314]: receive: Unexpected origin timestamp 0xec095370.1142538a does not match aorg 0000000000.00000000 from server@85.199.214.99 xmt 0xec095370.ed1053ad Jun 27 19:29:21 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04ed0a000 drv_status 0x0 e_type 69 e_states 8 Jun 27 19:29:21 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04ed0a000 drv_status 0x0 e_type 69 e_states 8 Jun 27 19:29:21 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04ed0a000 drv_status 0x0 e_type 69 e_states 8 Jun 27 19:29:21 rivo volumio[3327]: info: [1751045361218] Starting BluetoothController Jun 27 19:29:21 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04ed0a000 drv_status 0x0 e_type 69 e_states 8 Jun 27 19:29:21 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04ed0a000 drv_status 0x0 e_type 69 e_states 8 Jun 27 19:29:21 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04ed0a000 drv_status 0x0 e_type 69 e_states 8 Jun 27 19:29:21 rivo volumio[3327]: info: Loading plugin "alarm-clock"... Jun 27 19:29:21 rivo volumio[3327]: info: Loading plugin "manifestui"... Jun 27 19:29:21 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04ed0a000 drv_status 0x0 e_type 69 e_states 8 Jun 27 19:29:22 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04ed0a000 drv_status 0x0 e_type 69 e_states 8 Jun 27 19:29:22 rivo volumio[3327]: info: Loading plugin "metavolumio"... Jun 27 19:29:22 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04ed0a000 drv_status 0x0 e_type 69 e_states 8 Jun 27 19:29:23 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04ed0a000 drv_status 0x0 e_type 69 e_states 8 Jun 27 19:29:23 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04ed0a000 drv_status 0x0 e_type 69 e_states 8 Jun 27 19:29:23 rivo systemd[1]: systemd-fsckd.service: Succeeded. Jun 27 19:29:23 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04ed0a000 drv_status 0x0 e_type 69 e_states 0 Jun 27 19:29:23 rivo sudo[3474]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:24 rivo volumio[3327]: info: Loading plugin "airplay_emulation"... Jun 27 19:29:24 rivo volumio[3327]: info: Starting Shairport Sync Jun 27 19:29:24 rivo volumio[3327]: info: Loading plugin "cd_controller"... Jun 27 19:29:24 rivo kernel: usb 1-1.1: reset high-speed USB device number 3 using xhci-hcd Jun 27 19:29:24 rivo volumio[3327]: info: Loading plugin "last_100"... Jun 27 19:29:24 rivo volumio[3327]: info: Loading plugin "qobuzconnect"... Jun 27 19:29:24 rivo volumio[3327]: info: Loading plugin "raat"... Jun 27 19:29:25 rivo volumio[3327]: info: RAAT Plugin loaded Jun 27 19:29:25 rivo volumio[3327]: info: Adding restartRAATSocket REST API Endpoint Jun 27 19:29:25 rivo volumio[3327]: info: Adding restartRAATSocket REST Endpoint for plugin: music_service/raat Jun 27 19:29:25 rivo volumio[3327]: info: Loading plugin "streaming_services"... Jun 27 19:29:25 rivo sh[2781]: timed out Jun 27 19:29:25 rivo sh[2781]: dhcpcd exited Jun 27 19:29:25 rivo dhcpcd[2833]: timed out Jun 27 19:29:25 rivo systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Jun 27 19:29:25 rivo sh[2781]: ifup: failed to bring up eth0 Jun 27 19:29:25 rivo dhcpcd[2833]: dhcpcd exited Jun 27 19:29:25 rivo systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Jun 27 19:29:27 rivo volumio[3327]: info: Starting Streaming Service Transparent Proxy Jun 27 19:29:27 rivo volumio[3327]: info: Loading plugin "tidalconnect"... Jun 27 19:29:27 rivo volumio[3327]: info: Loading plugin "webradio"... Jun 27 19:29:28 rivo volumio[3327]: info: Loading plugin "i2s_dacs"... Jun 27 19:29:28 rivo volumio[3327]: info: I2S DAC not set, start Auto-detection Jun 27 19:29:28 rivo volumio[3327]: info: Loading plugin "volumiodiscovery"... Jun 27 19:29:28 rivo volumio[3327]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 27 19:29:28 rivo volumio[3327]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 27 19:29:28 rivo volumio[3327]: *** WARNING *** For more information see Jun 27 19:29:28 rivo node[3327]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 27 19:29:28 rivo volumio[3327]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 27 19:29:28 rivo volumio[3327]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 27 19:29:28 rivo volumio[3327]: *** WARNING *** For more information see Jun 27 19:29:28 rivo node[3327]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 27 19:29:28 rivo node[3327]: *** WARNING *** For more information see Jun 27 19:29:28 rivo node[3327]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 27 19:29:28 rivo node[3327]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 27 19:29:28 rivo node[3327]: *** WARNING *** For more information see Jun 27 19:29:28 rivo volumio[3327]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 27 19:29:28 rivo volumio[3327]: info: Discovery: Started advertising with name: Rivo Jun 27 19:29:28 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 27 19:29:28 rivo volumio[3327]: info: Plugin multiroom is not enabled Jun 27 19:29:28 rivo volumio[3327]: info: Loading plugin "outputs"... Jun 27 19:29:28 rivo volumio[3327]: info: Loading plugin "albumart"... Jun 27 19:29:28 rivo volumio[3327]: info: Plugin example_plugin is not enabled Jun 27 19:29:28 rivo volumio[3327]: info: Loading plugin "hi_res_audio"... Jun 27 19:29:29 rivo volumio[3327]: Forking 3 albumart workers Jun 27 19:29:30 rivo volumio[3327]: STREAMING PROXY: Starting server on port 3245 Jun 27 19:29:30 rivo volumio[3327]: Node JS runtime: 14 Jun 27 19:29:32 rivo volumio[3327]: Starting albumart workers Jun 27 19:29:32 rivo volumio[3327]: Starting albumart workers Jun 27 19:29:32 rivo volumio[3327]: Starting albumart workers Jun 27 19:29:34 rivo volumio-remote-updater[2853]: [2025-06-27 19:29:34] [connect] Successful connection Jun 27 19:29:35 rivo volumio[3327]: info: Applying required configuration parameters for plugin hi_res_audio Jun 27 19:29:35 rivo volumio[3327]: info: Loading plugin "inputs"... Jun 27 19:29:35 rivo systemd[1]: systemd-hostnamed.service: Succeeded. Jun 27 19:29:36 rivo volumio[3327]: info: Loading plugin "qobuz"... Jun 27 19:29:37 rivo systemd[1]: Started Music Player Daemon. Jun 27 19:29:37 rivo systemd[1]: Startup finished in 12.966s (kernel) + 47.248s (userspace) = 1min 214ms. Jun 27 19:29:37 rivo mpd_monitor.sh[2874]: MPD Monitor Service: MPD restarted due to no mpc output. Jun 27 19:29:37 rivo kernel: sdb: sdb1 sdb2 Jun 27 19:29:37 rivo kernel: sd 1:0:0:0: [sdb] Very big device. Trying to use READ CAPACITY(16). Jun 27 19:29:37 rivo kernel: sd 1:0:0:0: [sdb] Attached SCSI disk Jun 27 19:29:37 rivo kernel: sda: sda1 sda2 Jun 27 19:29:37 rivo kernel: sd 0:0:0:0: [sda] Very big device. Trying to use READ CAPACITY(16). Jun 27 19:29:37 rivo kernel: sd 0:0:0:0: [sda] Attached SCSI disk Jun 27 19:29:38 rivo volumio[3327]: info: Loading plugin "smart_inputs"... Jun 27 19:29:38 rivo volumio[3327]: info: Loading plugin "tidal"... Jun 27 19:29:39 rivo kernel: fb: mem_free_work, free memory: addr:800000 Jun 27 19:29:40 rivo volumio[3327]: info: Loading plugin "rivocontrol"... Jun 27 19:29:41 rivo volumio[3327]: info: Adding this device properties Jun 27 19:29:41 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , setThisDeviceVolumioProperties Jun 27 19:29:41 rivo volumio[3327]: info: Setting Additional Device Volumio Properties: [object Object] Jun 27 19:29:41 rivo volumio[3327]: info: Loading plugin "updater_comm"... Jun 27 19:29:41 rivo volumio[3327]: info: Loading plugin "cec_controller"... Jun 27 19:29:41 rivo volumio[3327]: info: Applying required configuration parameters for plugin cec_controller Jun 27 19:29:41 rivo volumio[3327]: info: Plugin mpdemulation is not enabled Jun 27 19:29:41 rivo volumio[3327]: info: Loading plugin "rest_api"... Jun 27 19:29:41 rivo volumio[3327]: info: Loading plugin "websocket"... Jun 27 19:29:41 rivo volumio[3327]: info: Starting Socket.io Server version 2.3.0 Jun 27 19:29:41 rivo volumio[3327]: info: Loading i18n strings for locale it Jun 27 19:29:41 rivo volumio[3327]: Updating browse sources language Jun 27 19:29:41 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::initPlayerControls Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 27 19:29:42 rivo volumio[3327]: Express server listening on port 3000 Jun 27 19:29:42 rivo volumio[3327]: [Metrics] WebUI: 27s 398.80ms Jun 27 19:29:42 rivo volumio[3327]: info: CoreStateMachine::resetVolumioState Jun 27 19:29:42 rivo volumio[3327]: info: CoreStateMachine::getcurrentVolume Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::volumioRetrievevolume Jun 27 19:29:42 rivo volumio[3327]: info: CoreStateMachine::pushState Jun 27 19:29:42 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::volumioPushState Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 27 19:29:42 rivo sudo[3780]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 27 19:29:42 rivo sudo[3780]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:42 rivo sudo[3780]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:42 rivo volumio[3327]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Jun 27 19:29:42 rivo volumio[3327]: info: Completed loading Core Plugins Jun 27 19:29:42 rivo sudo[3782]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 27 19:29:42 rivo volumio[3327]: info: Preparing to generate the ALSA configuration file Jun 27 19:29:42 rivo sudo[3782]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:42 rivo sudo[3782]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:42 rivo volumio[3327]: info: Volumio Network Manager: Network status updated: 2 Jun 27 19:29:42 rivo volumio[3327]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Jun 27 19:29:42 rivo volumio[3327]: error: Cannot associate FS Label, not mounting Jun 27 19:29:42 rivo volumio[3327]: info: Reloading queue from file Jun 27 19:29:42 rivo volumio[3327]: error: Cannot associate FS Label, not mounting Jun 27 19:29:42 rivo volumio[3327]: info: Asound.conf file unchanged, so no further update is needed Jun 27 19:29:42 rivo volumio[3327]: info: Output device has changed, restarting MPD Jun 27 19:29:42 rivo volumio[3327]: info: Output device has changed, restarting Shairport Sync Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 27 19:29:42 rivo sudo[3794]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 27 19:29:42 rivo sudo[3794]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:42 rivo sudo[3794]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:42 rivo sudo[3796]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 27 19:29:42 rivo sudo[3796]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:42 rivo systemd[1]: Stopping Music Player Daemon... Jun 27 19:29:42 rivo volumio[3327]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 27 19:29:42 rivo volumio[3327]: info: ___________ START PLUGINS ___________ Jun 27 19:29:42 rivo volumio[3327]: info: ControllerMpd::onStart: Initializing MPD Jun 27 19:29:42 rivo volumio[3327]: info: Creating MPD Configuration file Jun 27 19:29:42 rivo sudo[3803]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 27 19:29:42 rivo sudo[3803]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 27 19:29:42 rivo volumio[3327]: info: [1751045382908] CoreMusicLibrary::Adding element Server multimediali Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 27 19:29:42 rivo sudo[3803]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:42 rivo sudo[3805]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 27 19:29:42 rivo sudo[3805]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 27 19:29:42 rivo volumio[3327]: info: Adding METAVOLUMIO REST API Endpoints Jun 27 19:29:42 rivo volumio[3327]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Jun 27 19:29:42 rivo volumio[3327]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Jun 27 19:29:42 rivo volumio[3327]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Jun 27 19:29:42 rivo volumio[3327]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:42 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 27 19:29:42 rivo sudo[3809]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Rivo Jun 27 19:29:42 rivo sudo[3809]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:42 rivo sudo[3809]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:43 rivo volumio[3327]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 27 19:29:43 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:43 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 27 19:29:43 rivo volumio[3327]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 27 19:29:43 rivo volumio[3327]: info: Preparing CD Folders Jun 27 19:29:43 rivo volumio[3327]: info: Adding CD REST API Endpoints Jun 27 19:29:43 rivo volumio[3327]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Jun 27 19:29:43 rivo volumio[3327]: info: Starting UDEV Watcher for CD Jun 27 19:29:43 rivo volumio[3327]: info: Detecting CD presence with UDEV Jun 27 19:29:43 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Jun 27 19:29:43 rivo volumio[3327]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 27 19:29:43 rivo volumio[3327]: info: [1751045383168] CoreMusicLibrary::Adding element Last_100 Jun 27 19:29:43 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 27 19:29:43 rivo volumio[3327]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Jun 27 19:29:43 rivo volumio[3327]: info: QobuzConnect: Starting Qobuz Connect socket and service Jun 27 19:29:43 rivo volumio[3327]: info: Starting RAAT Plugin Jun 27 19:29:43 rivo sudo[3821]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jun 27 19:29:43 rivo sudo[3821]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:43 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Jun 27 19:29:43 rivo volumio[3327]: info: Additional UI Settings Added for plugin music_service/raat Jun 27 19:29:43 rivo volumio[3327]: info: Registering DSP Elements listener and retrieving current ones Jun 27 19:29:43 rivo volumio[3327]: info: Additional DSP elements updated Jun 27 19:29:43 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:43 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:43 rivo volumio[3327]: info: Updating RAAT Signal Path Jun 27 19:29:43 rivo sudo[3821]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:43 rivo volumio[3327]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Jun 27 19:29:43 rivo volumio[3327]: info: Streaming services startup Jun 27 19:29:43 rivo volumio[3327]: info: Starting Streaming Daemon Jun 27 19:29:43 rivo sudo[3825]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jun 27 19:29:43 rivo sudo[3825]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:43 rivo sudo[3827]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 27 19:29:43 rivo sudo[3827]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:43 rivo sudo[3827]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:43 rivo systemd[1]: mpd.service: Succeeded. Jun 27 19:29:43 rivo systemd[1]: Stopped Music Player Daemon. Jun 27 19:29:43 rivo volumio[3327]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 27 19:29:43 rivo volumio[3327]: info: [1751045383403] CoreMusicLibrary::Adding element Webradio Jun 27 19:29:43 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 27 19:29:43 rivo systemd[1]: Starting Music Player Daemon... Jun 27 19:29:43 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 27 19:29:43 rivo systemd[1]: Started Volumio Qobuz Connect Service. Jun 27 19:29:43 rivo volumio[3327]: info: Initializing BBC Radios Jun 27 19:29:43 rivo sudo[3825]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:43 rivo sudo[3836]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 27 19:29:43 rivo sudo[3836]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:43 rivo sudo[3836]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:43 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 27 19:29:43 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 27 19:29:43 rivo volumio[3327]: error: Hi Res Audio Failed Login: Missing Login Data Jun 27 19:29:43 rivo volumio[3327]: info: Adding HIGHRESAUDIO REST API Endpoints Jun 27 19:29:43 rivo volumio[3327]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Jun 27 19:29:43 rivo volumio[3327]: info: Initializing Serial Communication on port /dev/ttyS3 Jun 27 19:29:43 rivo sudo[3837]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 27 19:29:43 rivo sudo[3837]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:43 rivo volumio[3327]: info: Touch Event Listener Process Starting Jun 27 19:29:43 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 0 to 9600 Jun 27 19:29:43 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 9600 to 9600 Jun 27 19:29:43 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 9600 to 115200 Jun 27 19:29:43 rivo sudo[3837]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:43 rivo volumio[3327]: info: Refreshing QOBUZ token Jun 27 19:29:43 rivo sudo[3861]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xinput --test-xi2 --root Jun 27 19:29:43 rivo sudo[3861]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:43 rivo volumio[3327]: info: Adding inputs REST Endpoints Jun 27 19:29:43 rivo volumio[3327]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Jun 27 19:29:43 rivo volumio[3327]: info: Scanning Audio Inputs Jun 27 19:29:43 rivo volumio[3327]: info: Checking against Known Cards name Jun 27 19:29:43 rivo volumio[3327]: info: Checking against Known Cards name Jun 27 19:29:43 rivo volumio[3327]: info: Checking against Known Cards name Jun 27 19:29:43 rivo volumio[3327]: info: Checking against Known Cards name Jun 27 19:29:43 rivo volumio[3327]: info: Checking against Known Cards name Jun 27 19:29:43 rivo volumio[3327]: info: Adding Server instance for streaming Jun 27 19:29:43 rivo sudo[3873]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x25 0x0 Jun 27 19:29:43 rivo sudo[3873]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:43 rivo sudo[3873]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:43 rivo sudo[3876]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x28 0x0 Jun 27 19:29:43 rivo sudo[3876]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:43 rivo sudo[3876]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:43 rivo sudo[3879]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x29 0x1 Jun 27 19:29:43 rivo sudo[3879]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:43 rivo sudo[3879]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:43 rivo sudo[3882]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x33 0x1 Jun 27 19:29:43 rivo sudo[3882]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:43 rivo sudo[3882]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:43 rivo volumio[3327]: info: Apply VIM3L Onboard LEDs Settings Jun 27 19:29:43 rivo volumio[3327]: info: Turning On Onboard LEDs Jun 27 19:29:44 rivo sudo[3886]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/sys_led/trigger Jun 27 19:29:44 rivo sudo[3886]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:44 rivo volumio[3327]: info: Starting CEC Event listener Jun 27 19:29:44 rivo sudo[3886]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:44 rivo volumio[3327]: info: Volumio Calling Home Jun 27 19:29:44 rivo sudo[3890]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/red_red/trigger Jun 27 19:29:44 rivo sudo[3890]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:44 rivo sudo[3890]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:44 rivo volumio[3327]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Jun 27 19:29:44 rivo volumio[3327]: (node:3327) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Jun 27 19:29:44 rivo volumio[3327]: (Use `node --trace-deprecation ...` to show where the warning was created) Jun 27 19:29:44 rivo volumio[3327]: info: Stopping AccessToken refresher cron Jun 27 19:29:44 rivo volumio[3327]: info: AccessToken refresher cron started Jun 27 19:29:44 rivo volumio[3327]: info: Adding TIDAL REST API Endpoints Jun 27 19:29:44 rivo volumio[3327]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Jun 27 19:29:44 rivo volumio[3327]: info: CoreStateMachine::setRepeat null single undefined Jun 27 19:29:44 rivo volumio[3327]: info: CoreStateMachine::pushState Jun 27 19:29:44 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:44 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 27 19:29:44 rivo volumio[3327]: info: CoreCommandRouter::volumioPushState Jun 27 19:29:44 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:29:44 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:44 rivo volumio[3327]: info: CoreStateMachine::setRandom null Jun 27 19:29:44 rivo volumio[3327]: info: CoreStateMachine::pushState Jun 27 19:29:44 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:44 rivo volumio[3327]: info: CoreCommandRouter::volumioPushState Jun 27 19:29:44 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:29:44 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:44 rivo volumio[3327]: info: Mounting Device 01_LIQUID Jun 27 19:29:44 rivo sudo[3900]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sdb2 /mnt/USB/01_LIQUID -o noatime Jun 27 19:29:44 rivo sudo[3900]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:44 rivo mount.exfat[3902]: volume was not unmounted cleanly Jun 27 19:29:44 rivo sudo[3900]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:44 rivo volumio[3327]: WARN: volume was not unmounted cleanly. Jun 27 19:29:44 rivo systemd[1]: systemd-timedated.service: Succeeded. Jun 27 19:29:44 rivo volumio[3327]: info: Serial port opened successfully Jun 27 19:29:44 rivo volumio[3327]: info: Sending serial start messages Jun 27 19:29:44 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:44 rivo volumio[3327]: info: Reporting MCU Network Status: 2 Jun 27 19:29:44 rivo volumio[3327]: info: MP1 GPIO: Signalled system ready via GPIO Jun 27 19:29:45 rivo volumio[3327]: info: Mounting Device 02_LIQUID Jun 27 19:29:45 rivo sudo[3913]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda2 /mnt/USB/02_LIQUID -o noatime Jun 27 19:29:45 rivo sudo[3913]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:45 rivo mpd[3862]: Jun 27 19:29 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 27 19:29:45 rivo mount.exfat[3915]: volume was not unmounted cleanly Jun 27 19:29:45 rivo sudo[3913]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:45 rivo volumio[3327]: WARN: volume was not unmounted cleanly. Jun 27 19:29:45 rivo volumio[3327]: error: Cannot start Volumio Streaming Daemon Jun 27 19:29:45 rivo volumio[3327]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 27 19:29:45 rivo volumio[3327]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 27 19:29:45 rivo volumio[3327]: info: RAAT Albumart path created successfully Jun 27 19:29:45 rivo volumio[3327]: info: Bluetooth name changed to Rivo Jun 27 19:29:45 rivo volumio[3327]: info: MPD Permissions set Jun 27 19:29:45 rivo volumio[3327]: info: MPD Permissions set Jun 27 19:29:45 rivo sudo[3918]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 27 19:29:45 rivo sudo[3918]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:45 rivo systemd[1]: Started UPnP Renderer front-end to MPD. Jun 27 19:29:45 rivo sudo[3918]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:45 rivo volumio[3327]: info: Executing endpoint qc_getconfig Jun 27 19:29:45 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Jun 27 19:29:45 rivo qobuz-connect[3839]: 20250627 19:29:45.896 [3839.3839] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Jun 27 19:29:45 rivo volumio[3327]: info: Volumio called home Jun 27 19:29:45 rivo volumio[3327]: info: Discovery: adding 8b20345d-8480-4e6d-af7a-f9530019a703 Jun 27 19:29:45 rivo volumio[3327]: info: Discovery: Found device Rivo Jun 27 19:29:45 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:29:45 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:45 rivo volumio[3327]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jun 27 19:29:45 rivo volumio[3327]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Jun 27 19:29:45 rivo volumio[3327]: info: QobuzConnect: QOBUZ Connect daemon connected Jun 27 19:29:46 rivo volumio[3327]: info: Upmpdcli Daemon Started Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:46 rivo sudo[3924]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:46 rivo sudo[3924]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:46 rivo qobuz-connect[3839]: 20250627 19:29:46.095 [3839.3839] INFO VolumeManager: [0xabae18f0]: Setting new playback volume: 75 Jun 27 19:29:46 rivo qobuz-connect[3839]: 20250627 19:29:46.095 [3839.3839] INFO VolumeManager: [0xabae18f0]: Setting new mute state: 0 Jun 27 19:29:46 rivo qobuz-connect[3839]: 20250627 19:29:46.095 [3839.3839] INFO QobuzConnect: [0xabae22c0]: Client initialized! Jun 27 19:29:46 rivo qobuz-connect[3839]: 20250627 19:29:46.095 [3839.3839] INFO SampleApp: Starting Avahi advertising, name: Rivo, service name: _qobuz-connect._tcp Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:46 rivo qobuz-connect[3839]: 20250627 19:29:46.142 [3839.3839] INFO LocalConfigManager: [0xabae11d0]: Starting Local Configuration server Jun 27 19:29:46 rivo qobuz-connect[3839]: 20250627 19:29:46.143 [3839.3839] INFO SampleApp: Starting Local configuration server Jun 27 19:29:46 rivo qobuz-connect[3839]: 20250627 19:29:46.143 [3839.3839] INFO SampleApp: Playback volume changed: 75 Jun 27 19:29:46 rivo qobuz-connect[3839]: 20250627 19:29:46.144 [3839.3839] INFO SampleApp: Connected to UNIX socket client 0xabad6ed8 Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jun 27 19:29:46 rivo systemd[1]: Started Volumio Bluetooth Module. Jun 27 19:29:46 rivo sudo[3924]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:46 rivo sudo[3933]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Jun 27 19:29:46 rivo sudo[3933]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:46 rivo volumiobt[3931]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Jun 27 19:29:46 rivo sudo[3933]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setDeviceVolumeOverride Jun 27 19:29:46 rivo volumio[3327]: info: Setting Device Volume Override Jun 27 19:29:46 rivo volumio[3327]: No protocol specified Jun 27 19:29:46 rivo volumio[3327]: xcb_connection_has_error() returned true Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jun 27 19:29:46 rivo volumio[3327]: info: Updating Volume Controller Parameters: Device: 0,2 Name: S/PDIF + AES/EBU Mixer: Audio hdmi-out mute Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jun 27 19:29:46 rivo volumio[3327]: info: Disabling external Volume Control Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:46 rivo volumio[3327]: info: CoreStateMachine::pushState Jun 27 19:29:46 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::volumioPushState Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:29:46 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Jun 27 19:29:46 rivo volumio[3327]: info: Setting Additional System Software info: Hardware Revision: 2.1 Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Jun 27 19:29:46 rivo volumio[3327]: info: Setting HW Firmware info: undefined Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Jun 27 19:29:46 rivo volumio[3327]: info: Setting HW Version info: 2.1 Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Jun 27 19:29:46 rivo volumio[3327]: info: Setting Additional System Software info: Hardware Revision: 2.1, Firmware Version: 0.3.4 Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Jun 27 19:29:46 rivo volumio[3327]: info: Setting HW Firmware info: 0.3.4 Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Jun 27 19:29:46 rivo volumio[3327]: info: Setting HW Version info: 2.1 Jun 27 19:29:46 rivo volumio[3327]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Jun 27 19:29:46 rivo volumio[3327]: info: MCU Signalled Headphone Mode Disabled Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jun 27 19:29:46 rivo volumio[3327]: info: Reporting Headphone State: false Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 27 19:29:46 rivo volumio[3327]: info: Updating RAAT Signal Path Jun 27 19:29:46 rivo volumio[3327]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Jun 27 19:29:46 rivo volumio[3327]: info: MCU Signalled Sleep Mode Disabled Jun 27 19:29:46 rivo volumio[3327]: info: Enabling Advanced system settings configuration Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , addAdditionalUISections Jun 27 19:29:46 rivo volumio[3327]: info: Additional UI Settings Added for plugin music_service/inputs Jun 27 19:29:46 rivo volumio[3327]: info: MCU Signalled Auto Boot Mode On Power Disabled Jun 27 19:29:46 rivo volumio[3327]: info: CoreStateMachine::pushState Jun 27 19:29:46 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::volumioPushState Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:29:46 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:46 rivo sudo[3947]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force on Jun 27 19:29:46 rivo sudo[3947]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:46 rivo kernel: fb: osd[0] enable: 1 (Xorg) Jun 27 19:29:46 rivo sudo[3947]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:46 rivo volumio[3327]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jun 27 19:29:46 rivo volumio[3327]: error: Serial API: Failed to decode command: MAXVOL, message: 100 Jun 27 19:29:46 rivo volumio[3327]: info: Access Token successfully retrieved Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 27 19:29:46 rivo volumio[3327]: info: [1751045386702] CoreMusicLibrary::Adding element QOBUZ Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 27 19:29:46 rivo volumio[3327]: Cannot find translation for source QOBUZ Jun 27 19:29:46 rivo volumio[3327]: info: Stopping AccessToken refresher cron for QOBUZ Jun 27 19:29:46 rivo volumio[3327]: info: AccessToken refresher cron started for QOBUZ Jun 27 19:29:46 rivo volumio[3327]: info: Adding QOBUZ REST API Endpoints Jun 27 19:29:46 rivo volumio[3327]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Jun 27 19:29:46 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:29:46 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:46 rivo volumio[3327]: info: TidalConnect service stoped! Jun 27 19:29:46 rivo volumio[3327]: info: Volumio BT Module successfully started Jun 27 19:29:46 rivo sudo[3950]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms 0 0 0 Jun 27 19:29:46 rivo sudo[3950]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:46 rivo sudo[3950]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:47 rivo volumio[3327]: info: Starting Shairport Sync Jun 27 19:29:47 rivo volumio[3327]: info: Starting Shairport Sync Jun 27 19:29:47 rivo volumio[3327]: info: Starting Shairport Sync Jun 27 19:29:47 rivo sudo[3959]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 27 19:29:47 rivo sudo[3959]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:47 rivo sudo[3961]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 27 19:29:47 rivo sudo[3961]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:47 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 27 19:29:47 rivo systemd[1]: shairport-sync.service: Succeeded. Jun 27 19:29:47 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 27 19:29:47 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 27 19:29:47 rivo sudo[3964]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 27 19:29:47 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:29:47 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:47 rivo sudo[3964]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:47 rivo sudo[3959]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:47 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 27 19:29:47 rivo volumio[3327]: info: Adding Inputs via Serial API Jun 27 19:29:47 rivo volumio[3327]: info: CoreStateMachine::pushState Jun 27 19:29:47 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:47 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 27 19:29:47 rivo volumio[3327]: info: CoreCommandRouter::volumioPushState Jun 27 19:29:47 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:29:47 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:47 rivo sudo[3970]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Jun 27 19:29:47 rivo sudo[3970]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:47 rivo volumio[3327]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 27 19:29:47 rivo volumio[3327]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 27 19:29:47 rivo volumio[3327]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 27 19:29:47 rivo volumio[3327]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 27 19:29:47 rivo volumiobt[3931]: pulseaudio: no process found Jun 27 19:29:47 rivo sudo[3970]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:47 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:29:47 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:47 rivo volumio[3327]: info: Shairport-Sync Started Jun 27 19:29:47 rivo volumio[3327]: Error adding Membership: Error: addMembership EINVAL Jun 27 19:29:47 rivo dbus-daemon[2866]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.20' (uid=1000 pid=3977 comm="/usr/bin/pulseaudio --high-priority=true " label="kernel") Jun 27 19:29:47 rivo systemd[1]: Starting RealtimeKit Scheduling Policy Service... Jun 27 19:29:47 rivo volumio[3327]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Jun 27 19:29:47 rivo volumio[3327]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Jun 27 19:29:47 rivo kernel: IPVS: Creating netns size=1928 id=3 Jun 27 19:29:47 rivo dbus-daemon[2866]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Jun 27 19:29:47 rivo systemd[1]: Started RealtimeKit Scheduling Policy Service. Jun 27 19:29:47 rivo rtkit-daemon[3978]: Successfully called chroot. Jun 27 19:29:47 rivo rtkit-daemon[3978]: Successfully dropped privileges. Jun 27 19:29:47 rivo rtkit-daemon[3978]: Successfully limited resources. Jun 27 19:29:47 rivo rtkit-daemon[3978]: Running. Jun 27 19:29:47 rivo dbus-daemon[2866]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.21' (uid=0 pid=3978 comm="/usr/lib/rtkit/rtkit-daemon " label="kernel") Jun 27 19:29:47 rivo rtkit-daemon[3978]: Watchdog thread running. Jun 27 19:29:47 rivo rtkit-daemon[3978]: Canary thread running. Jun 27 19:29:47 rivo sudo[3980]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Jun 27 19:29:47 rivo sudo[3980]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:47 rivo systemd[1]: Starting Authorization Manager... Jun 27 19:29:47 rivo volumio[3327]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 27 19:29:47 rivo volumio[3327]: info: CoreCommandRouter::servicePushState Jun 27 19:29:47 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:47 rivo volumio[3327]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received inputs Jun 27 19:29:47 rivo volumio[3327]: info: CoreCommandRouter::volumiosetSourceActiveno-source Jun 27 19:29:47 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 27 19:29:47 rivo volumio[3327]: Cannot find translation for source QOBUZ Jun 27 19:29:47 rivo volumio[3327]: info: MCU Signalled Playback Inactive Jun 27 19:29:47 rivo systemd[1]: Started Volumio Tidal Connect Service. Jun 27 19:29:47 rivo volumio[3327]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 27 19:29:47 rivo sudo[3980]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:47 rivo polkitd[3984]: started daemon version 0.105 using authority implementation `local' version `0.105' Jun 27 19:29:47 rivo volumio[3327]: info: Turning Off Onboard LEDs Jun 27 19:29:47 rivo dbus-daemon[2866]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Jun 27 19:29:47 rivo systemd[1]: Started Authorization Manager. Jun 27 19:29:47 rivo sudo[3995]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/sys_led/trigger Jun 27 19:29:47 rivo sudo[3995]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:47 rivo sudo[3995]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:48 rivo sudo[3998]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/red_red/trigger Jun 27 19:29:48 rivo sudo[3998]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:29:48 rivo sudo[3998]: pam_unix(sudo:session): session closed for user root Jun 27 19:29:48 rivo volumio[3327]: info: Onboard LEDs initialized Jun 27 19:29:48 rivo volumio[3327]: info: Executing endpoint tc_getconfig Jun 27 19:29:48 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Jun 27 19:29:48 rivo vtcs[3987]: STARTING TidalConnect services, version: 1.5.1-beta1 Jun 27 19:29:48 rivo vtcs[3987]: STARTED TidalConnect services. Jun 27 19:29:48 rivo volumio[3327]: info: Executing endpoint tc_connect Jun 27 19:29:48 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Jun 27 19:29:48 rivo volumio[3327]: info: Connecting to TidalConnect Jun 27 19:29:48 rivo volumio[3327]: info: CoreCommandRouter::servicePushState Jun 27 19:29:48 rivo volumio[3327]: info: CoreStateMachine::pushState Jun 27 19:29:48 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:48 rivo volumio[3327]: info: CoreCommandRouter::volumioPushState Jun 27 19:29:48 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:29:48 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:48 rivo pulseaudio[3977]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Jun 27 19:29:48 rivo pulseaudio[3977]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Jun 27 19:29:48 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:48 rivo volumio[3327]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect Jun 27 19:29:48 rivo volumio[3327]: info: CoreCommandRouter::servicePushState Jun 27 19:29:48 rivo volumio[3327]: info: CoreStateMachine::pushState Jun 27 19:29:48 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:48 rivo volumio[3327]: info: CoreCommandRouter::volumioPushState Jun 27 19:29:48 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:29:48 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:48 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:48 rivo volumio[3327]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect Jun 27 19:29:48 rivo bluetoothd[3235]: Endpoint registered: sender=:1.41 path=/MediaEndpoint/A2DPSource Jun 27 19:29:48 rivo volumiobt[3931]: Applying permissions Jun 27 19:29:48 rivo volumiobt[3931]: Setting BT discoverable and pairable Jun 27 19:29:48 rivo bluetoothd[3235]: Endpoint registered: sender=:1.41 path=/MediaEndpoint/A2DPSink Jun 27 19:29:48 rivo pulseaudio[3977]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files Jun 27 19:29:48 rivo volumiobt[3931]: Agent registered Jun 27 19:29:48 rivo volumiobt[3931]: [bluetooth]# -e power on Jun 27 19:29:48 rivo volumiobt[3931]: Invalid command in menu main: -e Jun 27 19:29:48 rivo volumiobt[3931]: Jun 27 19:29:48 rivo volumiobt[3931]: Use "help" for a list of available commands in a menu. Jun 27 19:29:48 rivo volumiobt[3931]: Use "menu " if you want to enter any submenu. Jun 27 19:29:48 rivo volumiobt[3931]: Use "back" if you want to return to menu main. Jun 27 19:29:48 rivo volumiobt[3931]: [bluetooth]# agent on Jun 27 19:29:48 rivo volumiobt[3931]: Agent is already registered Jun 27 19:29:48 rivo volumiobt[3931]: [bluetooth]# discoverable on Jun 27 19:29:48 rivo volumiobt[3931]: [bluetooth]# pairable on Jun 27 19:29:48 rivo volumiobt[3931]: [bluetooth]# agent NoInputNoOutput Jun 27 19:29:48 rivo volumiobt[3931]: Agent is already registered Jun 27 19:29:48 rivo volumiobt[3931]: [bluetooth]# default-agent Jun 27 19:29:48 rivo volumiobt[3931]: [bluetooth]# quit Jun 27 19:29:48 rivo volumiobt[3931]: [59B blob data] Jun 27 19:29:49 rivo volumio[3327]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 3 Jun 27 19:29:49 rivo volumio-remote-updater[2853]: [2025-06-27 19:29:49] [connect] Successful connection Jun 27 19:29:49 rivo volumio-remote-updater[2853]: [2025-06-27 19:29:49] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1751045389 101 Jun 27 19:29:49 rivo volumio[3327]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 4 Jun 27 19:29:50 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 27 19:29:50 rivo volumio[3327]: info: TidalConnect service started! Jun 27 19:29:51 rivo volumio[3327]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 5 Jun 27 19:29:52 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 27 19:29:53 rivo volumio[3327]: info: Checking for updated MCU Firmware Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 27 19:29:54 rivo volumio[3327]: info: Firware on device is on latest version, no need to update Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::volumioGetVisibleSources Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:29:54 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 27 19:29:54 rivo volumio[3327]: info: Received Get System Info Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 27 19:29:54 rivo volumio[3327]: info: Discovery: Getting this device information Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:29:54 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:29:54 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:54 rivo volumio[3327]: info: Listing playlists Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:29:54 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 27 19:29:54 rivo volumio[3327]: info: Received Get System Info Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 27 19:29:54 rivo volumio[3327]: info: Discovery: Getting this device information Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:29:54 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:54 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 27 19:29:56 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 27 19:29:56 rivo volumio[3327]: info: Executing endpoint metavolumio Jun 27 19:29:56 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 27 19:29:56 rivo volumio[3327]: info: Executing endpoint metavolumio Jun 27 19:29:56 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 27 19:29:56 rivo volumio[3327]: info: Executing endpoint metavolumio Jun 27 19:29:56 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 27 19:29:58 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 27 19:29:58 rivo volumio[3327]: info: Received Get System Info Jun 27 19:29:58 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 27 19:29:58 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 27 19:29:58 rivo volumio[3327]: info: Discovery: Getting this device information Jun 27 19:29:58 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:29:58 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:29:58 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 27 19:29:59 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jun 27 19:30:00 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 27 19:30:00 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 27 19:30:00 rivo volumio[3327]: info: Discovery: Getting this device information Jun 27 19:30:00 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:30:00 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:30:00 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 27 19:30:00 rivo volumio[3327]: verbose: New Socket.io Connection to 192.168.0.36:3000 from 192.168.0.16 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Jun 27 19:30:00 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:30:00 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:30:00 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 27 19:30:00 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 27 19:30:01 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 27 19:30:02 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:30:02 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:30:02 rivo sudo[4109]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 27 19:30:02 rivo sudo[4109]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:30:02 rivo sudo[4109]: pam_unix(sudo:session): session closed for user root Jun 27 19:30:02 rivo sudo[4111]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 27 19:30:02 rivo sudo[4111]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:30:02 rivo sudo[4111]: pam_unix(sudo:session): session closed for user root Jun 27 19:30:02 rivo volumio[3327]: verbose: New Socket.io Connection to 192.168.0.36 from 192.168.0.16 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_5 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 7 Jun 27 19:30:02 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 27 19:30:02 rivo volumio[3327]: info: CoreCommandRouter::volumioGetVisibleSources Jun 27 19:30:02 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 27 19:30:02 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:30:02 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:30:02 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 27 19:30:02 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 27 19:30:02 rivo volumio[3327]: info: Received Get System Info Jun 27 19:30:02 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 27 19:30:02 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 27 19:30:02 rivo volumio[3327]: info: Discovery: Getting this device information Jun 27 19:30:02 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:30:02 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:30:02 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 27 19:30:03 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:30:03 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:30:03 rivo volumio[3327]: info: Listing playlists Jun 27 19:30:03 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 27 19:30:03 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 27 19:30:03 rivo sudo[4117]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 27 19:30:03 rivo sudo[4117]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:30:03 rivo sudo[4117]: pam_unix(sudo:session): session closed for user root Jun 27 19:30:03 rivo sudo[4119]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 27 19:30:03 rivo sudo[4119]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:30:03 rivo sudo[4119]: pam_unix(sudo:session): session closed for user root Jun 27 19:30:03 rivo volumio[3327]: verbose: New Socket.io Connection to 192.168.0.36 from 192.168.0.16 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_5 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 7 Jun 27 19:30:03 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 27 19:30:03 rivo volumio[3327]: info: CoreCommandRouter::volumioGetVisibleSources Jun 27 19:30:03 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 27 19:30:03 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:30:03 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:30:03 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 27 19:30:03 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 27 19:30:03 rivo volumio[3327]: info: Received Get System Info Jun 27 19:30:03 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 27 19:30:03 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 27 19:30:03 rivo volumio[3327]: info: Discovery: Getting this device information Jun 27 19:30:03 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:30:03 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:30:03 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 27 19:30:03 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:30:03 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:30:03 rivo volumio[3327]: info: Listing playlists Jun 27 19:30:03 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 27 19:30:03 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 27 19:30:04 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 27 19:30:04 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 27 19:30:04 rivo volumio[3327]: info: Discovery: Getting this device information Jun 27 19:30:04 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:30:04 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:30:04 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 27 19:30:05 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 27 19:30:05 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 27 19:30:05 rivo volumio[3327]: info: Received Get System Info Jun 27 19:30:05 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 27 19:30:05 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 27 19:30:05 rivo volumio[3327]: info: Discovery: Getting this device information Jun 27 19:30:05 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:30:05 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:30:05 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 27 19:30:06 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jun 27 19:30:06 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 27 19:30:06 rivo volumio[3327]: info: Received Get System Info Jun 27 19:30:06 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 27 19:30:06 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 27 19:30:06 rivo volumio[3327]: info: Discovery: Getting this device information Jun 27 19:30:06 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:30:06 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:30:06 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 27 19:30:06 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jun 27 19:30:07 rivo mpd_monitor.sh[2874]: MPD Monitor Service: MPD Appears to be inactive, restarting Jun 27 19:30:07 rivo volumio[3327]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 27 19:30:07 rivo volumio[3327]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 27 19:30:07 rivo systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jun 27 19:30:07 rivo systemd[1]: mpd.service: Succeeded. Jun 27 19:30:07 rivo systemd[1]: Stopped Music Player Daemon. Jun 27 19:30:07 rivo volumio[3327]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 27 19:30:07 rivo systemd[1]: Starting Music Player Daemon... Jun 27 19:30:07 rivo volumio[3327]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 27 19:30:07 rivo sudo[4126]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 27 19:30:07 rivo sudo[4126]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 19:30:07 rivo sudo[4126]: pam_unix(sudo:session): session closed for user root Jun 27 19:30:08 rivo volumio[3327]: info: CoreCommandRouter::volumioPlay Jun 27 19:30:08 rivo volumio[3327]: info: CoreStateMachine::play index undefined Jun 27 19:30:08 rivo volumio[3327]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 27 19:30:08 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:30:08 rivo volumio[3327]: info: CoreStateMachine::startPlaybackTimer Jun 27 19:30:08 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:30:08 rivo volumio[3327]: verbose: ControllerMpd::clearAddPlayTracks USB/02_LIQUID/Pink Floyd Pink Floyd at Pompeii - MCMLXXII FLAC (24bit-96kHz)/CD 01/01 - Pompeii Intro (Live at Pompeii.flac Jun 27 19:30:08 rivo volumio[3327]: verbose: ControllerMpd::sendMpdCommand stop Jun 27 19:30:09 rivo mpd[4136]: Jun 27 19:30 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 27 19:30:09 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 27 19:30:09 rivo volumio[3327]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jun 27 19:30:09 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jun 27 19:30:09 rivo volumio[3327]: info: Received Get System Version Jun 27 19:30:09 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 27 19:30:09 rivo volumio[3327]: info: Received Get System Info Jun 27 19:30:09 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 27 19:30:09 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 27 19:30:09 rivo volumio[3327]: info: Discovery: Getting this device information Jun 27 19:30:09 rivo volumio[3327]: info: CoreCommandRouter::volumioGetState Jun 27 19:30:09 rivo volumio[3327]: info: CorePlayQueue::getTrack 0 Jun 27 19:30:09 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 27 19:30:13 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 27 19:30:14 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 27 19:30:14 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 27 19:30:14 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 27 19:30:14 rivo volumio[3327]: error: Plugin music_service mpd failed to complete 'onStart' in a timely fashion Jun 27 19:30:14 rivo volumio[3327]: info: ------------------------------------------- Jun 27 19:30:14 rivo volumio[3327]: info: ----- MyVolumio plugins startup ---- Jun 27 19:30:14 rivo volumio[3327]: info: ------------------------------------------- Jun 27 19:30:14 rivo volumio[3327]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 27 19:30:15 rivo volumio[3327]: info: CoreCommandRouter::volumioGetQueue Jun 27 19:30:15 rivo volumio[3327]: info: CoreStateMachine::getQueue Jun 27 19:30:15 rivo volumio[3327]: info: CorePlayQueue::getQueue Jun 27 19:30:17 rivo dbus-daemon[2866]: [system] Connection has not authenticated soon enough, closing it (auth_timeout=30000ms, elapsed: 30010ms) Jun 27 19:30:19 rivo volumio[3327]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jun 27 19:30:19 rivo volumio[3327]: info: CURURI: albums:// Jun 27 19:30:19 rivo volumio[3327]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 27 19:30:19 rivo volumio[3327]: TypeError: Cannot read property 'sendCommand' of undefined Jun 27 19:30:19 rivo volumio[3327]: at /volumio/app/plugins/music_service/mpd/index.js:2987:22 Jun 27 19:30:19 rivo volumio[3327]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Jun 27 19:30:19 rivo volumio[3327]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 27 19:30:19 rivo sudo[4165]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-27 19:29 Jun 27 19:30:20 rivo sudo[4165]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 06:01:16 PM CEST" VOLUMIO_VERSION="3.816" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="5a6f819282ea0c6f84bf87456dce95cb"