-- Logs begin at Sun 2025-12-28 10:55:48 CET, end at Sun 2025-12-28 10:57:08 CET. -- Dec 28 10:56:00 rivo systemd[1]: systemd-rfkill.service: Succeeded. Dec 28 10:56:00 rivo wireless.js[2824]: trying... Dec 28 10:56:00 rivo sudo[3176]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:00 rivo sudo[3176]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:00 rivo sudo[3176]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:01 rivo wireless.js[2824]: trying... Dec 28 10:56:01 rivo sudo[3179]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:01 rivo sudo[3179]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:01 rivo sudo[3179]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:02 rivo wireless.js[2824]: trying... Dec 28 10:56:02 rivo sudo[3182]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:02 rivo sudo[3182]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:02 rivo sudo[3182]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:02 rivo volumio-time-update[2843]: volumio-time-update-util: Fetching time from Volumio... Dec 28 10:56:02 rivo volumio-time-update[2843]: volumio-time-update-util: Date not found in response Dec 28 10:56:02 rivo volumio-time-update[2843]: volumio-time-update-util: Retrying in 5 seconds... Dec 28 10:56:03 rivo wireless.js[2824]: trying... Dec 28 10:56:03 rivo sudo[3190]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:03 rivo sudo[3190]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:03 rivo sudo[3190]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:03 rivo kernel: meson_uart ffd24000.serial: ttyS1 use xtal(24M) 24000000 change 115200 to 2000000 Dec 28 10:56:03 rivo systemd[1]: Starting Load/Save RF Kill Switch Status... Dec 28 10:56:03 rivo systemd[1]: Started Load/Save RF Kill Switch Status. Dec 28 10:56:03 rivo systemd[1]: Starting Bluetooth service... Dec 28 10:56:03 rivo bluetoothd[3198]: Bluetooth daemon 5.83 Dec 28 10:56:03 rivo bluetoothd[3198]: src/main.c:check_options() Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Dec 28 10:56:03 rivo systemd[1]: Started Bluetooth service. Dec 28 10:56:03 rivo systemd[1]: Reached target Bluetooth. Dec 28 10:56:03 rivo bluetoothd[3198]: Starting SDP server Dec 28 10:56:03 rivo bluetoothd[3198]: Excluding (cli) hostname Dec 28 10:56:03 rivo bluetoothd[3198]: Excluding (cli) scanparam Dec 28 10:56:03 rivo bluetoothd[3198]: Excluding (cli) battery Dec 28 10:56:03 rivo bluetoothd[3198]: Bluetooth management interface 1.14 initialized Dec 28 10:56:03 rivo bluetoothd[3198]: src/adapter.c:reset_adv_monitors_complete() Failed to reset Adv Monitors: Unknown Command (0x01) Dec 28 10:56:03 rivo bluetoothd[3198]: Battery Provider Manager created Dec 28 10:56:04 rivo wireless.js[2824]: trying... Dec 28 10:56:04 rivo sudo[3209]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:04 rivo sudo[3209]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:04 rivo sudo[3209]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:05 rivo wireless.js[2824]: trying... Dec 28 10:56:05 rivo sudo[3212]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:05 rivo sudo[3212]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:05 rivo sudo[3212]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:06 rivo wireless.js[2824]: trying... Dec 28 10:56:06 rivo sudo[3215]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:06 rivo sudo[3215]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:06 rivo sudo[3215]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:07 rivo volumio-remote-updater[2830]: [2025-12-28 10:56:07] [info] asio async_connect error: system:111 (Connection refused) Dec 28 10:56:07 rivo volumio-remote-updater[2830]: [2025-12-28 10:56:07] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 28 10:56:07 rivo volumio-remote-updater[2830]: [2025-12-28 10:56:07] [error] handle_connect error: Underlying Transport Error Dec 28 10:56:07 rivo wireless.js[2824]: trying... Dec 28 10:56:07 rivo sudo[3218]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:07 rivo sudo[3218]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:07 rivo sudo[3218]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:07 rivo volumio-time-update[2843]: volumio-time-update-util: Fetching time from Volumio... Dec 28 10:56:07 rivo volumio-time-update[2843]: volumio-time-update-util: Date not found in response Dec 28 10:56:07 rivo volumio-time-update[2843]: volumio-time-update-util: Retrying in 5 seconds... Dec 28 10:56:08 rivo wireless.js[2824]: trying... Dec 28 10:56:08 rivo sudo[3226]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:08 rivo sudo[3226]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:08 rivo sudo[3226]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:08 rivo systemd[1]: systemd-rfkill.service: Succeeded. Dec 28 10:56:09 rivo wireless.js[2824]: trying... Dec 28 10:56:09 rivo sudo[3229]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:09 rivo sudo[3229]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:09 rivo sudo[3229]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:10 rivo wireless.js[2824]: trying... Dec 28 10:56:10 rivo sudo[3232]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:10 rivo sudo[3232]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:10 rivo sudo[3232]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:11 rivo wireless.js[2824]: trying... Dec 28 10:56:11 rivo sudo[3235]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:11 rivo sudo[3235]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:11 rivo sudo[3235]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:12 rivo wireless.js[2824]: trying... Dec 28 10:56:12 rivo sudo[3238]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:12 rivo sudo[3238]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:12 rivo sudo[3238]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:12 rivo volumio-time-update[2843]: volumio-time-update-util: Fetching time from Volumio... Dec 28 10:56:12 rivo volumio-time-update[2843]: volumio-time-update-util: Date not found in response Dec 28 10:56:12 rivo volumio-time-update[2843]: volumio-time-update-util: Retrying in 5 seconds... Dec 28 10:56:13 rivo wireless.js[2824]: trying... Dec 28 10:56:13 rivo sudo[3246]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:13 rivo sudo[3246]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:13 rivo sudo[3246]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:14 rivo wireless.js[2824]: trying... Dec 28 10:56:14 rivo sudo[3249]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:14 rivo sudo[3249]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:14 rivo sudo[3249]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:15 rivo wireless.js[2824]: trying... Dec 28 10:56:15 rivo sudo[3252]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:15 rivo sudo[3252]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:15 rivo sudo[3252]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:16 rivo wireless.js[2824]: trying... Dec 28 10:56:16 rivo sudo[3255]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:16 rivo sudo[3255]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:16 rivo sudo[3255]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:17 rivo volumio-remote-updater[2830]: [2025-12-28 10:56:17] [info] asio async_connect error: system:111 (Connection refused) Dec 28 10:56:17 rivo volumio-remote-updater[2830]: [2025-12-28 10:56:17] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 28 10:56:17 rivo volumio-remote-updater[2830]: [2025-12-28 10:56:17] [error] handle_connect error: Underlying Transport Error Dec 28 10:56:17 rivo wireless.js[2824]: trying... Dec 28 10:56:17 rivo sudo[3258]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:17 rivo sudo[3258]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:17 rivo sudo[3258]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:17 rivo volumio-time-update[2843]: volumio-time-update-util: Fetching time from Volumio... Dec 28 10:56:17 rivo volumio-time-update[2843]: volumio-time-update-util: Date not found in response Dec 28 10:56:17 rivo volumio-time-update[2843]: volumio-time-update-util: Retrying in 5 seconds... Dec 28 10:56:18 rivo wireless.js[2824]: trying... Dec 28 10:56:18 rivo sudo[3266]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 28 10:56:18 rivo sudo[3266]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:18 rivo sudo[3266]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:19 rivo wireless.js[2824]: Overtime, starting plan B Dec 28 10:56:19 rivo systemd[1]: Started Wireless Services. Dec 28 10:56:19 rivo systemd[1]: Started Volumio Backend Module. Dec 28 10:56:19 rivo systemd[1]: Started Start Volumio Kiosk. Dec 28 10:56:19 rivo systemd[1]: Started Volumio Cpu Tweaker. Dec 28 10:56:19 rivo startkiosk.sh[3272]: Starting Volumio Kiosk with arguments for cursor display Dec 28 10:56:19 rivo volumio-cpu-tweak[3277]: Setting RT Priority for mpd Dec 28 10:56:19 rivo volumio-cpu-tweak[3277]: chrt: cannot obtain the list of tasks: No such file or directory Dec 28 10:56:19 rivo volumio-cpu-tweak[3277]: Setting MPD Affinity Dec 28 10:56:19 rivo volumio-cpu-tweak[3277]: pid 3's current affinity mask: 1 Dec 28 10:56:19 rivo volumio-cpu-tweak[3277]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Dec 28 10:56:19 rivo volumio-cpu-tweak[3277]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Dec 28 10:56:19 rivo systemd[1]: volumio_cpu_tweak.service: Succeeded. Dec 28 10:56:20 rivo startkiosk.sh[3272]: X.Org X Server 1.20.4 Dec 28 10:56:20 rivo startkiosk.sh[3272]: X Protocol Version 11, Revision 0 Dec 28 10:56:20 rivo startkiosk.sh[3272]: Build Operating System: Linux 4.19.0-18-armmp-lpae armv7l Debian Dec 28 10:56:20 rivo startkiosk.sh[3272]: Current Operating System: Linux rivo 4.9.241 #4 SMP PREEMPT Wed Jun 4 18:07:40 CEST 2025 aarch64 Dec 28 10:56:20 rivo startkiosk.sh[3272]: Kernel command line: imgpart=UUID=ef4af274-704b-4844-b428-0a2b2adcd4f3 imgfile=/volumio_current.sqsh bootpart=UUID=005D-DC98 datapart=UUID=976cc8d3-1eaa-451c-b611-88193927abd9 uuidconfig=env.system.txt hwdevice=VIM3L 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:16:16:01 fan=auto hwver=VIM3.V12 coherent_pool=2M quiet loglevel=0 splash plymouth.ignore-serial-consoles initramfs.clear splash bootdelay=7 Dec 28 10:56:20 rivo startkiosk.sh[3272]: Build Date: 18 December 2021 09:05:36AM Dec 28 10:56:20 rivo startkiosk.sh[3272]: xorg-server 2:1.20.4-1+deb10u4 (https://www.debian.org/support) Dec 28 10:56:20 rivo startkiosk.sh[3272]: Current version of pixman: 0.36.0 Dec 28 10:56:20 rivo startkiosk.sh[3272]: Before reporting problems, check http://wiki.x.org Dec 28 10:56:20 rivo startkiosk.sh[3272]: to make sure that you have the latest version. Dec 28 10:56:20 rivo startkiosk.sh[3272]: Markers: (--) probed, (**) from config file, (==) default setting, Dec 28 10:56:20 rivo startkiosk.sh[3272]: (++) from command line, (!!) notice, (II) informational, Dec 28 10:56:20 rivo startkiosk.sh[3272]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Dec 28 10:56:20 rivo startkiosk.sh[3272]: (==) Log file: "/var/log/Xorg.0.log", Time: Sun Dec 28 10:56:20 2025 Dec 28 10:56:20 rivo startkiosk.sh[3272]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Dec 28 10:56:20 rivo kernel: fb: osd[0] canvas.idx =0x40 Dec 28 10:56:20 rivo kernel: fb: osd[0] canvas.addr=0x70000000 Dec 28 10:56:20 rivo kernel: fb: osd[0] canvas.width=7680 Dec 28 10:56:20 rivo kernel: fb: osd[0] canvas.height=1080 Dec 28 10:56:20 rivo kernel: fb: osd[0] frame.width=1920 Dec 28 10:56:20 rivo kernel: fb: osd[0] frame.height=1080 Dec 28 10:56:20 rivo kernel: fb: osd[0] out_addr_id =0x1 Dec 28 10:56:20 rivo kernel: fb: osd[0] enable: 0 (Xorg) Dec 28 10:56:21 rivo kernel: fb: osd[0] enable: 1 (Xorg) Dec 28 10:56:21 rivo systemd[1]: systemd-fsckd.service: Succeeded. Dec 28 10:56:22 rivo kernel: fb: osd[0] enable: 1 (Xorg) Dec 28 10:56:22 rivo volumio[3271]: info: ------------------------------------------- Dec 28 10:56:22 rivo volumio[3271]: info: ----- Volumio3 ---- Dec 28 10:56:22 rivo volumio[3271]: info: ------------------------------------------- Dec 28 10:56:22 rivo volumio[3271]: info: ----- System startup ---- Dec 28 10:56:22 rivo volumio[3271]: info: ------------------------------------------- Dec 28 10:56:22 rivo volumio-time-update[2843]: volumio-time-update-util: Fetching time from Volumio... Dec 28 10:56:22 rivo volumio-time-update[2843]: volumio-time-update-util: Date not found in response Dec 28 10:56:22 rivo volumio-time-update[2843]: volumio-time-update-util: Retrying in 5 seconds... Dec 28 10:56:23 rivo sh[2756]: timed out Dec 28 10:56:23 rivo sh[2756]: dhcpcd exited Dec 28 10:56:23 rivo dhcpcd[2807]: timed out Dec 28 10:56:23 rivo sh[2756]: ifup: failed to bring up eth0 Dec 28 10:56:23 rivo dhcpcd[2807]: dhcpcd exited Dec 28 10:56:23 rivo systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Dec 28 10:56:23 rivo systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Dec 28 10:56:23 rivo dhcpcd[2841]: timed out Dec 28 10:56:23 rivo dhcpcd[2841]: timed out Dec 28 10:56:24 rivo dhcpcd[2841]: forked to background, child pid 3388 Dec 28 10:56:24 rivo systemd[1]: Started DHCP Client Daemon. Dec 28 10:56:23 rivo dhcpcd[2841]: forked to background, child pid 3388 Dec 28 10:56:24 rivo volumio[3271]: info: MYVOLUMIO Environment detected Dec 28 10:56:24 rivo volumio[3271]: info: Plugin folders cleanup Dec 28 10:56:24 rivo volumio[3271]: info: Scanning into folder /volumio/app/plugins/ Dec 28 10:56:24 rivo volumio[3271]: info: Scanning category audio_interface Dec 28 10:56:24 rivo volumio[3271]: info: Scanning category miscellanea Dec 28 10:56:24 rivo volumio[3271]: info: Scanning category music_service Dec 28 10:56:24 rivo volumio[3271]: info: Scanning category plugins.json Dec 28 10:56:24 rivo volumio[3271]: info: Scanning category system_controller Dec 28 10:56:24 rivo volumio[3271]: info: Scanning category user_interface Dec 28 10:56:24 rivo volumio[3271]: info: Scanning into folder /data/plugins/ Dec 28 10:56:24 rivo volumio[3271]: info: Scanning category music_service Dec 28 10:56:24 rivo volumio[3271]: info: Plugin folders cleanup completed Dec 28 10:56:24 rivo volumio[3271]: info: ------------------------------------------- Dec 28 10:56:24 rivo volumio[3271]: info: ----- Core plugins startup ---- Dec 28 10:56:24 rivo volumio[3271]: info: ------------------------------------------- Dec 28 10:56:24 rivo volumio[3271]: info: Loading plugins from folder /volumio/app/plugins/ Dec 28 10:56:24 rivo volumio[3271]: info: Adding plugin bluetooth to MyMusic Plugins Dec 28 10:56:24 rivo volumio[3271]: info: Adding plugin multiroom to MyMusic Plugins Dec 28 10:56:24 rivo volumio[3271]: info: Adding plugin upnp to MyMusic Plugins Dec 28 10:56:24 rivo volumio[3271]: info: Adding plugin metavolumio to MyMusic Plugins Dec 28 10:56:24 rivo volumio[3271]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 28 10:56:24 rivo volumio[3271]: info: Adding plugin cd_controller to MyMusic Plugins Dec 28 10:56:24 rivo volumio[3271]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 28 10:56:24 rivo volumio[3271]: info: Adding plugin raat to MyMusic Plugins Dec 28 10:56:24 rivo volumio[3271]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 28 10:56:24 rivo volumio[3271]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 28 10:56:24 rivo volumio[3271]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 28 10:56:24 rivo volumio[3271]: info: Loading plugins from folder /data/plugins/ Dec 28 10:56:24 rivo volumio[3271]: info: Loading plugin "system"... Dec 28 10:56:24 rivo volumio[3271]: info: Loading plugin "appearance"... Dec 28 10:56:26 rivo volumio[3271]: info: Loading plugin "network"... Dec 28 10:56:26 rivo volumio[3271]: info: Refreshing Cached IP Addresses Dec 28 10:56:26 rivo sudo[3395]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 28 10:56:26 rivo sudo[3395]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:26 rivo sudo[3397]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 28 10:56:26 rivo sudo[3397]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:26 rivo sudo[3395]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:26 rivo volumio[3271]: info: Loading plugin "services"... Dec 28 10:56:26 rivo volumio[3271]: info: Loading plugin "volumio5onboarding"... Dec 28 10:56:26 rivo sudo[3397]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:26 rivo sudo[3409]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 28 10:56:26 rivo sudo[3409]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:26 rivo kernel: wl_escan_set_scan: ioctl_ver=2 Dec 28 10:56:26 rivo volumio[3271]: info: Loading plugin "alsa_controller"... Dec 28 10:56:26 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:26 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:26 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:26 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:26 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:26 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:26 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:26 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 28 10:56:26 rivo volumio[3271]: info: Loading plugin "wizard"... Dec 28 10:56:26 rivo volumio[3271]: info: Loading plugin "networkfs"... Dec 28 10:56:26 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:26 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:26 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:26 rivo volumio[3271]: info: Starting Udev Watcher for removable devices Dec 28 10:56:26 rivo volumio[3271]: info: Ignoring mount for partition: BOOT Dec 28 10:56:26 rivo volumio[3271]: info: Ignoring mount for partition: volumio Dec 28 10:56:26 rivo volumio[3271]: info: Ignoring mount for partition: volumio_data Dec 28 10:56:26 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 28 10:56:26 rivo volumio[3271]: info: Loading plugin "volumio_command_line_client"... Dec 28 10:56:26 rivo volumio[3271]: info: Plugin upnp is not enabled Dec 28 10:56:26 rivo volumio[3271]: info: Loading plugin "my_music"... Dec 28 10:56:26 rivo volumio[3271]: info: Loading plugin "mpd"... Dec 28 10:56:26 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:26 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:26 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:26 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:26 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:26 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:26 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:27 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:27 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:27 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:27 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:27 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:27 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:27 rivo volumio[3271]: info: Loading plugin "upnp_browser"... Dec 28 10:56:27 rivo volumio-remote-updater[2830]: [2025-12-28 10:56:27] [connect] Successful connection Dec 28 10:56:27 rivo volumio[3271]: info: Starting UPNP Browser Dec 28 10:56:27 rivo volumio[3271]: info: Loading plugin "bluetooth"... Dec 28 10:56:27 rivo volumio-time-update[2843]: volumio-time-update-util: Fetching time from Volumio... Dec 28 10:56:27 rivo volumio[3271]: info: [1766915787958] Starting BluetoothController Dec 28 10:56:27 rivo volumio-time-update[2843]: volumio-time-update-util: Date not found in response Dec 28 10:56:27 rivo volumio-time-update[2843]: volumio-time-update-util: Retrying in 5 seconds... Dec 28 10:56:28 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:28 rivo volumio[3271]: info: Loading plugin "alarm-clock"... Dec 28 10:56:28 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:28 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 8 Dec 28 10:56:28 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dadb000 drv_status 0x0 e_type 69 e_states 0 Dec 28 10:56:28 rivo sudo[3409]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:28 rivo volumio[3271]: info: Loading plugin "manifestui"... Dec 28 10:56:28 rivo volumio[3271]: info: Loading plugin "metavolumio"... Dec 28 10:56:30 rivo volumio[3271]: info: Loading plugin "airplay_emulation"... Dec 28 10:56:30 rivo volumio[3271]: info: Starting Shairport Sync Dec 28 10:56:30 rivo volumio[3271]: info: Loading plugin "cd_controller"... Dec 28 10:56:31 rivo volumio[3271]: info: Loading plugin "last_100"... Dec 28 10:56:31 rivo volumio[3271]: info: Loading plugin "qobuzconnect"... Dec 28 10:56:31 rivo volumio[3271]: info: Loading plugin "raat"... Dec 28 10:56:31 rivo volumio[3271]: info: RAAT Plugin loaded Dec 28 10:56:31 rivo volumio[3271]: info: Adding restartRAATSocket REST API Endpoint Dec 28 10:56:31 rivo volumio[3271]: info: Adding restartRAATSocket REST Endpoint for plugin: music_service/raat Dec 28 10:56:31 rivo volumio[3271]: info: Loading plugin "streaming_services"... Dec 28 10:56:32 rivo volumio-time-update[2843]: volumio-time-update-util: Fetching time from Volumio... Dec 28 10:56:33 rivo volumio-time-update[2843]: volumio-time-update-util: Date not found in response Dec 28 10:56:33 rivo volumio-time-update[2843]: volumio-time-update-util: Retrying in 5 seconds... Dec 28 10:56:34 rivo volumio[3271]: info: Starting Streaming Service Transparent Proxy Dec 28 10:56:34 rivo volumio[3271]: info: Loading plugin "tidalconnect"... Dec 28 10:56:34 rivo volumio[3271]: info: Loading plugin "webradio"... Dec 28 10:56:34 rivo volumio[3271]: info: Loading plugin "i2s_dacs"... Dec 28 10:56:34 rivo volumio[3271]: info: I2S DAC not set, start Auto-detection Dec 28 10:56:34 rivo volumio[3271]: info: Loading plugin "volumiodiscovery"... Dec 28 10:56:34 rivo volumio[3271]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 28 10:56:34 rivo volumio[3271]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 28 10:56:34 rivo volumio[3271]: *** WARNING *** For more information see Dec 28 10:56:34 rivo node[3271]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 28 10:56:34 rivo volumio[3271]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 28 10:56:34 rivo volumio[3271]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 28 10:56:34 rivo volumio[3271]: *** WARNING *** For more information see Dec 28 10:56:34 rivo node[3271]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 28 10:56:34 rivo node[3271]: *** WARNING *** For more information see Dec 28 10:56:34 rivo node[3271]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 28 10:56:34 rivo node[3271]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 28 10:56:34 rivo node[3271]: *** WARNING *** For more information see Dec 28 10:56:34 rivo volumio[3271]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 28 10:56:34 rivo volumio[3271]: info: Discovery: Started advertising with name: Rivo Dec 28 10:56:34 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 28 10:56:34 rivo volumio[3271]: info: Loading plugin "spop"... Dec 28 10:56:35 rivo volumio[3271]: STREAMING PROXY: Starting server on port 3245 Dec 28 10:56:35 rivo volumio[3271]: Node JS runtime: 14 Dec 28 10:56:37 rivo volumio[3271]: info: Loading plugin "multiroom"... Dec 28 10:56:37 rivo kernel: fb: mem_free_work, free memory: addr:800000 Dec 28 10:56:38 rivo volumio-time-update[2843]: volumio-time-update-util: Fetching time from Volumio... Dec 28 10:56:38 rivo volumio-time-update[2843]: volumio-time-update-util: Date not found in response Dec 28 10:56:38 rivo volumio-time-update[2843]: volumio-time-update-util: Retrying in 5 seconds... Dec 28 10:56:39 rivo volumio[3271]: info: Applying required configuration parameters for plugin multiroom Dec 28 10:56:39 rivo sudo[3638]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 28 10:56:39 rivo sudo[3638]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:39 rivo sudo[3638]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:39 rivo volumio[3271]: info: MRS: MultiRoom plugin initialized Dec 28 10:56:39 rivo volumio[3271]: info: MRS: STOPPING SNAPCLIENT Dec 28 10:56:39 rivo volumio[3271]: info: MRS: Snap server stop Dec 28 10:56:39 rivo sudo[3654]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 28 10:56:39 rivo sudo[3654]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:39 rivo volumio[3271]: info: MRS: STOPPING volumioStreaming Dec 28 10:56:39 rivo sudo[3656]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 28 10:56:39 rivo sudo[3656]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:39 rivo volumio[3271]: info: Loading plugin "outputs"... Dec 28 10:56:39 rivo sudo[3654]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:39 rivo sudo[3660]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 28 10:56:39 rivo sudo[3660]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:39 rivo volumio[3271]: info: Loading plugin "albumart"... Dec 28 10:56:39 rivo sudo[3662]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 28 10:56:39 rivo sudo[3662]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:39 rivo sudo[3662]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:39 rivo sudo[3656]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:39 rivo volumio[3271]: info: Plugin example_plugin is not enabled Dec 28 10:56:39 rivo volumio[3271]: info: Loading plugin "hi_res_audio"... Dec 28 10:56:39 rivo sudo[3660]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:40 rivo volumio[3271]: Forking 3 albumart workers Dec 28 10:56:41 rivo volumio[3271]: Starting albumart workers Dec 28 10:56:41 rivo volumio[3271]: Starting albumart workers Dec 28 10:56:41 rivo volumio[3271]: Starting albumart workers Dec 28 10:56:41 rivo volumio[3271]: info: Applying required configuration parameters for plugin hi_res_audio Dec 28 10:56:41 rivo volumio[3271]: info: Loading plugin "inputs"... Dec 28 10:56:42 rivo volumio-remote-updater[2830]: [2025-12-28 10:56:42] [connect] Successful connection Dec 28 10:56:42 rivo volumio[3271]: info: Loading plugin "qobuz"... Dec 28 10:56:43 rivo volumio-time-update[2843]: volumio-time-update-util: Fetching time from Volumio... Dec 28 10:56:43 rivo volumio-time-update[2843]: volumio-time-update-util: Date not found in response Dec 28 10:56:43 rivo volumio-time-update[2843]: volumio-time-update-util: Retrying in 5 seconds... Dec 28 10:56:44 rivo volumio[3271]: info: Loading plugin "smart_inputs"... Dec 28 10:56:44 rivo volumio[3271]: info: Loading plugin "tidal"... Dec 28 10:56:46 rivo volumio[3271]: info: Loading plugin "rivocontrol"... Dec 28 10:56:46 rivo volumio[3271]: info: Adding this device properties Dec 28 10:56:46 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , setThisDeviceVolumioProperties Dec 28 10:56:46 rivo volumio[3271]: info: Setting Additional Device Volumio Properties: [object Object] Dec 28 10:56:46 rivo volumio[3271]: info: Loading plugin "updater_comm"... Dec 28 10:56:47 rivo volumio[3271]: info: Loading plugin "cec_controller"... Dec 28 10:56:47 rivo volumio[3271]: info: Applying required configuration parameters for plugin cec_controller Dec 28 10:56:47 rivo volumio[3271]: info: Plugin mpdemulation is not enabled Dec 28 10:56:47 rivo volumio[3271]: info: Loading plugin "rest_api"... Dec 28 10:56:47 rivo volumio[3271]: info: Loading plugin "websocket"... Dec 28 10:56:47 rivo volumio[3271]: info: Starting Socket.io Server version 2.3.0 Dec 28 10:56:47 rivo volumio[3271]: info: Loading i18n strings for locale nl Dec 28 10:56:47 rivo volumio[3271]: Updating browse sources language Dec 28 10:56:47 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::initPlayerControls Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 28 10:56:48 rivo volumio[3271]: Express server listening on port 3000 Dec 28 10:56:48 rivo volumio[3271]: [Metrics] WebUI: 26s 317.00ms Dec 28 10:56:48 rivo volumio[3271]: info: CoreStateMachine::resetVolumioState Dec 28 10:56:48 rivo volumio[3271]: info: CoreStateMachine::getcurrentVolume Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::volumioRetrievevolume Dec 28 10:56:48 rivo volumio-time-update[2843]: volumio-time-update-util: Fetching time from Volumio... Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 28 10:56:48 rivo volumio-time-update[2843]: volumio-time-update-util: Date not found in response Dec 28 10:56:48 rivo volumio-time-update[2843]: volumio-time-update-util: Retrying in 5 seconds... Dec 28 10:56:48 rivo volumio[3271]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Dec 28 10:56:48 rivo volumio[3271]: info: Completed loading Core Plugins Dec 28 10:56:48 rivo volumio[3271]: info: Preparing to generate the ALSA configuration file Dec 28 10:56:48 rivo volumio[3271]: info: Volumio Network Manager: Network status updated: 0 Dec 28 10:56:48 rivo volumio[3271]: info: MRS: Removed streaming files Dec 28 10:56:48 rivo volumio[3271]: info: MRS: volumioStreaming STOPPED Dec 28 10:56:48 rivo volumio[3271]: info: MRS: SNAPSERVER STOPPED Dec 28 10:56:48 rivo volumio[3271]: info: MRS: SNAPCLIENT STOPPED Dec 28 10:56:48 rivo volumio[3271]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Dec 28 10:56:48 rivo volumio[3271]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 28 10:56:48 rivo volumio[3271]: info: Reading ALSA contributions from plugins. Dec 28 10:56:48 rivo volumio[3271]: info: Reloading queue from file Dec 28 10:56:48 rivo volumio[3271]: info: VolumeController:: Volume=46 Mute =false Dec 28 10:56:48 rivo volumio[3271]: info: CoreStateMachine::pushState Dec 28 10:56:48 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::volumioPushState Dec 28 10:56:48 rivo volumio[3271]: info: CoreStateMachine::updateTrackBlock Dec 28 10:56:48 rivo volumio[3271]: info: CorePlayQueue::getTrackBlock Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::volumioRetrievevolume Dec 28 10:56:48 rivo volumio[3271]: info: CoreStateMachine::setRepeat false single undefined Dec 28 10:56:48 rivo volumio[3271]: info: CoreStateMachine::pushState Dec 28 10:56:48 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::volumioPushState Dec 28 10:56:48 rivo volumio[3271]: info: CoreStateMachine::setRandom false Dec 28 10:56:48 rivo volumio[3271]: info: CoreStateMachine::pushState Dec 28 10:56:48 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::volumioPushState Dec 28 10:56:48 rivo volumio[3271]: info: Asound.conf file unchanged, so no further update is needed Dec 28 10:56:48 rivo volumio[3271]: info: Output device has changed, restarting MPD Dec 28 10:56:48 rivo volumio[3271]: info: Output device has changed, restarting Shairport Sync Dec 28 10:56:48 rivo sudo[3760]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 28 10:56:48 rivo sudo[3760]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 28 10:56:48 rivo sudo[3760]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:48 rivo sudo[3763]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 28 10:56:48 rivo sudo[3763]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:48 rivo systemd[1]: Listening on mpd.socket. Dec 28 10:56:48 rivo systemd[1]: Starting Music Player Daemon... Dec 28 10:56:48 rivo volumio[3271]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 28 10:56:48 rivo volumio[3271]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 28 10:56:48 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:49 rivo volumio[3271]: info: ___________ START PLUGINS ___________ Dec 28 10:56:49 rivo volumio[3271]: info: ControllerMpd::onStart: Initializing MPD Dec 28 10:56:49 rivo volumio[3271]: info: Creating MPD Configuration file Dec 28 10:56:49 rivo sudo[3781]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Dec 28 10:56:49 rivo sudo[3781]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:49 rivo systemd[1]: Started Volumio5 Onboarding Server. Dec 28 10:56:49 rivo sudo[3781]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:49 rivo sudo[3770]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 28 10:56:49 rivo sudo[3770]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:49 rivo sudo[3785]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 28 10:56:49 rivo sudo[3785]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:49 rivo sudo[3785]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:49 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 28 10:56:49 rivo sudo[3770]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 28 10:56:49 rivo volumio[3271]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 28 10:56:49 rivo volumio[3271]: info: [1766915809202] CoreMusicLibrary::Adding element Media Servers Dec 28 10:56:49 rivo sudo[3770]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:49 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 28 10:56:49 rivo volumio[3271]: info: UPNP Browser: Client initialized successfully Dec 28 10:56:49 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 28 10:56:49 rivo sudo[3791]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 28 10:56:49 rivo sudo[3791]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:49 rivo volumio[3271]: info: Adding METAVOLUMIO REST API Endpoints Dec 28 10:56:49 rivo volumio[3271]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 28 10:56:49 rivo volumio[3271]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 28 10:56:49 rivo volumio[3271]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 28 10:56:49 rivo volumio[3271]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 28 10:56:49 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:49 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 28 10:56:49 rivo systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Dec 28 10:56:49 rivo systemd[1]: mpd.service: Succeeded. Dec 28 10:56:49 rivo systemd[1]: Stopped Music Player Daemon. Dec 28 10:56:49 rivo systemd[1]: Starting Music Player Daemon... Dec 28 10:56:49 rivo sudo[3795]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Rivo Dec 28 10:56:49 rivo sudo[3795]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:49 rivo sudo[3795]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:49 rivo volumio[3271]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 28 10:56:49 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:49 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 28 10:56:49 rivo volumio[3271]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 28 10:56:49 rivo volumio[3271]: info: Preparing CD Folders Dec 28 10:56:49 rivo volumio[3271]: info: Adding CD REST API Endpoints Dec 28 10:56:49 rivo volumio[3271]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 28 10:56:49 rivo volumio[3271]: info: Starting UDEV Watcher for CD Dec 28 10:56:49 rivo volumio[3271]: info: Detecting CD presence with UDEV Dec 28 10:56:49 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 28 10:56:49 rivo sudo[3796]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 28 10:56:49 rivo sudo[3796]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:49 rivo sudo[3796]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 28 10:56:49 rivo sudo[3796]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:49 rivo volumio[3271]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 28 10:56:49 rivo volumio[3271]: info: [1766915809581] CoreMusicLibrary::Adding element Last_100 Dec 28 10:56:49 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 28 10:56:49 rivo volumio[3271]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 28 10:56:49 rivo volumio[3271]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 28 10:56:49 rivo volumio[3271]: info: Starting RAAT Plugin Dec 28 10:56:49 rivo volumio5-onboarding[3786]: time=2025-12-28T10:56:49.698+01:00 level=INFO msg="running volumio5-device-gateway" version=5bca5789+CHANGES buildDate=2025-12-11T14:07:23Z Dec 28 10:56:49 rivo sudo[3816]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 28 10:56:49 rivo sudo[3816]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:49 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Dec 28 10:56:49 rivo volumio[3271]: info: Additional UI Settings Added for plugin music_service/raat Dec 28 10:56:49 rivo volumio[3271]: info: Registering DSP Elements listener and retrieving current ones Dec 28 10:56:49 rivo volumio[3271]: info: Additional DSP elements updated Dec 28 10:56:49 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:49 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:49 rivo volumio[3271]: info: Updating RAAT Signal Path Dec 28 10:56:49 rivo volumio[3271]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Dec 28 10:56:49 rivo volumio[3271]: info: Streaming services startup Dec 28 10:56:49 rivo volumio[3271]: info: Starting Streaming Daemon Dec 28 10:56:49 rivo sudo[3816]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:49 rivo sudo[3821]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 28 10:56:49 rivo sudo[3821]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:49 rivo sudo[3822]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 28 10:56:49 rivo sudo[3822]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:49 rivo systemd[1]: Started Volumio Qobuz Connect Service. Dec 28 10:56:49 rivo sudo[3821]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:49 rivo sudo[3822]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:49 rivo volumio[3271]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 28 10:56:49 rivo volumio[3271]: info: [1766915809936] CoreMusicLibrary::Adding element Webradio Dec 28 10:56:49 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 28 10:56:49 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 28 10:56:49 rivo volumio[3271]: info: Initializing BBC Radios Dec 28 10:56:49 rivo sudo[3832]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 28 10:56:49 rivo sudo[3832]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:50 rivo sudo[3832]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:50 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 28 10:56:50 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 28 10:56:50 rivo volumio[3271]: info: Creating Spotify config file Dec 28 10:56:50 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:50 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 28 10:56:50 rivo volumio[3271]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 28 10:56:50 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:50 rivo volumio[3271]: error: Hi Res Audio Failed Login: Missing Login Data Dec 28 10:56:50 rivo volumio[3271]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 28 10:56:50 rivo volumio[3271]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 28 10:56:50 rivo volumio[3271]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 28 10:56:50 rivo volumio[3271]: info: Initializing Serial Communication on port /dev/ttyS3 Dec 28 10:56:50 rivo volumio[3271]: info: Touch Event Listener Process Starting Dec 28 10:56:50 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 0 to 9600 Dec 28 10:56:50 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 9600 to 9600 Dec 28 10:56:50 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 9600 to 115200 Dec 28 10:56:50 rivo volumio[3271]: info: Refreshing QOBUZ token Dec 28 10:56:50 rivo sudo[3851]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xinput --test-xi2 --root Dec 28 10:56:50 rivo sudo[3851]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:50 rivo volumio[3271]: info: Adding inputs REST Endpoints Dec 28 10:56:50 rivo volumio[3271]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 28 10:56:50 rivo volumio[3271]: info: Scanning Audio Inputs Dec 28 10:56:50 rivo volumio[3271]: info: Checking against Known Cards name Dec 28 10:56:50 rivo volumio[3271]: info: Checking against Known Cards name Dec 28 10:56:50 rivo volumio[3271]: info: Checking against Known Cards name Dec 28 10:56:50 rivo volumio[3271]: info: Checking against Known Cards name Dec 28 10:56:50 rivo volumio[3271]: info: Checking against Known Cards name Dec 28 10:56:50 rivo volumio[3271]: info: Adding Server instance for streaming Dec 28 10:56:50 rivo sudo[3862]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x25 0x0 Dec 28 10:56:50 rivo sudo[3862]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:50 rivo sudo[3862]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:50 rivo sudo[3865]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x28 0x0 Dec 28 10:56:50 rivo sudo[3865]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:50 rivo sudo[3865]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:50 rivo sudo[3869]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x29 0x1 Dec 28 10:56:50 rivo sudo[3869]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:50 rivo sudo[3869]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:50 rivo sudo[3872]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x33 0x1 Dec 28 10:56:50 rivo sudo[3872]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:50 rivo sudo[3872]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:50 rivo volumio[3271]: info: Apply VIM3L Onboard LEDs Settings Dec 28 10:56:50 rivo volumio[3271]: info: Turning On Onboard LEDs Dec 28 10:56:50 rivo sudo[3876]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/sys_led/trigger Dec 28 10:56:50 rivo sudo[3876]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:50 rivo volumio[3271]: info: Starting CEC Event listener Dec 28 10:56:50 rivo volumio[3271]: info: Volumio Calling Home Dec 28 10:56:50 rivo sudo[3876]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:50 rivo sudo[3880]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/red_red/trigger Dec 28 10:56:50 rivo sudo[3880]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:50 rivo sudo[3880]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:51 rivo volumio[3271]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 28 10:56:51 rivo volumio[3271]: (node:3271) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Dec 28 10:56:51 rivo volumio[3271]: (Use `node --trace-deprecation ...` to show where the warning was created) Dec 28 10:56:51 rivo volumio[3271]: info: Adding TIDAL REST API Endpoints Dec 28 10:56:51 rivo volumio[3271]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Dec 28 10:56:51 rivo volumio[3271]: Unhandled rejection Error: No sockets available, cannot start. Dec 28 10:56:51 rivo volumio[3271]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Dec 28 10:56:51 rivo volumio[3271]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Dec 28 10:56:51 rivo volumio[3271]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Dec 28 10:56:51 rivo volumio[3271]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Dec 28 10:56:51 rivo volumio[3271]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Dec 28 10:56:51 rivo volumio[3271]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Dec 28 10:56:51 rivo volumio[3271]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Dec 28 10:56:51 rivo volumio[3271]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Dec 28 10:56:51 rivo volumio[3271]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:156:14) Dec 28 10:56:51 rivo volumio[3271]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Dec 28 10:56:51 rivo volumio[3271]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Dec 28 10:56:51 rivo volumio[3271]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Dec 28 10:56:51 rivo volumio[3271]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Dec 28 10:56:51 rivo volumio[3271]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Dec 28 10:56:51 rivo volumio[3271]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Dec 28 10:56:51 rivo volumio[3271]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 28 10:56:51 rivo volumio[3271]: info: Serial port opened successfully Dec 28 10:56:51 rivo volumio[3271]: info: Sending serial start messages Dec 28 10:56:51 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:51 rivo volumio[3271]: info: Reporting MCU Network Status: 0 Dec 28 10:56:51 rivo volumio[3271]: info: MP1 GPIO: Signalled system ready via GPIO Dec 28 10:56:51 rivo volumio[3271]: warn: QOBUZ login failed: No access token received Dec 28 10:56:51 rivo volumio[3271]: info: Stopping AccessToken refresher cron for QOBUZ Dec 28 10:56:51 rivo volumio[3271]: info: AccessToken refresher cron started for QOBUZ Dec 28 10:56:51 rivo volumio[3271]: info: Adding QOBUZ REST API Endpoints Dec 28 10:56:51 rivo volumio[3271]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Dec 28 10:56:51 rivo volumio[3271]: error: Cannot start Volumio Streaming Daemon Dec 28 10:56:51 rivo volumio[3271]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 28 10:56:51 rivo volumio[3271]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 28 10:56:51 rivo volumio[3271]: info: RAAT Albumart path created successfully Dec 28 10:56:51 rivo volumio[3271]: info: Bluetooth name changed to Rivo Dec 28 10:56:51 rivo volumio[3271]: info: MPD Permissions set Dec 28 10:56:51 rivo volumio[3271]: info: MPD Permissions set Dec 28 10:56:51 rivo volumio[3271]: info: VolumeController:: Volume=46 Mute =false Dec 28 10:56:51 rivo volumio[3271]: info: CoreStateMachine::pushState Dec 28 10:56:51 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:51 rivo volumio[3271]: info: CoreCommandRouter::volumioPushState Dec 28 10:56:51 rivo volumio[3271]: info: CoreCommandRouter::volumioGetState Dec 28 10:56:51 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:51 rivo volumio[3271]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Dec 28 10:56:51 rivo volumio5-onboarding[3786]: time=2025-12-28T10:56:51.731+01:00 level=INFO msg="listening for BLE messages" address=10:2C:6B:5C:DD:BD%00 Dec 28 10:56:51 rivo volumio5-onboarding[3786]: time=2025-12-28T10:56:51.732+01:00 level=INFO msg="listening for WebSocket messages" address=[::]:7331 Dec 28 10:56:51 rivo volumio[3271]: info: Executing endpoint qc_getconfig Dec 28 10:56:51 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 28 10:56:51 rivo qobuz-connect[3828]: 20251228 10:56:51.834 [3828.3828] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 28 10:56:51 rivo volumio[3271]: info: Spotify config file written Dec 28 10:56:51 rivo sudo[3903]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 28 10:56:51 rivo sudo[3903]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:51 rivo volumio[3271]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Dec 28 10:56:51 rivo volumio[3271]: info: Received Get System Info Dec 28 10:56:51 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 28 10:56:51 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 28 10:56:51 rivo volumio[3271]: info: Discovery: Getting this device information Dec 28 10:56:51 rivo volumio[3271]: info: CoreCommandRouter::volumioGetState Dec 28 10:56:51 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:51 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 28 10:56:51 rivo volumio[3271]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 28 10:56:52 rivo volumio[3271]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 28 10:56:52 rivo volumio[3271]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:52 rivo systemd[1]: Started go-librespot Daemon. Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:52 rivo qobuz-connect[3828]: 20251228 10:56:52.037 [3828.3828] INFO VolumeManager: [0xab1339b8]: Setting new playback volume: 75 Dec 28 10:56:52 rivo qobuz-connect[3828]: 20251228 10:56:52.038 [3828.3828] INFO VolumeManager: [0xab1339b8]: Setting new mute state: 0 Dec 28 10:56:52 rivo go-librespot[3905]: go-librespot daemon starting... Dec 28 10:56:52 rivo qobuz-connect[3828]: 20251228 10:56:52.042 [3828.3828] INFO QobuzConnect: [0xab134388]: Client initialized! Dec 28 10:56:52 rivo qobuz-connect[3828]: 20251228 10:56:52.042 [3828.3828] INFO SampleApp: Starting Avahi advertising, name: Rivo, service name: _qobuz-connect._tcp Dec 28 10:56:52 rivo sudo[3903]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:52 rivo qobuz-connect[3828]: 20251228 10:56:52.089 [3828.3828] INFO LocalConfigManager: [0xab133298]: Starting Local Configuration server Dec 28 10:56:52 rivo qobuz-connect[3828]: 20251228 10:56:52.089 [3828.3828] INFO SampleApp: Starting Local configuration server Dec 28 10:56:52 rivo qobuz-connect[3828]: 20251228 10:56:52.090 [3828.3828] INFO SampleApp: Playback volume changed: 75 Dec 28 10:56:52 rivo qobuz-connect[3828]: 20251228 10:56:52.090 [3828.3828] INFO SampleApp: Connected to UNIX socket client 0xab128ed8 Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 28 10:56:52 rivo go-librespot[3905]: time="2025-12-28T10:56:52+01:00" level=info msg="running go-librespot 0.4.0" Dec 28 10:56:52 rivo go-librespot[3905]: time="2025-12-28T10:56:52+01:00" level=debug msg="app state loaded" Dec 28 10:56:52 rivo go-librespot[3905]: time="2025-12-28T10:56:52+01:00" level=debug msg="stored credentials not found" Dec 28 10:56:52 rivo go-librespot[3905]: time="2025-12-28T10:56:52+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 10:56:52 rivo go-librespot[3905]: time="2025-12-28T10:56:52+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Dec 28 10:56:52 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:56:52 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 10:56:52 rivo volumio[3271]: info: No need to fix Spotify hosts Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 28 10:56:52 rivo volumio5-onboarding[3786]: time=2025-12-28T10:56:52.342+01:00 level=INFO msg="BLE descriptor updated" deviceId=62d8aee608042b2e70e8dba82c16ab02 deviceName=Rivo deviceModel=0x2492688 Dec 28 10:56:52 rivo volumio5-onboarding[3786]: time=2025-12-28T10:56:52.342+01:00 level=INFO msg="mDNS descriptor updated" deviceId=62d8aee608042b2e70e8dba82c16ab02 deviceName=Rivo deviceModel=0x2492688 Dec 28 10:56:52 rivo volumio5-onboarding[3786]: time=2025-12-28T10:56:52.343+01:00 level=INFO msg="bootstrapping state" hasInternet=false Dec 28 10:56:52 rivo volumio[3271]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::volumioGetState Dec 28 10:56:52 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:52 rivo sudo[3927]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 28 10:56:52 rivo sudo[3927]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:52 rivo systemd[1]: Started Volumio Bluetooth Module. Dec 28 10:56:52 rivo sudo[3927]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:52 rivo sudo[3932]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Dec 28 10:56:52 rivo sudo[3932]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:52 rivo volumiobt[3931]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Dec 28 10:56:52 rivo sudo[3932]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:52 rivo volumio[3271]: info: Received Get System Info Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 28 10:56:52 rivo volumio[3271]: info: Discovery: Getting this device information Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::volumioGetState Dec 28 10:56:52 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 28 10:56:52 rivo volumio[3271]: info: Volumio BT Module successfully started Dec 28 10:56:52 rivo volumio[3271]: info: Starting Shairport Sync Dec 28 10:56:52 rivo volumio[3271]: info: Starting Shairport Sync Dec 28 10:56:52 rivo sudo[3937]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 28 10:56:52 rivo sudo[3937]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:52 rivo volumio[3271]: info: Starting Shairport Sync Dec 28 10:56:52 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 28 10:56:52 rivo systemd[1]: shairport-sync.service: Succeeded. Dec 28 10:56:52 rivo sudo[3944]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 28 10:56:52 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 28 10:56:52 rivo sudo[3944]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:52 rivo volumio[3271]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 28 10:56:52 rivo sudo[3949]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 28 10:56:52 rivo sudo[3949]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:52 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 28 10:56:52 rivo volumio5-onboarding[3786]: time=2025-12-28T10:56:52.794+01:00 level=INFO msg="BLE descriptor updated" deviceId=62d8aee608042b2e70e8dba82c16ab02 deviceName=Rivo deviceModel=0x2492058 Dec 28 10:56:52 rivo volumio5-onboarding[3786]: time=2025-12-28T10:56:52.799+01:00 level=INFO msg="mDNS descriptor updated" deviceId=62d8aee608042b2e70e8dba82c16ab02 deviceName=Rivo deviceModel=0x2492058 Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 28 10:56:52 rivo sudo[3937]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::volumioGetState Dec 28 10:56:52 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:52 rivo volumio[3271]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 28 10:56:52 rivo volumio[3271]: info: CoreCommandRouter::volumioGetState Dec 28 10:56:52 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:52 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 28 10:56:52 rivo systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Dec 28 10:56:52 rivo systemd[1]: shairport-sync.service: Succeeded. Dec 28 10:56:52 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 28 10:56:52 rivo volumio[3271]: info: Shairport-Sync Started Dec 28 10:56:52 rivo volumio[3271]: Error adding Membership: Error: addMembership EINVAL Dec 28 10:56:52 rivo volumio[3271]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 28 10:56:52 rivo volumio[3271]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 28 10:56:52 rivo volumio[3271]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 28 10:56:52 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 28 10:56:52 rivo sudo[3949]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:52 rivo sudo[3944]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:53 rivo volumio[3271]: info: Shairport-Sync Started Dec 28 10:56:53 rivo volumio[3271]: info: Shairport-Sync Started Dec 28 10:56:53 rivo volumio[3271]: info: TidalConnect service stoped! Dec 28 10:56:53 rivo volumio-time-update[2843]: volumio-time-update-util: Fetching time from Volumio... Dec 28 10:56:53 rivo volumio-time-update[2843]: volumio-time-update-util: Date not found in response Dec 28 10:56:53 rivo volumio-time-update[2843]: volumio-time-update-util: Retrying in 5 seconds... Dec 28 10:56:53 rivo volumio[3271]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 28 10:56:53 rivo volumio[3271]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 28 10:56:53 rivo sudo[3986]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 28 10:56:53 rivo sudo[3986]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:53 rivo systemd[1]: Started Volumio Tidal Connect Service. Dec 28 10:56:53 rivo sudo[3986]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:53 rivo mpd[3811]: Dec 28 10:56 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 28 10:56:53 rivo systemd[1]: Started Music Player Daemon. Dec 28 10:56:53 rivo sudo[3763]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:53 rivo sudo[3791]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:53 rivo volumio[3271]: info: Turning Off Onboard LEDs Dec 28 10:56:53 rivo sudo[3996]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Dec 28 10:56:53 rivo sudo[3996]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:53 rivo sudo[3998]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/sys_led/trigger Dec 28 10:56:53 rivo sudo[3998]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:53 rivo volumiobt[3931]: pulseaudio: no process found Dec 28 10:56:53 rivo sudo[3996]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:53 rivo sudo[3998]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:53 rivo sudo[4003]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/red_red/trigger Dec 28 10:56:53 rivo sudo[4003]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:53 rivo sudo[4003]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:53 rivo volumio[3271]: error: MPD error: The expression evaluated to a falsy value: Dec 28 10:56:53 rivo volumio[3271]: assert.ok(self.idling) Dec 28 10:56:53 rivo volumio[3271]: error: The expression evaluated to a falsy value: Dec 28 10:56:53 rivo volumio[3271]: assert.ok(self.idling) Dec 28 10:56:53 rivo volumio[3271]: error: updateQueue error: null Dec 28 10:56:53 rivo volumio[3271]: info: Onboard LEDs initialized Dec 28 10:56:53 rivo volumio[3271]: info: MPD running with PID3811 Dec 28 10:56:53 rivo volumio[3271]: ,establishing connection Dec 28 10:56:53 rivo volumio[3271]: error: updateQueue error: null Dec 28 10:56:53 rivo dbus-daemon[2834]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.19' (uid=1000 pid=4006 comm="/usr/bin/pulseaudio --high-priority=true " label="kernel") Dec 28 10:56:53 rivo volumio[3271]: info: Executing endpoint tc_getconfig Dec 28 10:56:53 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 28 10:56:53 rivo vtcs[3988]: STARTING TidalConnect services, version: 1.5.2.56 Dec 28 10:56:53 rivo vtcs[3988]: STARTED TidalConnect services. Dec 28 10:56:53 rivo systemd[1]: Starting RealtimeKit Scheduling Policy Service... Dec 28 10:56:53 rivo volumio[3271]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 28 10:56:53 rivo kernel: IPVS: Creating netns size=1928 id=2 Dec 28 10:56:53 rivo volumio[3271]: info: Executing endpoint tc_connect Dec 28 10:56:53 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 28 10:56:53 rivo volumio[3271]: info: Connecting to TidalConnect Dec 28 10:56:53 rivo dbus-daemon[2834]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Dec 28 10:56:53 rivo rtkit-daemon[4015]: Successfully called chroot. Dec 28 10:56:53 rivo systemd[1]: Started RealtimeKit Scheduling Policy Service. Dec 28 10:56:53 rivo volumio[3271]: 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: 4 Dec 28 10:56:53 rivo rtkit-daemon[4015]: Successfully dropped privileges. Dec 28 10:56:53 rivo rtkit-daemon[4015]: Successfully limited resources. Dec 28 10:56:53 rivo rtkit-daemon[4015]: Running. Dec 28 10:56:53 rivo rtkit-daemon[4015]: Watchdog thread running. Dec 28 10:56:53 rivo rtkit-daemon[4015]: Canary thread running. Dec 28 10:56:53 rivo dbus-daemon[2834]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.20' (uid=0 pid=4015 comm="/usr/lib/rtkit/rtkit-daemon " label="kernel") Dec 28 10:56:54 rivo systemd[1]: Starting Authorization Manager... Dec 28 10:56:54 rivo volumio[3271]: info: CoreCommandRouter::servicePushState Dec 28 10:56:54 rivo volumio[3271]: info: CoreStateMachine::pushState Dec 28 10:56:54 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:54 rivo volumio[3271]: info: CoreCommandRouter::volumioPushState Dec 28 10:56:54 rivo volumio[3271]: info: CoreCommandRouter::volumioGetState Dec 28 10:56:54 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:54 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:54 rivo volumio[3271]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received tidalconnect Dec 28 10:56:54 rivo volumio[3271]: info: CoreCommandRouter::servicePushState Dec 28 10:56:54 rivo volumio[3271]: info: CoreStateMachine::pushState Dec 28 10:56:54 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:54 rivo volumio[3271]: info: CoreCommandRouter::volumioPushState Dec 28 10:56:54 rivo volumio[3271]: info: CoreCommandRouter::volumioGetState Dec 28 10:56:54 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:54 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:54 rivo volumio[3271]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received tidalconnect Dec 28 10:56:54 rivo volumio[3271]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 28 10:56:54 rivo polkitd[4020]: started daemon version 0.105 using authority implementation `local' version `0.105' Dec 28 10:56:54 rivo dbus-daemon[2834]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Dec 28 10:56:54 rivo systemd[1]: Started Authorization Manager. Dec 28 10:56:54 rivo pulseaudio[4006]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Dec 28 10:56:54 rivo pulseaudio[4006]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Dec 28 10:56:54 rivo volumiobt[3931]: Applying permissions Dec 28 10:56:54 rivo volumiobt[3931]: Setting BT discoverable and pairable Dec 28 10:56:54 rivo bluetoothd[3198]: Endpoint registered: sender=:1.41 path=/MediaEndpoint/A2DPSource Dec 28 10:56:54 rivo pulseaudio[4006]: 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 Dec 28 10:56:54 rivo bluetoothd[3198]: Endpoint registered: sender=:1.41 path=/MediaEndpoint/A2DPSink Dec 28 10:56:54 rivo volumiobt[3931]: [96B blob data] Dec 28 10:56:54 rivo volumiobt[3931]: [77B blob data] Dec 28 10:56:54 rivo volumiobt[3931]: [77B blob data] Dec 28 10:56:54 rivo volumiobt[3931]: [33B blob data] Dec 28 10:56:54 rivo volumiobt[3931]: [65B blob data] Dec 28 10:56:54 rivo volumiobt[3931]: [103B blob data] Dec 28 10:56:54 rivo volumiobt[3931]: [bluetoothctl]> -e power on Dec 28 10:56:54 rivo volumiobt[3931]: Invalid command in menu main: -e Dec 28 10:56:54 rivo volumiobt[3931]: Dec 28 10:56:54 rivo volumiobt[3931]: Use "help" for a list of available commands in a menu. Dec 28 10:56:54 rivo volumiobt[3931]: Use "menu " if you want to enter any submenu. Dec 28 10:56:54 rivo volumiobt[3931]: Use "back" if you want to return to menu main. Dec 28 10:56:54 rivo volumiobt[3931]: [bluetoothctl]> agent on Dec 28 10:56:54 rivo volumiobt[3931]: Agent is already registered Dec 28 10:56:54 rivo volumiobt[3931]: [bluetoothctl]> discoverable on Dec 28 10:56:54 rivo volumiobt[3931]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended Dec 28 10:56:54 rivo volumiobt[3931]: [bluetoothctl]> pairable on Dec 28 10:56:54 rivo volumiobt[3931]: [bluetoothctl]> agent NoInputNoOutput Dec 28 10:56:54 rivo volumiobt[3931]: Agent is already registered Dec 28 10:56:54 rivo volumiobt[3931]: [bluetoothctl]> default-agent Dec 28 10:56:54 rivo volumiobt[3931]: [bluetoothctl]> quit Dec 28 10:56:54 rivo volumiobt[3931]: [65B blob data] Dec 28 10:56:54 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 28 10:56:55 rivo volumio[3271]: info: MRS: Getting audio outputs on start Dec 28 10:56:55 rivo volumio[3271]: info: MRS: Requesting all other devices output Dec 28 10:56:55 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 10:56:55 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 28 10:56:55 rivo systemd[1]: Stopped go-librespot Daemon. Dec 28 10:56:55 rivo volumio[3271]: info: go-librespot daemon successfully initialized Dec 28 10:56:55 rivo systemd[1]: Started go-librespot Daemon. Dec 28 10:56:55 rivo go-librespot[4034]: go-librespot daemon starting... Dec 28 10:56:55 rivo go-librespot[4034]: time="2025-12-28T10:56:55+01:00" level=info msg="running go-librespot 0.4.0" Dec 28 10:56:55 rivo go-librespot[4034]: time="2025-12-28T10:56:55+01:00" level=debug msg="app state loaded" Dec 28 10:56:55 rivo go-librespot[4034]: time="2025-12-28T10:56:55+01:00" level=debug msg="stored credentials not found" Dec 28 10:56:55 rivo go-librespot[4034]: time="2025-12-28T10:56:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 10:56:55 rivo go-librespot[4034]: time="2025-12-28T10:56:55+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Dec 28 10:56:55 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 10:56:55 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 10:56:55 rivo volumio[3271]: 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 Dec 28 10:56:56 rivo volumio[3271]: info: TidalConnect service started! Dec 28 10:56:56 rivo volumio[3271]: info: Completed starting Core Plugins Dec 28 10:56:56 rivo volumio[3271]: info: ------------------------------------------- Dec 28 10:56:56 rivo volumio[3271]: info: ----- MyVolumio plugins startup ---- Dec 28 10:56:56 rivo volumio[3271]: info: ------------------------------------------- Dec 28 10:56:56 rivo volumio[3271]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 28 10:56:56 rivo sudo[4060]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 28 10:56:56 rivo sudo[4060]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:56 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 28 10:56:56 rivo sudo[4062]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 28 10:56:56 rivo sudo[4062]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:56:56 rivo systemd[1]: Started MPD Monitor Service. Dec 28 10:56:56 rivo sudo[4060]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:56 rivo systemd[1]: Stopping MPD Monitor Service... Dec 28 10:56:56 rivo systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Dec 28 10:56:56 rivo systemd[1]: mpd_monitor.service: Succeeded. Dec 28 10:56:56 rivo systemd[1]: Stopped MPD Monitor Service. Dec 28 10:56:56 rivo systemd[1]: Started MPD Monitor Service. Dec 28 10:56:56 rivo sudo[4062]: pam_unix(sudo:session): session closed for user root Dec 28 10:56:56 rivo volumio[3271]: info: Successfully started MPD Monitor Dec 28 10:56:56 rivo volumio[3271]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 28 10:56:56 rivo volumio[3271]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 28 10:56:56 rivo volumio[3271]: info: Successfully started MPD Monitor Dec 28 10:56:56 rivo mpd_monitor.sh[4066]: MPD Monitor Service: Starting MPD Monitor Service Dec 28 10:56:57 rivo volumio[3271]: info: CoreCommandRouter::volumioGetVisibleSources Dec 28 10:56:57 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 28 10:56:57 rivo volumio[3271]: info: CoreCommandRouter::volumioGetState Dec 28 10:56:57 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:57 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 28 10:56:57 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 28 10:56:57 rivo volumio[3271]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Dec 28 10:56:57 rivo volumio[3271]: info: Received Get System Info Dec 28 10:56:57 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 28 10:56:57 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 28 10:56:57 rivo volumio[3271]: info: Discovery: Getting this device information Dec 28 10:56:57 rivo volumio[3271]: info: CoreCommandRouter::volumioGetState Dec 28 10:56:57 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:57 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 28 10:56:57 rivo volumio[3271]: info: CoreCommandRouter::volumioGetState Dec 28 10:56:57 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:57 rivo volumio[3271]: info: Listing playlists Dec 28 10:56:57 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 28 10:56:57 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 28 10:56:57 rivo volumio[3271]: info: CoreCommandRouter::volumioGetState Dec 28 10:56:57 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:57 rivo volumio-remote-updater[2830]: [2025-12-28 10:56:57] [connect] Successful connection Dec 28 10:56:57 rivo volumio-remote-updater[2830]: [2025-12-28 10:56:57] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1766915817 101 Dec 28 10:56:57 rivo volumio[3271]: 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: 6 Dec 28 10:56:57 rivo dhcpcd[3388]: eth0: carrier acquired Dec 28 10:56:57 rivo kernel: meson6-dwmac ff3f0000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Dec 28 10:56:57 rivo dhcpcd[3388]: eth0: IAID 00:16:16:01 Dec 28 10:56:57 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 28 10:56:57 rivo volumio[3271]: info: Received Get System Info Dec 28 10:56:57 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 28 10:56:57 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 28 10:56:57 rivo volumio[3271]: info: Discovery: Getting this device information Dec 28 10:56:57 rivo volumio[3271]: info: CoreCommandRouter::volumioGetState Dec 28 10:56:57 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:57 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 28 10:56:57 rivo ifplugd(eth0)[3085]: Link beat detected. Dec 28 10:56:58 rivo dhcpcd[3388]: eth0: rebinding lease of 192.168.178.177 Dec 28 10:56:58 rivo volumio[3271]: info: Received Get System Info Dec 28 10:56:58 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 28 10:56:58 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 28 10:56:58 rivo volumio[3271]: info: Discovery: Getting this device information Dec 28 10:56:58 rivo volumio[3271]: info: CoreCommandRouter::volumioGetState Dec 28 10:56:58 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:58 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 28 10:56:58 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 28 10:56:58 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 28 10:56:58 rivo volumio5-onboarding[3786]: time=2025-12-28T10:56:58.051+01:00 level=INFO msg="BLE descriptor updated" deviceId=62d8aee608042b2e70e8dba82c16ab02 deviceName=Rivo deviceModel=0x251c2e0 Dec 28 10:56:58 rivo volumio5-onboarding[3786]: time=2025-12-28T10:56:58.057+01:00 level=INFO msg="mDNS descriptor updated" deviceId=62d8aee608042b2e70e8dba82c16ab02 deviceName=Rivo deviceModel=0x251c2e0 Dec 28 10:56:58 rivo ifplugd(eth0)[3085]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Dec 28 10:56:58 rivo ifplugd(eth0)[3085]: client: sending commands to master dhcpcd process Dec 28 10:56:58 rivo dhcpcd[4092]: sending commands to master dhcpcd process Dec 28 10:56:58 rivo dhcpcd[3388]: control command: /sbin/dhcpcd eth0 Dec 28 10:56:58 rivo volumio-time-update[2843]: volumio-time-update-util: Fetching time from Volumio... Dec 28 10:56:58 rivo volumio-time-update[2843]: volumio-time-update-util: Date not found in response Dec 28 10:56:58 rivo volumio-time-update[2843]: volumio-time-update-util: Retrying in 5 seconds... Dec 28 10:56:58 rivo dhcpcd[3388]: eth0: probing address 192.168.178.177/24 Dec 28 10:56:58 rivo dhcpcd[3388]: eth0: soliciting an IPv6 router Dec 28 10:56:58 rivo ifplugd(eth0)[3085]: Program executed successfully. Dec 28 10:56:58 rivo volumio[3271]: info: Initializing connection to go-librespot Websocket Dec 28 10:56:58 rivo volumio[3271]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 10:56:58 rivo volumio[3271]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 28 10:56:58 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 10:56:58 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 28 10:56:58 rivo systemd[1]: Stopped go-librespot Daemon. Dec 28 10:56:58 rivo systemd[1]: Started go-librespot Daemon. Dec 28 10:56:58 rivo go-librespot[4123]: go-librespot daemon starting... Dec 28 10:56:58 rivo go-librespot[4123]: time="2025-12-28T10:56:58+01:00" level=info msg="running go-librespot 0.4.0" Dec 28 10:56:58 rivo go-librespot[4123]: time="2025-12-28T10:56:58+01:00" level=debug msg="app state loaded" Dec 28 10:56:58 rivo go-librespot[4123]: time="2025-12-28T10:56:58+01:00" level=debug msg="stored credentials not found" Dec 28 10:56:58 rivo go-librespot[4123]: time="2025-12-28T10:56:58+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 10:56:58 rivo go-librespot[4123]: time="2025-12-28T10:56:58+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Dec 28 10:56:58 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 10:56:58 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 10:56:58 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 28 10:56:59 rivo ntpd[3074]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Dec 28 10:56:59 rivo volumio[3271]: info: Executing endpoint metavolumio Dec 28 10:56:59 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 28 10:56:59 rivo volumio[3271]: info: Executing endpoint metavolumio Dec 28 10:56:59 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 28 10:56:59 rivo volumio[3271]: info: Executing endpoint metavolumio Dec 28 10:56:59 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 28 10:56:59 rivo volumio[3271]: error: Failed request for metavolumio API Dec 28 10:56:59 rivo volumio[3271]: error: Failed request for metavolumio API Dec 28 10:56:59 rivo volumio[3271]: error: Failed request for metavolumio API Dec 28 10:56:59 rivo volumio[3271]: info: Received Get System Info Dec 28 10:56:59 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 28 10:56:59 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 28 10:56:59 rivo volumio[3271]: info: Discovery: Getting this device information Dec 28 10:56:59 rivo volumio[3271]: info: CoreCommandRouter::volumioGetState Dec 28 10:56:59 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:56:59 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 28 10:56:59 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 28 10:56:59 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 28 10:56:59 rivo volumio5-onboarding[3786]: time=2025-12-28T10:56:59.557+01:00 level=INFO msg="BLE descriptor updated" deviceId=62d8aee608042b2e70e8dba82c16ab02 deviceName=Rivo deviceModel=0x251c2b8 Dec 28 10:56:59 rivo volumio5-onboarding[3786]: time=2025-12-28T10:56:59.560+01:00 level=INFO msg="mDNS descriptor updated" deviceId=62d8aee608042b2e70e8dba82c16ab02 deviceName=Rivo deviceModel=0x251c2b8 Dec 28 10:57:00 rivo volumio[3271]: info: Checking for updated MCU Firmware Dec 28 10:57:00 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 28 10:57:01 rivo volumio[3271]: info: Initializing connection to go-librespot Websocket Dec 28 10:57:01 rivo volumio[3271]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 10:57:01 rivo volumio[3271]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=mp1&variante=rivo&version=3.886&uuid=62d8aee608042b2e70e8dba82c16ab02" http://updates.volumio.org/downloader-v1/track-device Dec 28 10:57:01 rivo volumio[3271]: % Total % Received % Xferd Average Speed Time Time Time Current Dec 28 10:57:01 rivo volumio[3271]: Dload Upload Total Spent Left Speed Dec 28 10:57:01 rivo volumio[3271]: [132B blob data] Dec 28 10:57:01 rivo volumio[3271]: retrying in 5 seconds, trial 0 Dec 28 10:57:01 rivo volumio[3271]: info: Volumio Calling Home Dec 28 10:57:02 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 10:57:02 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 28 10:57:02 rivo systemd[1]: Stopped go-librespot Daemon. Dec 28 10:57:02 rivo systemd[1]: Started go-librespot Daemon. Dec 28 10:57:02 rivo go-librespot[4133]: go-librespot daemon starting... Dec 28 10:57:02 rivo go-librespot[4133]: time="2025-12-28T10:57:02+01:00" level=info msg="running go-librespot 0.4.0" Dec 28 10:57:02 rivo go-librespot[4133]: time="2025-12-28T10:57:02+01:00" level=debug msg="app state loaded" Dec 28 10:57:02 rivo go-librespot[4133]: time="2025-12-28T10:57:02+01:00" level=debug msg="stored credentials not found" Dec 28 10:57:02 rivo go-librespot[4133]: time="2025-12-28T10:57:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 10:57:02 rivo go-librespot[4133]: time="2025-12-28T10:57:02+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Dec 28 10:57:02 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 10:57:02 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 10:57:02 rivo ntpd[3074]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Dec 28 10:57:02 rivo ntpd[3074]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Dec 28 10:57:03 rivo volumio-time-update[2843]: volumio-time-update-util: Fetching time from Volumio... Dec 28 10:57:03 rivo volumio-time-update[2843]: volumio-time-update-util: Date not found in response Dec 28 10:57:03 rivo volumio-time-update[2843]: volumio-time-update-util: Retrying in 5 seconds... Dec 28 10:57:03 rivo ntpd[3074]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Dec 28 10:57:03 rivo dhcpcd[3388]: eth0: leased 192.168.178.177 for 86400 seconds Dec 28 10:57:03 rivo avahi-daemon[2825]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.178.177. Dec 28 10:57:03 rivo avahi-daemon[2825]: New relevant interface eth0.IPv4 for mDNS. Dec 28 10:57:03 rivo avahi-daemon[2825]: Registering new address record for 192.168.178.177 on eth0.IPv4. Dec 28 10:57:03 rivo dhcpcd[3388]: eth0: adding route to 192.168.178.0/24 Dec 28 10:57:03 rivo dhcpcd[3388]: eth0: adding default route via 192.168.178.1 Dec 28 10:57:03 rivo volumio[3271]: info: MRS: Found cast device: Chromecast-1c5c4ccaecb318c38324dd96bab9308b Dec 28 10:57:03 rivo volumio[3271]: info: Adding audio output: Dec 28 10:57:03 rivo ntpd[3074]: ntpd exiting on signal 15 (Terminated) Dec 28 10:57:03 rivo systemd[1]: Stopping Network Time Service... Dec 28 10:57:03 rivo volumio[3271]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 28 10:57:04 rivo systemd[1]: ntp.service: Succeeded. Dec 28 10:57:04 rivo systemd[1]: Stopped Network Time Service. Dec 28 10:57:04 rivo volumio[3271]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 28 10:57:04 rivo systemd[1]: Starting Network Time Service... Dec 28 10:57:04 rivo volumio[3271]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 28 10:57:04 rivo ntpd[4182]: ntpd 4.2.8p12@1.3728-o (1): Starting Dec 28 10:57:04 rivo ntpd[4182]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Dec 28 10:57:04 rivo systemd[1]: Started Network Time Service. Dec 28 10:57:04 rivo ntpd[4188]: proto: precision = 1.208 usec (-20) Dec 28 10:57:04 rivo ntpd[4188]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Dec 28 10:57:04 rivo ntpd[4188]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Dec 28 10:57:04 rivo ntpd[4188]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 1097 days ago Dec 28 10:57:04 rivo ntpd[4188]: Listen and drop on 0 v6wildcard [::]:123 Dec 28 10:57:04 rivo ntpd[4188]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Dec 28 10:57:04 rivo ntpd[4188]: Listen normally on 2 lo 127.0.0.1:123 Dec 28 10:57:04 rivo ntpd[4188]: Listen normally on 3 eth0 192.168.178.177:123 Dec 28 10:57:04 rivo ntpd[4188]: Listening on routing socket on fd #20 for interface updates Dec 28 10:57:04 rivo ntpd[4188]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Dec 28 10:57:04 rivo ntpd[4188]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Dec 28 10:57:04 rivo volumio[3271]: info: Received Get System Info Dec 28 10:57:04 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 28 10:57:04 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 28 10:57:04 rivo volumio[3271]: info: Discovery: Getting this device information Dec 28 10:57:04 rivo volumio[3271]: info: CoreCommandRouter::volumioGetState Dec 28 10:57:04 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:57:04 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 28 10:57:04 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 28 10:57:04 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 28 10:57:04 rivo volumio5-onboarding[3786]: time=2025-12-28T10:57:04.231+01:00 level=INFO msg="BLE descriptor updated" deviceId=62d8aee608042b2e70e8dba82c16ab02 deviceName=Rivo deviceModel=0x2492058 Dec 28 10:57:04 rivo volumio5-onboarding[3786]: time=2025-12-28T10:57:04.234+01:00 level=INFO msg="mDNS descriptor updated" deviceId=62d8aee608042b2e70e8dba82c16ab02 deviceName=Rivo deviceModel=0x2492058 Dec 28 10:57:04 rivo volumio[3271]: info: Initializing connection to go-librespot Websocket Dec 28 10:57:04 rivo volumio[3271]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 10:57:04 rivo volumio[3271]: info: Discovery: adding a207b852-abdb-4913-aadd-a236315978f3 Dec 28 10:57:04 rivo volumio[3271]: info: Discovery: Found device Rivo Dec 28 10:57:04 rivo volumio[3271]: info: CoreCommandRouter::volumioGetState Dec 28 10:57:04 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:57:04 rivo volumio[3271]: info: MRS: Pushing multiroomSync output for this device Dec 28 10:57:04 rivo volumio[3271]: info: MRS: Pushing multiroomSync output Dec 28 10:57:04 rivo volumio[3271]: info: Adding audio output: Dec 28 10:57:04 rivo volumio[3271]: info: Adding audio output: Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 28 10:57:04 rivo volumio[3271]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 28 10:57:05 rivo ntpd[4188]: Soliciting pool server 213.154.236.182 Dec 28 10:57:05 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 10:57:05 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 28 10:57:05 rivo systemd[1]: Stopped go-librespot Daemon. Dec 28 10:57:05 rivo systemd[1]: Started go-librespot Daemon. Dec 28 10:57:05 rivo go-librespot[4190]: go-librespot daemon starting... Dec 28 10:57:05 rivo go-librespot[4190]: time="2025-12-28T10:57:05+01:00" level=info msg="running go-librespot 0.4.0" Dec 28 10:57:05 rivo go-librespot[4190]: time="2025-12-28T10:57:05+01:00" level=debug msg="app state loaded" Dec 28 10:57:05 rivo go-librespot[4190]: time="2025-12-28T10:57:05+01:00" level=debug msg="stored credentials not found" Dec 28 10:57:05 rivo go-librespot[4190]: time="2025-12-28T10:57:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 10:57:05 rivo go-librespot[4190]: time="2025-12-28T10:57:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 28 10:57:05 rivo go-librespot[4190]: time="2025-12-28T10:57:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 28 10:57:05 rivo go-librespot[4190]: time="2025-12-28T10:57:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 28 10:57:05 rivo go-librespot[4190]: time="2025-12-28T10:57:05+01:00" level=info msg="zeroconf server listening on port 36777" Dec 28 10:57:06 rivo systemd[1]: Started Samba NMB Daemon. Dec 28 10:57:06 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. Dec 28 10:57:06 rivo nmbd[3046]: [2025/12/28 10:57:06.037378, 0] ../lib/util/become_daemon.c:138(daemon_ready) Dec 28 10:57:06 rivo nmbd[3046]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Dec 28 10:57:06 rivo systemd[1]: Starting Samba Winbind Daemon... Dec 28 10:57:06 rivo ntpd[4188]: Soliciting pool server 185.51.192.63 Dec 28 10:57:06 rivo ntpd[4188]: Soliciting pool server 172.233.59.169 Dec 28 10:57:06 rivo volumio[3271]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 28 10:57:06 rivo volumio[3271]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 28 10:57:06 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 28 10:57:06 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 28 10:57:06 rivo volumio[3271]: info: Starting MyVolumio Remote Streaming Endpoints Dec 28 10:57:06 rivo volumio[3271]: info: MyVolumio login type: Token Dec 28 10:57:06 rivo volumio[3271]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 28 10:57:06 rivo volumio[3271]: error: [MyVolumio PluginManager] Could not read package.json file: Error: /myvolumio/plugins/music_service/streaming_services//package.json: ENOENT: no such file or directory, open '/myvolumio/plugins/music_service/streaming_services//package.json' Dec 28 10:57:06 rivo volumio[3271]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 28 10:57:06 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 28 10:57:06 rivo winbindd[4199]: [2025/12/28 10:57:06.441522, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Dec 28 10:57:06 rivo winbindd[4199]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Dec 28 10:57:06 rivo winbindd[4199]: [2025/12/28 10:57:06.454134, 0] ../lib/util/become_daemon.c:138(daemon_ready) Dec 28 10:57:06 rivo winbindd[4199]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Dec 28 10:57:06 rivo systemd[1]: Started Samba Winbind Daemon. Dec 28 10:57:06 rivo systemd[1]: Starting Samba SMB Daemon... Dec 28 10:57:06 rivo volumio[3271]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 28 10:57:06 rivo volumio[3271]: info: Reporting MCU Network Status: 1 Dec 28 10:57:06 rivo volumio[3271]: info: Volumio Network Manager: Network status updated: 1 Dec 28 10:57:06 rivo volumio[3271]: error: MyVolumio Custom Token format not valid, refreshing it Dec 28 10:57:06 rivo volumio[3271]: info: Received Get System Info Dec 28 10:57:06 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 28 10:57:06 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 28 10:57:06 rivo volumio[3271]: info: Discovery: Getting this device information Dec 28 10:57:06 rivo volumio[3271]: info: CoreCommandRouter::volumioGetState Dec 28 10:57:06 rivo volumio[3271]: info: CorePlayQueue::getTrack 0 Dec 28 10:57:06 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 28 10:57:06 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 28 10:57:06 rivo volumio[3271]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 28 10:57:06 rivo volumio5-onboarding[3786]: time=2025-12-28T10:57:06.696+01:00 level=INFO msg="BLE descriptor updated" deviceId=62d8aee608042b2e70e8dba82c16ab02 deviceName=Rivo deviceModel=0x2426348 Dec 28 10:57:06 rivo volumio5-onboarding[3786]: time=2025-12-28T10:57:06.700+01:00 level=INFO msg="mDNS descriptor updated" deviceId=62d8aee608042b2e70e8dba82c16ab02 deviceName=Rivo deviceModel=0x2426348 Dec 28 10:57:07 rivo smbd[4210]: [2025/12/28 10:57:07.055097, 0] ../lib/util/become_daemon.c:138(daemon_ready) Dec 28 10:57:07 rivo smbd[4210]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Dec 28 10:57:07 rivo systemd[1]: Started Samba SMB Daemon. Dec 28 10:57:07 rivo ntpd[4188]: Soliciting pool server 178.239.19.62 Dec 28 10:57:07 rivo ntpd[4188]: Soliciting pool server 164.92.156.55 Dec 28 10:57:07 rivo ntpd[4188]: Soliciting pool server 162.159.200.1 Dec 28 10:57:07 rivo volumio[3271]: info: MyVolumio login type: Token Dec 28 10:57:07 rivo volumio[3271]: info: Initializing connection to go-librespot Websocket Dec 28 10:57:07 rivo go-librespot[4190]: time="2025-12-28T10:57:07+01:00" level=debug msg="new websocket client" Dec 28 10:57:07 rivo volumio[3271]: info: Connection to go-librespot Websocket established Dec 28 10:57:07 rivo volumio[3271]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 28 10:57:08 rivo volumio[3271]: info: MyVolumio token set successfully Dec 28 10:57:08 rivo volumio[3271]: info: MYVOLUMIO: Adding device Dec 28 10:57:08 rivo volumio[3271]: info: MYVOLUMIO: Evaluating Server Dec 28 10:57:08 rivo ntpd[4188]: Soliciting pool server 185.51.192.61 Dec 28 10:57:08 rivo ntpd[4188]: Soliciting pool server 103.204.195.5 Dec 28 10:57:08 rivo ntpd[4188]: Soliciting pool server 80.60.67.39 Dec 28 10:57:08 rivo ntpd[4188]: Soliciting pool server 178.239.19.58 Dec 28 10:57:08 rivo volumio-time-update[2843]: volumio-time-update-util: Fetching time from Volumio... Dec 28 10:57:08 rivo volumio-time-update[2843]: volumio-time-update-util: Setting system time to: 2025-12-28 10:57:07 Dec 28 10:57:08 rivo sudo[4250]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-12-28 10:57:07 Dec 28 10:57:08 rivo sudo[4250]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:57:08 rivo dbus-daemon[2834]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.47' (uid=0 pid=4252 comm="timedatectl set-time 2025-12-28 10:57:07 " label="kernel") Dec 28 10:57:08 rivo systemd[1]: Starting Time & Date Service... Dec 28 10:57:08 rivo dbus-daemon[2834]: [system] Successfully activated service 'org.freedesktop.timedate1' Dec 28 10:57:08 rivo systemd[1]: Started Time & Date Service. Dec 28 10:57:07 rivo systemd-timedated[4255]: Changed local time to Sun Dec 28 10:57:07 2025 Dec 28 10:57:07 rivo systemd[1]: Started Volumio Time Update Utility. Dec 28 10:57:07 rivo volumio-time-update[2843]: volumio-time-update-util: System time updated successfully. Dec 28 10:57:07 rivo sudo[4250]: pam_unix(sudo:session): session closed for user root Dec 28 10:57:07 rivo systemd[1]: Reached target Multi-User System. Dec 28 10:57:07 rivo systemd[1]: Reached target Graphical Interface. Dec 28 10:57:07 rivo systemd[1]: Starting Update UTMP about System Runlevel Changes... Dec 28 10:57:07 rivo volumio[3271]: info: MyVolumio Plan changed: premium Dec 28 10:57:07 rivo volumio[3271]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 28 10:57:07 rivo volumio[3271]: info: Removing browser output: myVolumio user plan is not superstar Dec 28 10:57:07 rivo volumio[3271]: info: Removing audio output: Dec 28 10:57:07 rivo volumio[3271]: info: MYVOLUMIO: Adding device Dec 28 10:57:07 rivo volumio[3271]: info: MYVOLUMIO: Evaluating Server Dec 28 10:57:07 rivo systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Dec 28 10:57:07 rivo systemd[1]: Started Update UTMP about System Runlevel Changes. Dec 28 10:57:07 rivo systemd[1]: Startup finished in 12.945s (kernel) + 1min 20.736s (userspace) = 1min 33.682s. Dec 28 10:57:07 rivo volumio[3271]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 28 10:57:07 rivo volumio[3271]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 28 10:57:07 rivo volumio[3271]: error: Failed to ping endpoint us2.myvolumio.org : unknown error Dec 28 10:57:07 rivo volumio[3271]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 28 10:57:07 rivo volumio[3271]: Error: Unable to resolve or reject the same promise twice Dec 28 10:57:07 rivo volumio[3271]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Dec 28 10:57:07 rivo volumio[3271]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32367) Dec 28 10:57:07 rivo volumio[3271]: at Socket.emit (events.js:400:28) Dec 28 10:57:07 rivo volumio[3271]: at addChunk (internal/streams/readable.js:293:12) Dec 28 10:57:07 rivo volumio[3271]: at readableAddChunk (internal/streams/readable.js:267:9) Dec 28 10:57:07 rivo volumio[3271]: at Socket.Readable.push (internal/streams/readable.js:206:10) Dec 28 10:57:07 rivo volumio[3271]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) Dec 28 10:57:07 rivo volumio[3271]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 28 10:57:07 rivo ntpd[4188]: Soliciting pool server 185.51.192.61 Dec 28 10:57:07 rivo sudo[4287]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-28 10:56 Dec 28 10:57:07 rivo sudo[4287]: 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="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="2f25e1a98e53e2dbc4f3878604e250b0379f3ea4" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 07:07:40 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="90457dc663650a5d2f936402ef6c7dc1"