-- Logs begin at Fri 2025-12-19 12:58:42 CET, end at Sun 2026-01-11 16:37:09 CET. -- Jan 11 16:36:19 rivo systemd-timedated[3345]: Changed local time to Sun Jan 11 16:36:19 2026 Jan 11 16:36:19 rivo sudo[3343]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:19 rivo volumio-time-update[2825]: volumio-time-update-util: System time updated successfully. Jan 11 16:36:19 rivo systemd[1]: Started Volumio Time Update Utility. Jan 11 16:36:19 rivo systemd[1]: Starting Daily man-db regeneration... Jan 11 16:36:19 rivo systemd[1]: Starting Daily apt download activities... Jan 11 16:36:19 rivo systemd[1]: man-db.service: Succeeded. Jan 11 16:36:19 rivo systemd[1]: Started Daily man-db regeneration. Jan 11 16:36:19 rivo wireless.js[2826]: trying... Jan 11 16:36:19 rivo sudo[3364]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 16:36:19 rivo sudo[3364]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:19 rivo sudo[3364]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:19 rivo systemd[1]: systemd-rfkill.service: Succeeded. Jan 11 16:36:19 rivo ntpd[3310]: Soliciting pool server 185.19.184.35 Jan 11 16:36:20 rivo wireless.js[2826]: trying... Jan 11 16:36:20 rivo sudo[3374]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 16:36:20 rivo sudo[3374]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:20 rivo sudo[3374]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:20 rivo ntpd[3310]: Soliciting pool server 162.159.200.1 Jan 11 16:36:21 rivo systemd[1]: apt-daily.service: Succeeded. Jan 11 16:36:21 rivo systemd[1]: Started Daily apt download activities. Jan 11 16:36:21 rivo systemd[1]: Starting Daily apt upgrade and clean activities... Jan 11 16:36:21 rivo wireless.js[2826]: trying... Jan 11 16:36:21 rivo sudo[3425]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 16:36:21 rivo sudo[3425]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:21 rivo sudo[3425]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:21 rivo dhcpcd[3311]: wlan0: leased 192.168.1.8 for 86400 seconds Jan 11 16:36:21 rivo avahi-daemon[2817]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.8. Jan 11 16:36:21 rivo dhcpcd[3311]: wlan0: adding route to 192.168.1.0/24 Jan 11 16:36:21 rivo dhcpcd[3311]: wlan0: adding default route via 192.168.1.1 Jan 11 16:36:21 rivo avahi-daemon[2817]: New relevant interface wlan0.IPv4 for mDNS. Jan 11 16:36:21 rivo avahi-daemon[2817]: Registering new address record for 192.168.1.8 on wlan0.IPv4. Jan 11 16:36:21 rivo ntpd[3310]: Soliciting pool server 172.232.208.229 Jan 11 16:36:21 rivo ntpd[3310]: ntpd exiting on signal 15 (Terminated) Jan 11 16:36:21 rivo ntpd[3310]: 172.232.209.103 local addr 192.168.1.92 -> Jan 11 16:36:21 rivo systemd[1]: Stopping Network Time Service... Jan 11 16:36:21 rivo ntpd[3310]: 185.157.229.254 local addr 192.168.1.92 -> Jan 11 16:36:21 rivo ntpd[3310]: 212.6.50.243 local addr 192.168.1.92 -> Jan 11 16:36:21 rivo ntpd[3310]: 95.110.254.234 local addr 192.168.1.92 -> Jan 11 16:36:21 rivo ntpd[3310]: 80.211.238.32 local addr 192.168.1.92 -> Jan 11 16:36:21 rivo ntpd[3310]: 37.247.53.178 local addr 192.168.1.92 -> Jan 11 16:36:21 rivo ntpd[3310]: 89.46.74.148 local addr 192.168.1.92 -> Jan 11 16:36:21 rivo ntpd[3310]: 188.217.191.74 local addr 192.168.1.92 -> Jan 11 16:36:21 rivo ntpd[3310]: 185.19.184.35 local addr 192.168.1.92 -> Jan 11 16:36:21 rivo ntpd[3310]: 162.159.200.1 local addr 192.168.1.92 -> Jan 11 16:36:21 rivo ntpd[3310]: 172.232.208.229 local addr 192.168.1.92 -> Jan 11 16:36:21 rivo systemd[1]: ntp.service: Succeeded. Jan 11 16:36:21 rivo systemd[1]: Stopped Network Time Service. Jan 11 16:36:21 rivo systemd[1]: Starting Network Time Service... Jan 11 16:36:21 rivo ntpd[3462]: ntpd 4.2.8p12@1.3728-o (1): Starting Jan 11 16:36:21 rivo ntpd[3462]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Jan 11 16:36:21 rivo systemd[1]: Started Network Time Service. Jan 11 16:36:21 rivo ntpd[3468]: proto: precision = 1.291 usec (-19) Jan 11 16:36:21 rivo ntpd[3468]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jan 11 16:36:21 rivo ntpd[3468]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Jan 11 16:36:21 rivo ntpd[3468]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 1111 days ago Jan 11 16:36:21 rivo ntpd[3468]: Listen and drop on 0 v6wildcard [::]:123 Jan 11 16:36:21 rivo ntpd[3468]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jan 11 16:36:21 rivo ntpd[3468]: Listen normally on 2 lo 127.0.0.1:123 Jan 11 16:36:21 rivo ntpd[3468]: Listen normally on 3 eth0 192.168.1.92:123 Jan 11 16:36:21 rivo ntpd[3468]: Listen normally on 4 wlan0 192.168.1.8:123 Jan 11 16:36:21 rivo ntpd[3468]: Listening on routing socket on fd #21 for interface updates Jan 11 16:36:21 rivo ntpd[3468]: kernel reports TIME_ERROR: 0x4041: Clock Unsynchronized Jan 11 16:36:21 rivo ntpd[3468]: kernel reports TIME_ERROR: 0x4041: Clock Unsynchronized Jan 11 16:36:22 rivo wireless.js[2826]: trying... Jan 11 16:36:22 rivo sudo[3471]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 16:36:22 rivo sudo[3471]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:22 rivo sudo[3471]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:22 rivo wireless.js[2826]: Connected to: ----TIM-63749442 Jan 11 16:36:22 rivo wireless.js[2826]: ---- Jan 11 16:36:22 rivo sudo[3476]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 16:36:22 rivo sudo[3476]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:22 rivo sudo[3476]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:22 rivo wireless.js[2826]: ... joined AP, wlan0 IPv4 is 192.168.1.8, ipV6 is undefined Jan 11 16:36:22 rivo wireless.js[2826]: It's done! AP Jan 11 16:36:22 rivo systemd[1]: Started Wireless Services. Jan 11 16:36:22 rivo systemd[1]: Started Volumio Backend Module. Jan 11 16:36:22 rivo systemd[1]: Started Volumio Cpu Tweaker. Jan 11 16:36:22 rivo systemd[1]: Started Start Volumio Kiosk. Jan 11 16:36:22 rivo systemd[1]: Reached target Multi-User System. Jan 11 16:36:22 rivo systemd[1]: Reached target Graphical Interface. Jan 11 16:36:22 rivo systemd[1]: Starting Update UTMP about System Runlevel Changes... Jan 11 16:36:22 rivo startkiosk.sh[3490]: Starting Volumio Kiosk with arguments for cursor display Jan 11 16:36:22 rivo systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jan 11 16:36:22 rivo systemd[1]: Started Update UTMP about System Runlevel Changes. Jan 11 16:36:22 rivo volumio-cpu-tweak[3489]: Setting RT Priority for mpd Jan 11 16:36:22 rivo volumio-cpu-tweak[3489]: chrt: cannot obtain the list of tasks: No such file or directory Jan 11 16:36:22 rivo volumio-cpu-tweak[3489]: Setting MPD Affinity Jan 11 16:36:22 rivo volumio-cpu-tweak[3489]: pid 3's current affinity mask: 1 Jan 11 16:36:22 rivo volumio-cpu-tweak[3489]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Jan 11 16:36:22 rivo volumio-cpu-tweak[3489]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Jan 11 16:36:22 rivo systemd[1]: volumio_cpu_tweak.service: Succeeded. Jan 11 16:36:22 rivo ntpd[3468]: Soliciting pool server 185.157.229.254 Jan 11 16:36:22 rivo startkiosk.sh[3490]: X.Org X Server 1.20.4 Jan 11 16:36:22 rivo startkiosk.sh[3490]: X Protocol Version 11, Revision 0 Jan 11 16:36:22 rivo startkiosk.sh[3490]: Build Operating System: Linux 4.19.0-18-armmp-lpae armv7l Debian Jan 11 16:36:22 rivo startkiosk.sh[3490]: Current Operating System: Linux rivo 4.9.241 #4 SMP PREEMPT Wed Jun 4 18:07:40 CEST 2025 aarch64 Jan 11 16:36:22 rivo startkiosk.sh[3490]: Kernel command line: imgpart=UUID=a32a76bf-19ea-4c30-8d09-32113f0a83fc imgfile=/volumio_current.sqsh bootpart=UUID=0051-8191 datapart=UUID=7901eaf7-90a3-4a8e-ace2-753d80142673 uuidconfig=env.system.txt hwdevice=VIMX 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:21:11:01 fan=auto hwver=Unknow coherent_pool=2M quiet loglevel=0 splash plymouth.ignore-serial-consoles initramfs.clear splash bootdelay=7 Jan 11 16:36:22 rivo startkiosk.sh[3490]: Build Date: 18 December 2021 09:05:36AM Jan 11 16:36:22 rivo startkiosk.sh[3490]: xorg-server 2:1.20.4-1+deb10u4 (https://www.debian.org/support) Jan 11 16:36:22 rivo startkiosk.sh[3490]: Current version of pixman: 0.36.0 Jan 11 16:36:22 rivo startkiosk.sh[3490]: Before reporting problems, check http://wiki.x.org Jan 11 16:36:22 rivo startkiosk.sh[3490]: to make sure that you have the latest version. Jan 11 16:36:22 rivo startkiosk.sh[3490]: Markers: (--) probed, (**) from config file, (==) default setting, Jan 11 16:36:22 rivo startkiosk.sh[3490]: (++) from command line, (!!) notice, (II) informational, Jan 11 16:36:22 rivo startkiosk.sh[3490]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Jan 11 16:36:22 rivo startkiosk.sh[3490]: (==) Log file: "/var/log/Xorg.0.log", Time: Sun Jan 11 16:36:22 2026 Jan 11 16:36:22 rivo startkiosk.sh[3490]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Jan 11 16:36:22 rivo systemd[1]: apt-daily-upgrade.service: Succeeded. Jan 11 16:36:22 rivo systemd[1]: Started Daily apt upgrade and clean activities. Jan 11 16:36:22 rivo systemd[1]: Startup finished in 12.873s (kernel) + 23.659s (userspace) = 36.533s. Jan 11 16:36:22 rivo kernel: fb: osd[0] canvas.idx =0x40 Jan 11 16:36:22 rivo kernel: fb: osd[0] canvas.addr=0x70000000 Jan 11 16:36:22 rivo kernel: fb: osd[0] canvas.width=7680 Jan 11 16:36:22 rivo kernel: fb: osd[0] canvas.height=1080 Jan 11 16:36:22 rivo kernel: fb: osd[0] frame.width=1920 Jan 11 16:36:22 rivo kernel: fb: osd[0] frame.height=1080 Jan 11 16:36:22 rivo kernel: fb: osd[0] out_addr_id =0x1 Jan 11 16:36:22 rivo kernel: fb: osd[0] enable: 0 (Xorg) Jan 11 16:36:23 rivo ntpd[3468]: Soliciting pool server 172.232.209.103 Jan 11 16:36:23 rivo ntpd[3468]: Soliciting pool server 162.159.200.123 Jan 11 16:36:24 rivo kernel: fb: osd[0] enable: 1 (Xorg) Jan 11 16:36:24 rivo ntpd[3468]: Soliciting pool server 162.159.200.1 Jan 11 16:36:24 rivo ntpd[3468]: Soliciting pool server 80.211.238.32 Jan 11 16:36:24 rivo ntpd[3468]: Soliciting pool server 93.94.88.50 Jan 11 16:36:25 rivo kernel: fb: osd[0] enable: 1 (Xorg) Jan 11 16:36:25 rivo volumio[3488]: info: ------------------------------------------- Jan 11 16:36:25 rivo volumio[3488]: info: ----- Volumio3 ---- Jan 11 16:36:25 rivo volumio[3488]: info: ------------------------------------------- Jan 11 16:36:25 rivo volumio[3488]: info: ----- System startup ---- Jan 11 16:36:25 rivo volumio[3488]: info: ------------------------------------------- Jan 11 16:36:25 rivo ntpd[3468]: Soliciting pool server 5.249.149.252 Jan 11 16:36:25 rivo ntpd[3468]: Soliciting pool server 95.110.254.234 Jan 11 16:36:25 rivo ntpd[3468]: Soliciting pool server 89.46.74.148 Jan 11 16:36:25 rivo ntpd[3468]: Soliciting pool server 212.45.144.206 Jan 11 16:36:26 rivo ntpd[3468]: Soliciting pool server 151.22.209.90 Jan 11 16:36:26 rivo ntpd[3468]: Soliciting pool server 85.199.214.99 Jan 11 16:36:26 rivo ntpd[3468]: Soliciting pool server 93.94.88.51 Jan 11 16:36:26 rivo ntpd[3468]: Soliciting pool server 172.232.208.229 Jan 11 16:36:27 rivo volumio[3488]: info: MYVOLUMIO Environment detected Jan 11 16:36:27 rivo volumio[3488]: info: Plugin folders cleanup Jan 11 16:36:27 rivo volumio[3488]: info: Scanning into folder /volumio/app/plugins/ Jan 11 16:36:27 rivo volumio[3488]: info: Scanning category audio_interface Jan 11 16:36:27 rivo volumio[3488]: info: Scanning category miscellanea Jan 11 16:36:27 rivo volumio[3488]: info: Scanning category music_service Jan 11 16:36:27 rivo volumio[3488]: info: Scanning category plugins.json Jan 11 16:36:27 rivo volumio[3488]: info: Scanning category system_controller Jan 11 16:36:27 rivo volumio[3488]: info: Scanning category user_interface Jan 11 16:36:27 rivo volumio[3488]: info: Scanning into folder /data/plugins/ Jan 11 16:36:27 rivo volumio[3488]: info: Scanning category audio_interface Jan 11 16:36:27 rivo volumio[3488]: info: Scanning category music_service Jan 11 16:36:27 rivo volumio[3488]: info: Plugin folders cleanup completed Jan 11 16:36:27 rivo volumio[3488]: info: ------------------------------------------- Jan 11 16:36:27 rivo volumio[3488]: info: ----- Core plugins startup ---- Jan 11 16:36:27 rivo volumio[3488]: info: ------------------------------------------- Jan 11 16:36:27 rivo volumio[3488]: info: Loading plugins from folder /volumio/app/plugins/ Jan 11 16:36:27 rivo volumio[3488]: info: Adding plugin bluetooth to MyMusic Plugins Jan 11 16:36:27 rivo volumio[3488]: info: Adding plugin multiroom to MyMusic Plugins Jan 11 16:36:27 rivo volumio[3488]: info: Adding plugin upnp to MyMusic Plugins Jan 11 16:36:27 rivo volumio[3488]: info: Adding plugin metavolumio to MyMusic Plugins Jan 11 16:36:27 rivo volumio[3488]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 11 16:36:27 rivo volumio[3488]: info: Adding plugin cd_controller to MyMusic Plugins Jan 11 16:36:27 rivo volumio[3488]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 11 16:36:27 rivo volumio[3488]: info: Adding plugin raat to MyMusic Plugins Jan 11 16:36:27 rivo volumio[3488]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 11 16:36:27 rivo volumio[3488]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 11 16:36:27 rivo volumio[3488]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 11 16:36:27 rivo volumio[3488]: info: Loading plugins from folder /data/plugins/ Jan 11 16:36:27 rivo volumio[3488]: info: Loading plugin "system"... Jan 11 16:36:27 rivo volumio[3488]: info: Loading plugin "appearance"... Jan 11 16:36:27 rivo ntpd[3468]: Soliciting pool server 37.247.53.178 Jan 11 16:36:27 rivo ntpd[3468]: Soliciting pool server 2a00:6d41:10:1194::7 Jan 11 16:36:28 rivo volumio-remote-updater[2828]: [2026-01-11 16:36:28] [connect] Successful connection Jan 11 16:36:29 rivo volumio[3488]: info: Loading plugin "network"... Jan 11 16:36:29 rivo volumio[3488]: info: Refreshing Cached IP Addresses Jan 11 16:36:29 rivo sudo[3619]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 16:36:29 rivo sudo[3619]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:29 rivo sudo[3621]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 16:36:29 rivo sudo[3621]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:29 rivo sudo[3621]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:29 rivo sudo[3619]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:29 rivo volumio[3488]: info: Loading plugin "services"... Jan 11 16:36:29 rivo volumio[3488]: info: Loading plugin "volumio5onboarding"... Jan 11 16:36:29 rivo sudo[3635]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 11 16:36:29 rivo sudo[3635]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:29 rivo volumio[3488]: info: Loading plugin "alsa_controller"... Jan 11 16:36:29 rivo kernel: wl_escan_set_scan: ioctl_ver=2 Jan 11 16:36:29 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04f6da000 drv_status 0x0 e_type 69 e_states 8 Jan 11 16:36:29 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04f6da000 drv_status 0x0 e_type 69 e_states 8 Jan 11 16:36:29 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04f6da000 drv_status 0x0 e_type 69 e_states 8 Jan 11 16:36:29 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04f6da000 drv_status 0x0 e_type 69 e_states 8 Jan 11 16:36:29 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 16:36:29 rivo volumio[3488]: info: Loading plugin "wizard"... Jan 11 16:36:29 rivo volumio[3488]: info: Loading plugin "networkfs"... Jan 11 16:36:29 rivo volumio[3488]: info: Starting Udev Watcher for removable devices Jan 11 16:36:29 rivo volumio[3488]: info: Ignoring mount for partition: BOOT Jan 11 16:36:29 rivo volumio[3488]: info: Ignoring mount for partition: volumio Jan 11 16:36:29 rivo volumio[3488]: info: Ignoring mount for partition: volumio_data Jan 11 16:36:29 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 16:36:29 rivo volumio[3488]: info: Loading plugin "volumio_command_line_client"... Jan 11 16:36:29 rivo volumio[3488]: info: Loading plugin "upnp"... Jan 11 16:36:29 rivo volumio[3488]: info: [1768145789434] Starting Upmpd Daemon Jan 11 16:36:29 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 16:36:29 rivo volumio[3488]: info: Loading plugin "my_music"... Jan 11 16:36:29 rivo volumio[3488]: info: Loading plugin "mpd"... Jan 11 16:36:29 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04f6da000 drv_status 0x0 e_type 69 e_states 8 Jan 11 16:36:29 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04f6da000 drv_status 0x0 e_type 69 e_states 8 Jan 11 16:36:29 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04f6da000 drv_status 0x0 e_type 69 e_states 8 Jan 11 16:36:30 rivo volumio[3488]: info: Loading plugin "upnp_browser"... Jan 11 16:36:30 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04f6da000 drv_status 0x0 e_type 69 e_states 8 Jan 11 16:36:30 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04f6da000 drv_status 0x0 e_type 69 e_states 8 Jan 11 16:36:30 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04f6da000 drv_status 0x0 e_type 69 e_states 8 Jan 11 16:36:30 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04f6da000 drv_status 0x0 e_type 69 e_states 8 Jan 11 16:36:30 rivo volumio[3488]: info: Starting UPNP Browser Jan 11 16:36:30 rivo volumio[3488]: info: Loading plugin "bluetooth"... Jan 11 16:36:30 rivo volumio[3488]: info: [1768145790839] Starting BluetoothController Jan 11 16:36:31 rivo volumio[3488]: info: Loading plugin "alarm-clock"... Jan 11 16:36:31 rivo volumio[3488]: info: Loading plugin "manifestui"... Jan 11 16:36:31 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04f6da000 drv_status 0x0 e_type 69 e_states 8 Jan 11 16:36:31 rivo volumio[3488]: info: Loading plugin "metavolumio"... Jan 11 16:36:31 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04f6da000 drv_status 0x0 e_type 69 e_states 8 Jan 11 16:36:31 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04f6da000 drv_status 0x0 e_type 69 e_states 8 Jan 11 16:36:32 rivo ntpd[3468]: receive: Unexpected origin timestamp 0xed0e41ff.d4f08086 does not match aorg 0000000000.00000000 from server@89.46.74.148 xmt 0xed0e4200.e6db800a Jan 11 16:36:32 rivo ntpd[3468]: receive: Unexpected origin timestamp 0xed0e41ff.d4f30788 does not match aorg 0000000000.00000000 from server@93.94.88.50 xmt 0xed0e4200.e80a39a5 Jan 11 16:36:33 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04f6da000 drv_status 0x0 e_type 69 e_states 8 Jan 11 16:36:33 rivo systemd[1]: systemd-fsckd.service: Succeeded. Jan 11 16:36:33 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04f6da000 drv_status 0x0 e_type 69 e_states 8 Jan 11 16:36:34 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04f6da000 drv_status 0x0 e_type 69 e_states 0 Jan 11 16:36:34 rivo sudo[3635]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:34 rivo volumio[3488]: info: Loading plugin "airplay_emulation"... Jan 11 16:36:34 rivo volumio[3488]: info: Starting Shairport Sync Jan 11 16:36:34 rivo volumio[3488]: info: Loading plugin "cd_controller"... Jan 11 16:36:35 rivo volumio[3488]: info: Loading plugin "last_100"... Jan 11 16:36:35 rivo volumio[3488]: info: Loading plugin "qobuzconnect"... Jan 11 16:36:35 rivo volumio[3488]: info: Loading plugin "raat"... Jan 11 16:36:35 rivo volumio[3488]: info: RAAT Plugin loaded Jan 11 16:36:35 rivo volumio[3488]: info: Adding restartRAATSocket REST API Endpoint Jan 11 16:36:35 rivo volumio[3488]: info: Adding restartRAATSocket REST Endpoint for plugin: music_service/raat Jan 11 16:36:35 rivo volumio[3488]: info: Loading plugin "streaming_services"... Jan 11 16:36:37 rivo volumio[3488]: info: Starting Streaming Service Transparent Proxy Jan 11 16:36:38 rivo volumio[3488]: info: Loading plugin "tidalconnect"... Jan 11 16:36:38 rivo volumio[3488]: info: Loading plugin "webradio"... Jan 11 16:36:38 rivo volumio[3488]: info: Loading plugin "i2s_dacs"... Jan 11 16:36:38 rivo volumio[3488]: info: I2S DAC not set, start Auto-detection Jan 11 16:36:38 rivo volumio[3488]: info: Loading plugin "volumiodiscovery"... Jan 11 16:36:38 rivo volumio[3488]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 16:36:38 rivo volumio[3488]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 16:36:38 rivo node[3488]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 16:36:38 rivo volumio[3488]: *** WARNING *** For more information see Jan 11 16:36:38 rivo volumio[3488]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 16:36:38 rivo volumio[3488]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 16:36:38 rivo volumio[3488]: *** WARNING *** For more information see Jan 11 16:36:38 rivo node[3488]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 16:36:38 rivo node[3488]: *** WARNING *** For more information see Jan 11 16:36:38 rivo node[3488]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 16:36:38 rivo node[3488]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 16:36:38 rivo node[3488]: *** WARNING *** For more information see Jan 11 16:36:38 rivo volumio[3488]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 11 16:36:38 rivo volumio[3488]: info: Discovery: Started advertising with name: Rivo Jan 11 16:36:38 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 16:36:38 rivo volumio[3488]: info: Loading plugin "spop"... Jan 11 16:36:39 rivo volumio[3488]: STREAMING PROXY: Starting server on port 3245 Jan 11 16:36:39 rivo volumio[3488]: Node JS runtime: 14 Jan 11 16:36:41 rivo volumio[3488]: info: Loading plugin "multiroom"... Jan 11 16:36:43 rivo volumio[3488]: info: Applying required configuration parameters for plugin multiroom Jan 11 16:36:43 rivo sudo[3844]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Jan 11 16:36:43 rivo sudo[3844]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:43 rivo sudo[3844]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:43 rivo volumio[3488]: info: MRS: MultiRoom plugin initialized Jan 11 16:36:43 rivo volumio[3488]: info: MRS: STOPPING SNAPCLIENT Jan 11 16:36:43 rivo volumio[3488]: info: MRS: Snap server stop Jan 11 16:36:43 rivo volumio[3488]: info: MRS: STOPPING volumioStreaming Jan 11 16:36:43 rivo sudo[3860]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Jan 11 16:36:43 rivo sudo[3860]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:43 rivo sudo[3862]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Jan 11 16:36:43 rivo sudo[3862]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:43 rivo sudo[3865]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Jan 11 16:36:43 rivo sudo[3865]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:43 rivo volumio[3488]: info: Loading plugin "outputs"... Jan 11 16:36:43 rivo sudo[3860]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:43 rivo volumio[3488]: info: Loading plugin "albumart"... Jan 11 16:36:43 rivo sudo[3869]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Jan 11 16:36:43 rivo sudo[3869]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:43 rivo sudo[3869]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:43 rivo volumio[3488]: info: Plugin example_plugin is not enabled Jan 11 16:36:43 rivo volumio[3488]: info: Loading plugin "hi_res_audio"... Jan 11 16:36:43 rivo sudo[3862]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:43 rivo sudo[3865]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:44 rivo volumio[3488]: Forking 3 albumart workers Jan 11 16:36:44 rivo volumio-remote-updater[2828]: [2026-01-11 16:36:44] [connect] Successful connection Jan 11 16:36:45 rivo volumio[3488]: Starting albumart workers Jan 11 16:36:45 rivo volumio[3488]: Starting albumart workers Jan 11 16:36:45 rivo volumio[3488]: Starting albumart workers Jan 11 16:36:45 rivo volumio[3488]: info: Applying required configuration parameters for plugin hi_res_audio Jan 11 16:36:45 rivo volumio[3488]: info: Loading plugin "inputs"... Jan 11 16:36:46 rivo volumio[3488]: info: Loading plugin "qobuz"... Jan 11 16:36:48 rivo volumio[3488]: info: Loading plugin "smart_inputs"... Jan 11 16:36:48 rivo volumio[3488]: info: Loading plugin "tidal"... Jan 11 16:36:49 rivo kernel: fb: mem_free_work, free memory: addr:800000 Jan 11 16:36:50 rivo systemd[1]: systemd-timedated.service: Succeeded. Jan 11 16:36:50 rivo volumio[3488]: info: Loading plugin "rivocontrol"... Jan 11 16:36:50 rivo volumio[3488]: info: Adding this device properties Jan 11 16:36:50 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , setThisDeviceVolumioProperties Jan 11 16:36:50 rivo volumio[3488]: info: Setting Additional Device Volumio Properties: [object Object] Jan 11 16:36:50 rivo volumio[3488]: info: Loading plugin "updater_comm"... Jan 11 16:36:51 rivo volumio[3488]: info: Loading plugin "cec_controller"... Jan 11 16:36:51 rivo volumio[3488]: info: Applying required configuration parameters for plugin cec_controller Jan 11 16:36:51 rivo volumio[3488]: info: Plugin mpdemulation is not enabled Jan 11 16:36:51 rivo volumio[3488]: info: Loading plugin "rest_api"... Jan 11 16:36:51 rivo volumio[3488]: info: Loading plugin "websocket"... Jan 11 16:36:51 rivo volumio[3488]: info: Starting Socket.io Server version 2.3.0 Jan 11 16:36:51 rivo volumio[3488]: info: Loading plugin "fusiondsp"... Jan 11 16:36:51 rivo volumio[3488]: info: Applying required configuration parameters for plugin fusiondsp Jan 11 16:36:52 rivo volumio[3488]: info: Loading i18n strings for locale it Jan 11 16:36:52 rivo volumio[3488]: Updating browse sources language Jan 11 16:36:52 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 16:36:52 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 16:36:52 rivo volumio[3488]: info: CoreCommandRouter::initPlayerControls Jan 11 16:36:52 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:52 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:52 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:52 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:52 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:52 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:52 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:52 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:52 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 16:36:52 rivo volumio[3488]: Express server listening on port 3000 Jan 11 16:36:52 rivo volumio[3488]: [Metrics] WebUI: 26s 803.03ms Jan 11 16:36:52 rivo volumio[3488]: info: CoreStateMachine::resetVolumioState Jan 11 16:36:52 rivo volumio[3488]: info: CoreStateMachine::getcurrentVolume Jan 11 16:36:52 rivo volumio[3488]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 16:36:52 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 16:36:52 rivo sudo[3953]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 16:36:52 rivo sudo[3953]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:52 rivo sudo[3953]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:52 rivo volumio[3488]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Jan 11 16:36:52 rivo sudo[3958]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 16:36:52 rivo volumio[3488]: info: Completed loading Core Plugins Jan 11 16:36:52 rivo sudo[3958]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:52 rivo volumio[3488]: info: Preparing to generate the ALSA configuration file Jan 11 16:36:52 rivo sudo[3958]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:52 rivo volumio[3488]: info: Volumio Network Manager: Network status updated: 3 Jan 11 16:36:52 rivo volumio[3488]: info: CoreStateMachine::pushState Jan 11 16:36:52 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:36:52 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 16:36:52 rivo volumio[3488]: info: CoreCommandRouter::volumioPushState Jan 11 16:36:52 rivo volumio[3488]: info: CoreStateMachine::updateTrackBlock Jan 11 16:36:52 rivo volumio[3488]: info: CorePlayQueue::getTrackBlock Jan 11 16:36:52 rivo volumio[3488]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 16:36:52 rivo volumio[3488]: info: MRS: Removed streaming files Jan 11 16:36:52 rivo volumio[3488]: info: MRS: volumioStreaming STOPPED Jan 11 16:36:52 rivo volumio[3488]: info: MRS: SNAPSERVER STOPPED Jan 11 16:36:52 rivo volumio[3488]: info: MRS: SNAPCLIENT STOPPED Jan 11 16:36:52 rivo volumio[3488]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Jan 11 16:36:52 rivo volumio[3488]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 11 16:36:52 rivo volumio[3488]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jan 11 16:36:52 rivo volumio[3488]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 11 16:36:52 rivo volumio[3488]: info: Reading ALSA contributions from plugins. Jan 11 16:36:52 rivo volumio[3488]: info: CoreStateMachine::pushState Jan 11 16:36:52 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:36:52 rivo volumio[3488]: info: CoreCommandRouter::volumioPushState Jan 11 16:36:53 rivo volumio[3488]: info: Reloading queue from file Jan 11 16:36:53 rivo volumio[3488]: info: CoreStateMachine::setRepeat false single undefined Jan 11 16:36:53 rivo volumio[3488]: info: CoreStateMachine::pushState Jan 11 16:36:53 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:36:53 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 16:36:53 rivo volumio[3488]: info: CoreCommandRouter::volumioPushState Jan 11 16:36:53 rivo volumio[3488]: info: CoreStateMachine::setRandom null Jan 11 16:36:53 rivo volumio[3488]: info: CoreStateMachine::pushState Jan 11 16:36:53 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:36:53 rivo volumio[3488]: info: CoreCommandRouter::volumioPushState Jan 11 16:36:53 rivo sudo[3975]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 11 16:36:53 rivo sudo[3975]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:53 rivo volumio[3488]: info: Discovery: adding 066a9c23-33f9-49f9-9dda-ea32fceb640e Jan 11 16:36:53 rivo volumio[3488]: info: Discovery: Found device Rivo Jan 11 16:36:53 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:36:53 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:36:53 rivo volumio[3488]: info: MRS: Pushing multiroomSync output for this device Jan 11 16:36:53 rivo volumio[3488]: info: MRS: Pushing multiroomSync output Jan 11 16:36:53 rivo volumio[3488]: info: Adding audio output: Jan 11 16:36:53 rivo volumio[3488]: info: Adding audio output: Jan 11 16:36:53 rivo volumio[3488]: info: Discovery: this is already registered, 066a9c23-33f9-49f9-9dda-ea32fceb640e Jan 11 16:36:53 rivo volumio[3488]: info: Discovery: Found device Rivo Jan 11 16:36:53 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:36:53 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:36:53 rivo volumio[3488]: info: Asound.conf file unchanged, so no further update is needed Jan 11 16:36:53 rivo volumio[3488]: info: Output device has changed, restarting MPD Jan 11 16:36:53 rivo systemd[1]: Started UPnP Renderer front-end to MPD. Jan 11 16:36:53 rivo sudo[3975]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:53 rivo sudo[3987]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 16:36:53 rivo sudo[3987]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:53 rivo sudo[3987]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:53 rivo volumio[3488]: info: Output device has changed, restarting Shairport Sync Jan 11 16:36:53 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:53 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 16:36:53 rivo sudo[3990]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 16:36:53 rivo sudo[3990]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:53 rivo systemd[1]: Listening on mpd.socket. Jan 11 16:36:53 rivo volumio[3488]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 16:36:53 rivo systemd[1]: Starting Music Player Daemon... Jan 11 16:36:53 rivo volumio[3488]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jan 11 16:36:53 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:53 rivo volumio[3488]: info: ___________ START PLUGINS ___________ Jan 11 16:36:53 rivo volumio[3488]: info: ControllerMpd::onStart: Initializing MPD Jan 11 16:36:53 rivo volumio[3488]: info: Creating MPD Configuration file Jan 11 16:36:53 rivo kernel: aml_spdif_open Jan 11 16:36:53 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jan 11 16:36:53 rivo kernel: spdif_a keep clk continuous Jan 11 16:36:53 rivo kernel: aml_spdif_close Jan 11 16:36:53 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jan 11 16:36:53 rivo sudo[3999]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Jan 11 16:36:53 rivo sudo[3999]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:53 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 16:36:53 rivo volumio[3488]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 16:36:53 rivo volumio[3488]: info: [1768145813724] CoreMusicLibrary::Adding element Server multimediali Jan 11 16:36:53 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 16:36:53 rivo systemd[1]: Started Volumio5 Onboarding Server. Jan 11 16:36:53 rivo sudo[3995]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 16:36:53 rivo sudo[3995]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:53 rivo sudo[4004]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 16:36:53 rivo sudo[3999]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:53 rivo sudo[4004]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:53 rivo sudo[3995]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jan 11 16:36:53 rivo sudo[4004]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:53 rivo sudo[3995]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:53 rivo volumio[3488]: info: UPNP Browser: Client initialized successfully Jan 11 16:36:53 rivo sudo[4007]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 16:36:53 rivo sudo[4007]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:53 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 16:36:53 rivo volumio[3488]: info: Adding METAVOLUMIO REST API Endpoints Jan 11 16:36:53 rivo volumio[3488]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Jan 11 16:36:53 rivo volumio[3488]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Jan 11 16:36:53 rivo volumio[3488]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Jan 11 16:36:53 rivo volumio[3488]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Jan 11 16:36:53 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:53 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 16:36:53 rivo systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jan 11 16:36:53 rivo systemd[1]: mpd.service: Succeeded. Jan 11 16:36:53 rivo systemd[1]: Stopped Music Player Daemon. Jan 11 16:36:53 rivo sudo[4015]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Rivo Jan 11 16:36:53 rivo sudo[4015]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:53 rivo systemd[1]: Starting Music Player Daemon... Jan 11 16:36:53 rivo sudo[4015]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:53 rivo volumio[3488]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 16:36:53 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:53 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 16:36:54 rivo volumio[3488]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 16:36:54 rivo volumio[3488]: info: Preparing CD Folders Jan 11 16:36:54 rivo volumio[3488]: info: Adding CD REST API Endpoints Jan 11 16:36:54 rivo volumio[3488]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Jan 11 16:36:54 rivo volumio[3488]: info: Starting UDEV Watcher for CD Jan 11 16:36:54 rivo volumio[3488]: info: Detecting CD presence with UDEV Jan 11 16:36:54 rivo sudo[4018]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 16:36:54 rivo sudo[4018]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:54 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Jan 11 16:36:54 rivo sudo[4018]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jan 11 16:36:54 rivo sudo[4018]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:54 rivo volumio[3488]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 16:36:54 rivo volumio[3488]: info: [1768145814156] CoreMusicLibrary::Adding element Last_100 Jan 11 16:36:54 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 16:36:54 rivo volumio[3488]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Jan 11 16:36:54 rivo volumio[3488]: info: QobuzConnect: Starting Qobuz Connect socket and service Jan 11 16:36:54 rivo volumio[3488]: info: Starting RAAT Plugin Jan 11 16:36:54 rivo volumio5-onboarding[4006]: time=2026-01-11T16:36:54.290+01:00 level=INFO msg="running volumio5-device-gateway" version=5bca5789+CHANGES buildDate=2025-12-11T14:07:23Z Jan 11 16:36:54 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Jan 11 16:36:54 rivo volumio[3488]: info: Additional UI Settings Added for plugin music_service/raat Jan 11 16:36:54 rivo volumio[3488]: info: Registering DSP Elements listener and retrieving current ones Jan 11 16:36:54 rivo volumio[3488]: info: Additional DSP elements updated Jan 11 16:36:54 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:54 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:54 rivo volumio[3488]: info: Updating RAAT Signal Path Jan 11 16:36:54 rivo sudo[4036]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jan 11 16:36:54 rivo sudo[4036]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:54 rivo volumio[3488]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Jan 11 16:36:54 rivo volumio[3488]: info: Streaming services startup Jan 11 16:36:54 rivo volumio[3488]: info: Starting Streaming Daemon Jan 11 16:36:54 rivo sudo[4036]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:54 rivo sudo[4041]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jan 11 16:36:54 rivo sudo[4041]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:54 rivo sudo[4042]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 11 16:36:54 rivo sudo[4042]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:54 rivo sudo[4042]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:54 rivo systemd[1]: Started Volumio Qobuz Connect Service. Jan 11 16:36:54 rivo sudo[4041]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:54 rivo volumio[3488]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 16:36:54 rivo volumio[3488]: info: [1768145814509] CoreMusicLibrary::Adding element Webradio Jan 11 16:36:54 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 16:36:54 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 16:36:54 rivo volumio[3488]: info: Initializing BBC Radios Jan 11 16:36:54 rivo sudo[4052]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jan 11 16:36:54 rivo sudo[4052]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:54 rivo sudo[4052]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:54 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 16:36:54 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 16:36:54 rivo volumio[3488]: info: Creating Spotify config file Jan 11 16:36:54 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:54 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Jan 11 16:36:54 rivo volumio[3488]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jan 11 16:36:54 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:54 rivo volumio[3488]: error: Hi Res Audio Failed Login: Missing Login Data Jan 11 16:36:54 rivo volumio[3488]: info: Adding HIGHRESAUDIO REST API Endpoints Jan 11 16:36:54 rivo volumio[3488]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Jan 11 16:36:54 rivo volumio[3488]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Jan 11 16:36:54 rivo volumio[3488]: info: Initializing Serial Communication on port /dev/ttyS3 Jan 11 16:36:54 rivo volumio[3488]: info: Touch Event Listener Process Starting Jan 11 16:36:54 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 0 to 9600 Jan 11 16:36:54 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 9600 to 9600 Jan 11 16:36:54 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 9600 to 115200 Jan 11 16:36:54 rivo kernel: aml_spdif_open Jan 11 16:36:54 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jan 11 16:36:54 rivo kernel: spdif_a keep clk continuous Jan 11 16:36:54 rivo kernel: aml_spdif_close Jan 11 16:36:54 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jan 11 16:36:54 rivo volumio[3488]: info: Adding inputs REST Endpoints Jan 11 16:36:54 rivo volumio[3488]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Jan 11 16:36:54 rivo volumio[3488]: info: Scanning Audio Inputs Jan 11 16:36:55 rivo sudo[4071]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xinput --test-xi2 --root Jan 11 16:36:55 rivo sudo[4071]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:55 rivo volumio[3488]: info: Checking against Known Cards name Jan 11 16:36:55 rivo volumio[3488]: info: Checking against Known Cards name Jan 11 16:36:55 rivo volumio[3488]: info: Checking against Known Cards name Jan 11 16:36:55 rivo volumio[3488]: info: Checking against Known Cards name Jan 11 16:36:55 rivo volumio[3488]: info: Checking against Known Cards name Jan 11 16:36:55 rivo volumio[3488]: info: Adding Server instance for streaming Jan 11 16:36:55 rivo volumio[3488]: info: Refreshing TIDAL token Jan 11 16:36:55 rivo sudo[4082]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x25 0x0 Jan 11 16:36:55 rivo sudo[4082]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:55 rivo sudo[4082]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:55 rivo sudo[4085]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x28 0x0 Jan 11 16:36:55 rivo sudo[4085]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:55 rivo sudo[4085]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:55 rivo sudo[4088]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x29 0x1 Jan 11 16:36:55 rivo sudo[4088]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:55 rivo sudo[4088]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:55 rivo sudo[4099]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x33 0x1 Jan 11 16:36:55 rivo sudo[4099]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:55 rivo sudo[4099]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:55 rivo volumio[3488]: info: Apply VIM3L Onboard LEDs Settings Jan 11 16:36:55 rivo volumio[3488]: info: Turning On Onboard LEDs Jan 11 16:36:55 rivo sudo[4105]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/sys_led/trigger Jan 11 16:36:55 rivo sudo[4105]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:55 rivo volumio[3488]: info: Starting CEC Event listener Jan 11 16:36:55 rivo sudo[4105]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:55 rivo volumio[3488]: info: Loading i18n strings for locale it Jan 11 16:36:55 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 11 16:36:55 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:55 rivo volumio[3488]: info: FusionDsp - mixtype--------------------- Software Jan 11 16:36:55 rivo sudo[4109]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/red_red/trigger Jan 11 16:36:55 rivo sudo[4109]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:55 rivo volumio[3488]: info: Volumio Calling Home Jan 11 16:36:55 rivo sudo[4109]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:55 rivo volumio[3488]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Jan 11 16:36:55 rivo volumio[3488]: (node:3488) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Jan 11 16:36:55 rivo volumio[3488]: (Use `node --trace-deprecation ...` to show where the warning was created) Jan 11 16:36:55 rivo volumio[3488]: info: Preparing to generate the ALSA configuration file Jan 11 16:36:55 rivo volumio[3488]: info: Stopping AccessToken refresher cron for QOBUZ Jan 11 16:36:56 rivo volumio[3488]: info: AccessToken refresher cron started for QOBUZ Jan 11 16:36:56 rivo volumio[3488]: info: Adding QOBUZ REST API Endpoints Jan 11 16:36:56 rivo volumio[3488]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Jan 11 16:36:56 rivo volumio[3488]: info: Serial port opened successfully Jan 11 16:36:56 rivo volumio[3488]: info: Sending serial start messages Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:56 rivo volumio[3488]: info: Reporting MCU Network Status: 3 Jan 11 16:36:56 rivo volumio[3488]: info: MP1 GPIO: Signalled system ready via GPIO Jan 11 16:36:56 rivo volumio[3488]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 11 16:36:56 rivo volumio[3488]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jan 11 16:36:56 rivo volumio[3488]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 11 16:36:56 rivo volumio[3488]: info: Reading ALSA contributions from plugins. Jan 11 16:36:56 rivo volumio[3488]: error: Cannot start Volumio Streaming Daemon Jan 11 16:36:56 rivo volumio[3488]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 11 16:36:56 rivo volumio[3488]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 11 16:36:56 rivo volumio[3488]: info: RAAT Albumart path created successfully Jan 11 16:36:56 rivo volumio[3488]: info: Bluetooth name changed to Rivo Jan 11 16:36:56 rivo volumio[3488]: info: MPD Permissions set Jan 11 16:36:56 rivo volumio[3488]: info: MPD Permissions set Jan 11 16:36:56 rivo volumio[3488]: info: Upmpdcli Daemon Started Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setDeviceVolumeOverride Jan 11 16:36:56 rivo volumio[3488]: info: Setting Device Volume Override Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jan 11 16:36:56 rivo volumio[3488]: info: Updating Volume Controller Parameters: Device: 0,2 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; logarithmic Vol Steps: 5 Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jan 11 16:36:56 rivo volumio[3488]: info: Disabling external Volume Control Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:56 rivo volumio[3488]: info: CoreStateMachine::pushState Jan 11 16:36:56 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::volumioPushState Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:36:56 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:36:56 rivo volumio[3488]: info: MRS: Pushing multiroomSync output update for this device Jan 11 16:36:56 rivo volumio[3488]: info: MRS: Pushing multiroomSync output Jan 11 16:36:56 rivo volumio[3488]: 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 Jan 11 16:36:56 rivo volumio5-onboarding[4006]: time=2026-01-11T16:36:56.542+01:00 level=INFO msg="listening for BLE messages" address=B8:13:32:E3:91:9F%00 Jan 11 16:36:56 rivo volumio5-onboarding[4006]: time=2026-01-11T16:36:56.543+01:00 level=INFO msg="listening for WebSocket messages" address=[::]:7331 Jan 11 16:36:56 rivo volumio[3488]: info: Executing endpoint qc_getconfig Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Jan 11 16:36:56 rivo qobuz-connect[4051]: 20260111 16:36:56.627 [4051.4051] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Jan 11 16:36:56 rivo volumio[3488]: info: Volumio called home Jan 11 16:36:56 rivo volumio[3488]: info: Spotify config file written Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Jan 11 16:36:56 rivo volumio[3488]: info: Setting Additional System Software info: Hardware Revision: 2.0 Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Jan 11 16:36:56 rivo volumio[3488]: info: Setting HW Firmware info: undefined Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Jan 11 16:36:56 rivo volumio[3488]: info: Setting HW Version info: 2.0 Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Jan 11 16:36:56 rivo volumio[3488]: info: Setting Additional System Software info: Hardware Revision: 2.0, Firmware Version: 0.3.5 Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Jan 11 16:36:56 rivo volumio[3488]: info: Setting HW Firmware info: 0.3.5 Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Jan 11 16:36:56 rivo volumio[3488]: info: Setting HW Version info: 2.0 Jan 11 16:36:56 rivo volumio[3488]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Jan 11 16:36:56 rivo volumio[3488]: info: MCU Signalled Headphone Mode Disabled Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jan 11 16:36:56 rivo volumio[3488]: info: Reporting Headphone State: false Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:56 rivo volumio[3488]: info: Updating RAAT Signal Path Jan 11 16:36:56 rivo volumio[3488]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Jan 11 16:36:56 rivo volumio[3488]: info: MCU Signalled Sleep Mode Disabled Jan 11 16:36:56 rivo sudo[4131]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 11 16:36:56 rivo sudo[4131]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:56 rivo volumio[3488]: info: Enabling Advanced system settings configuration Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , addAdditionalUISections Jan 11 16:36:56 rivo volumio[3488]: info: Additional UI Settings Added for plugin music_service/inputs Jan 11 16:36:56 rivo volumio[3488]: info: MCU Signalled Auto Boot Mode On Power Disabled Jan 11 16:36:56 rivo qobuz-connect[4051]: 20260111 16:36:56.770 [4051.4051] INFO VolumeManager: [0xac11f8f0]: Setting new playback volume: 75 Jan 11 16:36:56 rivo qobuz-connect[4051]: 20260111 16:36:56.770 [4051.4051] INFO VolumeManager: [0xac11f8f0]: Setting new mute state: 0 Jan 11 16:36:56 rivo qobuz-connect[4051]: 20260111 16:36:56.771 [4051.4051] INFO QobuzConnect: [0xac1202c0]: Client initialized! Jan 11 16:36:56 rivo qobuz-connect[4051]: 20260111 16:36:56.771 [4051.4051] INFO SampleApp: Starting Avahi advertising, name: Rivo, service name: _qobuz-connect._tcp Jan 11 16:36:56 rivo systemd[1]: Started go-librespot Daemon. Jan 11 16:36:56 rivo sudo[4131]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:56 rivo sudo[4134]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force on Jan 11 16:36:56 rivo go-librespot[4135]: go-librespot daemon starting... Jan 11 16:36:56 rivo sudo[4134]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:56 rivo qobuz-connect[4051]: 20260111 16:36:56.856 [4051.4051] INFO LocalConfigManager: [0xac11f1d0]: Starting Local Configuration server Jan 11 16:36:56 rivo qobuz-connect[4051]: 20260111 16:36:56.856 [4051.4051] INFO SampleApp: Starting Local configuration server Jan 11 16:36:56 rivo qobuz-connect[4051]: 20260111 16:36:56.857 [4051.4051] INFO SampleApp: Connected to UNIX socket client 0xac114ed8 Jan 11 16:36:56 rivo qobuz-connect[4051]: 20260111 16:36:56.857 [4051.4051] INFO SampleApp: Playback volume changed: 75 Jan 11 16:36:56 rivo kernel: fb: osd[0] enable: 1 (Xorg) Jan 11 16:36:56 rivo sudo[4134]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:56 rivo volumio[3488]: 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 Jan 11 16:36:56 rivo volumio[3488]: info: Received Get System Info Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 16:36:56 rivo volumio[3488]: info: Discovery: Getting this device information Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:36:56 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 16:36:56 rivo volumio[3488]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 11 16:36:56 rivo volumio[3488]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Jan 11 16:36:56 rivo volumio[3488]: info: QobuzConnect: QOBUZ Connect daemon connected Jan 11 16:36:56 rivo volumio[3488]: info: CoreStateMachine::pushState Jan 11 16:36:56 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 16:36:56 rivo volumio[3488]: info: CoreCommandRouter::volumioPushState Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:36:57 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:36:57 rivo volumio[3488]: info: MRS: Pushing multiroomSync output update for this device Jan 11 16:36:57 rivo volumio[3488]: info: MRS: Pushing multiroomSync output Jan 11 16:36:57 rivo volumio5-onboarding[4006]: time=2026-01-11T16:36:57.008+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal string into Go struct field State.volume of type int" Jan 11 16:36:57 rivo go-librespot[4135]: time="2026-01-11T16:36:57+01:00" level=info msg="running go-librespot 0.4.0" Jan 11 16:36:57 rivo go-librespot[4135]: time="2026-01-11T16:36:57+01:00" level=debug msg="app state loaded" Jan 11 16:36:57 rivo go-librespot[4135]: time="2026-01-11T16:36:57+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:57 rivo sudo[4145]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Jan 11 16:36:57 rivo sudo[4145]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jan 11 16:36:57 rivo systemd[1]: Started Volumio Bluetooth Module. Jan 11 16:36:57 rivo sudo[4145]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:57 rivo sudo[4154]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Jan 11 16:36:57 rivo sudo[4154]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:57 rivo volumiobt[4151]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Jan 11 16:36:57 rivo sudo[4154]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:57 rivo volumio[3488]: info: No need to fix Spotify hosts Jan 11 16:36:57 rivo volumio[3488]: error: Serial API: Failed to decode command: MAXVOL, message: 100 Jan 11 16:36:57 rivo volumio[3488]: info: Access Token successfully retrieved Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 11 16:36:57 rivo volumio5-onboarding[4006]: time=2026-01-11T16:36:57.348+01:00 level=INFO msg="BLE descriptor updated" deviceId=591439844de2f52ab8a8a0914ba892c0 deviceName=Rivo deviceModel=0x26ba1a0 Jan 11 16:36:57 rivo volumio5-onboarding[4006]: time=2026-01-11T16:36:57.349+01:00 level=INFO msg="mDNS descriptor updated" deviceId=591439844de2f52ab8a8a0914ba892c0 deviceName=Rivo deviceModel=0x26ba1a0 Jan 11 16:36:57 rivo volumio5-onboarding[4006]: time=2026-01-11T16:36:57.375+01:00 level=INFO msg="bootstrapping state" hasInternet=true Jan 11 16:36:57 rivo volumio[3488]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:36:57 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:36:57 rivo sudo[4166]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms 0 0 0 Jan 11 16:36:57 rivo sudo[4166]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:57 rivo volumio[3488]: info: Received Get System Info Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 16:36:57 rivo volumio[3488]: info: Discovery: Getting this device information Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:36:57 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 16:36:57 rivo volumio5-onboarding[4006]: time=2026-01-11T16:36:57.566+01:00 level=ERROR msg="failed to unmarshal event data" component=volumio/socket event=pushSystemInfo error="json: cannot unmarshal string into Go struct field State.state.volume of type int" data="{\"id\":\"066a9c23-33f9-49f9-9dda-ea32fceb640e\",\"host\":\"http://192.168.1.92\",\"name\":\"Rivo\",\"type\":\"device\",\"serviceName\":\"Volumio\",\"state\":{\"status\":\"stop\",\"volume\":\"100\",\"mute\":false,\"artist\":\"Sivert Høyem\",\"track\":\"Blown Away\",\"albumart\":\"https://i.scdn.co/image/ab67616d0000b2734e59296607e56e5a1c2f1638\"},\"systemversion\":\"3.886\",\"builddate\":\"Thu 11 Dec 2025 07:07:40 PM CET\",\"variant\":\"rivo\",\"hardware\":\"mp1\",\"os\":\"10\",\"additionalSVInfo\":\"Hardware Revision: 2.0, Firmware Version: 0.3.5\",\"hwFwVersion\":\"0.3.5\",\"hwVersion\":\"2.0\",\"isPremiumDevice\":true,\"isVolumioProduct\":true,\"productName\":\"Volumio Rivo\",\"hwUuid\":\"591439844de2f52ab8a8a0914ba892c0\"}" Jan 11 16:36:57 rivo sudo[4166]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:57 rivo go-librespot[4135]: time="2026-01-11T16:36:57+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 11 16:36:57 rivo go-librespot[4135]: time="2026-01-11T16:36:57+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 11 16:36:57 rivo go-librespot[4135]: time="2026-01-11T16:36:57+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 11 16:36:57 rivo go-librespot[4135]: time="2026-01-11T16:36:57+01:00" level=info msg="zeroconf server listening on port 42311" Jan 11 16:36:57 rivo volumio[3488]: info: Volumio BT Module successfully started Jan 11 16:36:57 rivo volumio[3488]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 11 16:36:57 rivo volumio[3488]: SPOTIFY: BQCeUfLXvRhxGQdSS3maFDFRf-s71Og_NT9wcYmdXew1wkTHmeQE24pmZxUfz6LQPXqU4BQqLm-ht6cNwngky-JaV4EvoRoOpYxIBmCEcYaRfYqCRuG2ZdrlLRXWZSGuf2y9wZOGvJHpy7k0EL3PWVa7dr4MBmZf684Gu5Avbto_MsZJ2-uz8gENhgPhyBHPPQKk8ztg2sQj-VOYO4bADdVwnfNGHbKLzIRXyQ94odE097jKlDfyCwgd9FyPJ4-tmyaPBaGTxN4zqyrjo0a8EX2WPNp_N4LqQxWfdx37tkcpjNpg06ym3tDm Jan 11 16:36:57 rivo volumio[3488]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 11 16:36:57 rivo volumio[3488]: info: New Spotify access token = BQCeUfLXvRhxGQdSS3maFDFRf-s71Og_NT9wcYmdXew1wkTHmeQE24pmZxUfz6LQPXqU4BQqLm-ht6cNwngky-JaV4EvoRoOpYxIBmCEcYaRfYqCRuG2ZdrlLRXWZSGuf2y9wZOGvJHpy7k0EL3PWVa7dr4MBmZf684Gu5Avbto_MsZJ2-uz8gENhgPhyBHPPQKk8ztg2sQj-VOYO4bADdVwnfNGHbKLzIRXyQ94odE097jKlDfyCwgd9FyPJ4-tmyaPBaGTxN4zqyrjo0a8EX2WPNp_N4LqQxWfdx37tkcpjNpg06ym3tDm Jan 11 16:36:57 rivo volumio[3488]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 11 16:36:57 rivo mpd[4030]: Jan 11 16:36 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 16:36:57 rivo volumio[3488]: info: TidalConnect service stoped! Jan 11 16:36:57 rivo systemd[1]: Started Music Player Daemon. Jan 11 16:36:57 rivo sudo[3990]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:57 rivo sudo[4007]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:57 rivo go-librespot[4135]: time="2026-01-11T16:36:57+01:00" level=debug msg="obtained new client token: AABfvm33TN00Lwh6L7W65kQMXP4ULBThOaCc0u0C31Cwft7Zz38aVpD28rwNiAi83JSd+jB3zaM5BgVTiszsDIGFFmBLrnP1pzS3ypUx6vHu3s8Mg/+eEFcp1No0fcuIO3VB1tiRhGJXNvrOw6XpU0nl4fwEhjWYok0Job4RC0nejAcbQqKsFkH0c5ygzmmnzj12MaTltuSqptFKxaooIn2airWXZeZ3NsFOVwTc1PecP+DCf4KefsS/Bg==" Jan 11 16:36:57 rivo volumio[3488]: info: camilladsp spawned new process with pid 4181, instance 1, run: true Jan 11 16:36:57 rivo volumio[3488]: info: camilladsp service started and running in background, instance 1 Jan 11 16:36:57 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:57 rivo go-librespot[4135]: time="2026-01-11T16:36:57+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jan 11 16:36:57 rivo kernel: aml_spdif_open Jan 11 16:36:57 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jan 11 16:36:57 rivo kernel: spdif_a keep clk continuous Jan 11 16:36:58 rivo kernel: aml_spdif_close Jan 11 16:36:58 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jan 11 16:36:58 rivo volumio[3488]: No protocol specified Jan 11 16:36:58 rivo volumio[3488]: xcb_connection_has_error() returned true Jan 11 16:36:58 rivo volumio[3488]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA Jan 11 16:36:58 rivo kernel: aml_spdif_open Jan 11 16:36:58 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jan 11 16:36:58 rivo go-librespot[4135]: time="2026-01-11T16:36:58+01:00" level=debug msg="completed keyexchange" Jan 11 16:36:58 rivo go-librespot[4135]: time="2026-01-11T16:36:58+01:00" level=debug msg="completed challenge" Jan 11 16:36:58 rivo kernel: set normal 512 fs /4 fs Jan 11 16:36:58 rivo kernel: set spdifout clk:5644800, mpll:22579200 Jan 11 16:36:58 rivo kernel: get spdifout clk:5644797, mpll:22579186 Jan 11 16:36:58 rivo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Jan 11 16:36:58 rivo kernel: set normal 512 fs /4 fs Jan 11 16:36:58 rivo kernel: set spdifout clk:5644800, mpll:22579200 Jan 11 16:36:58 rivo kernel: get spdifout clk:5644797, mpll:22579186 Jan 11 16:36:58 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Jan 11 16:36:58 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Jan 11 16:36:58 rivo volumio[3488]: info: FusionDsp loaded Jan 11 16:36:58 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 16:36:58 rivo sudo[4193]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jan 11 16:36:58 rivo sudo[4193]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:58 rivo volumio[3488]: info: FusionDsp - Reporting Fusion DSP Enabled Jan 11 16:36:58 rivo volumio[3488]: info: Adding Signal Path Element [object Object] Jan 11 16:36:58 rivo volumio[3488]: info: Adding fusiondspeq DSP Signal Path Element Jan 11 16:36:58 rivo volumio[3488]: info: Additional DSP elements updated Jan 11 16:36:58 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:58 rivo volumio[3488]: info: Updating RAAT Signal Path Jan 11 16:36:58 rivo volumio[3488]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Jan 11 16:36:58 rivo volumio[3488]: info: FusionDsp - ---- installed callbackRead Jan 11 16:36:58 rivo volumio[3488]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 11 16:36:58 rivo volumio[3488]: info: FusionDsp - Effects disabled Jan 11 16:36:58 rivo systemd[1]: Started FusionDsp Daemon. Jan 11 16:36:58 rivo volumio[3488]: info: Starting Shairport Sync Jan 11 16:36:58 rivo sudo[4193]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:58 rivo go-librespot[4135]: time="2026-01-11T16:36:58+01:00" level=info msg="authenticated AP" username="36*********************d7" Jan 11 16:36:58 rivo volumio[3488]: info: Starting Shairport Sync Jan 11 16:36:58 rivo volumio[3488]: info: Starting Shairport Sync Jan 11 16:36:58 rivo sudo[4197]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 16:36:58 rivo sudo[4197]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:58 rivo sudo[4199]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 16:36:58 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 16:36:58 rivo systemd[1]: shairport-sync.service: Succeeded. Jan 11 16:36:58 rivo volumio[3488]: info: Adding Inputs via Serial API Jan 11 16:36:58 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 16:36:58 rivo sudo[4199]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:58 rivo volumio[3488]: info: CoreStateMachine::pushState Jan 11 16:36:58 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:36:58 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 16:36:58 rivo volumio[3488]: info: CoreCommandRouter::volumioPushState Jan 11 16:36:58 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:36:58 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:36:58 rivo volumio[3488]: info: MRS: Pushing multiroomSync output update for this device Jan 11 16:36:58 rivo volumio[3488]: info: MRS: Pushing multiroomSync output Jan 11 16:36:58 rivo sudo[4202]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Jan 11 16:36:58 rivo sudo[4202]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:58 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 11 16:36:58 rivo sudo[4197]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:58 rivo sudo[4204]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 16:36:58 rivo go-librespot[4135]: time="2026-01-11T16:36:58+01:00" level=info msg="authenticated Login5" username="36*********************d7" Jan 11 16:36:58 rivo sudo[4204]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:58 rivo go-librespot[4135]: time="2026-01-11T16:36:58+01:00" level=debug msg="initializing zeroconf session" username="36*********************d7" Jan 11 16:36:58 rivo volumiobt[4151]: pulseaudio: no process found Jan 11 16:36:58 rivo sudo[4202]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:58 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 16:36:58 rivo systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Jan 11 16:36:58 rivo systemd[1]: shairport-sync.service: Succeeded. Jan 11 16:36:58 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 16:36:58 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:36:58 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 11 16:36:58 rivo sudo[4199]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:58 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:36:58 rivo sudo[4204]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:58 rivo volumio[3488]: Upnp client error: Error: This socket has been ended by the other party Jan 11 16:36:58 rivo dbus-daemon[2839]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.23' (uid=1000 pid=4213 comm="/usr/bin/pulseaudio --high-priority=true " label="kernel") Jan 11 16:36:58 rivo systemd[1]: Starting RealtimeKit Scheduling Policy Service... Jan 11 16:36:58 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:36:58 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:36:58 rivo kernel: IPVS: Creating netns size=1928 id=2 Jan 11 16:36:58 rivo dbus-daemon[2839]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Jan 11 16:36:58 rivo systemd[1]: Started RealtimeKit Scheduling Policy Service. Jan 11 16:36:58 rivo rtkit-daemon[4215]: Successfully called chroot. Jan 11 16:36:58 rivo rtkit-daemon[4215]: Successfully dropped privileges. Jan 11 16:36:58 rivo rtkit-daemon[4215]: Successfully limited resources. Jan 11 16:36:58 rivo rtkit-daemon[4215]: Running. Jan 11 16:36:58 rivo rtkit-daemon[4215]: Canary thread running. Jan 11 16:36:58 rivo rtkit-daemon[4215]: Watchdog thread running. Jan 11 16:36:58 rivo dbus-daemon[2839]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.25' (uid=0 pid=4215 comm="/usr/lib/rtkit/rtkit-daemon " label="kernel") Jan 11 16:36:58 rivo systemd[1]: Starting Authorization Manager... Jan 11 16:36:58 rivo volumio[3488]: info: Turning Off Onboard LEDs Jan 11 16:36:58 rivo polkitd[4222]: started daemon version 0.105 using authority implementation `local' version `0.105' Jan 11 16:36:58 rivo dbus-daemon[2839]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Jan 11 16:36:58 rivo systemd[1]: Started Authorization Manager. Jan 11 16:36:58 rivo sudo[4236]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/sys_led/trigger Jan 11 16:36:58 rivo sudo[4236]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:58 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:36:58 rivo sudo[4236]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:59 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:36:59 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:36:59 rivo sudo[4239]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/red_red/trigger Jan 11 16:36:59 rivo sudo[4239]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:59 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:36:59 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:36:59 rivo sudo[4239]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:59 rivo volumio-remote-updater[2828]: [2026-01-11 16:36:59] [connect] Successful connection Jan 11 16:36:59 rivo volumio[3488]: info: Successfully retrieved User Session From TIDAL Jan 11 16:36:59 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:36:59 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:36:59 rivo volumio[3488]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Jan 11 16:36:59 rivo volumio[3488]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Jan 11 16:36:59 rivo volumio[3488]: info: Shairport-Sync Started Jan 11 16:36:59 rivo volumio[3488]: Error adding Membership: Error: addMembership EINVAL Jan 11 16:36:59 rivo volumio[3488]: info: Shairport-Sync Started Jan 11 16:36:59 rivo volumio[3488]: info: Shairport-Sync Started Jan 11 16:36:59 rivo volumio[3488]: info: Asound.conf file unchanged, so no further update is needed Jan 11 16:36:59 rivo volumio[3488]: info: Output device has changed, restarting MPD Jan 11 16:36:59 rivo sudo[4243]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Jan 11 16:36:59 rivo sudo[4243]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:59 rivo systemd[1]: Started Volumio Tidal Connect Service. Jan 11 16:36:59 rivo sudo[4247]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 16:36:59 rivo sudo[4247]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:59 rivo sudo[4243]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:59 rivo volumio[3488]: info: Output device has changed, restarting Shairport Sync Jan 11 16:36:59 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:59 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 16:36:59 rivo sudo[4247]: pam_unix(sudo:session): session closed for user root Jan 11 16:36:59 rivo sudo[4253]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 16:36:59 rivo sudo[4253]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:59 rivo systemd[1]: Stopping Music Player Daemon... Jan 11 16:36:59 rivo pulseaudio[4213]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Jan 11 16:36:59 rivo pulseaudio[4213]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Jan 11 16:36:59 rivo volumiobt[4151]: Applying permissions Jan 11 16:36:59 rivo volumiobt[4151]: Setting BT discoverable and pairable Jan 11 16:36:59 rivo bluetoothd[3290]: Endpoint registered: sender=:1.45 path=/MediaEndpoint/A2DPSource Jan 11 16:36:59 rivo bluetoothd[3290]: Endpoint registered: sender=:1.45 path=/MediaEndpoint/A2DPSink Jan 11 16:36:59 rivo volumio[3488]: No protocol specified Jan 11 16:36:59 rivo volumio[3488]: xcb_connection_has_error() returned true Jan 11 16:36:59 rivo volumio[3488]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 16:36:59 rivo volumio[3488]: No protocol specified Jan 11 16:36:59 rivo volumio[3488]: xcb_connection_has_error() returned true Jan 11 16:36:59 rivo volumio[3488]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jan 11 16:36:59 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:59 rivo pulseaudio[4213]: 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 Jan 11 16:36:59 rivo volumio[3488]: info: QobuzConnect: setDeactiveState invoked Jan 11 16:36:59 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:36:59 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:36:59 rivo volumio[3488]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Jan 11 16:36:59 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:36:59 rivo volumio[3488]: error: Error starting TidalConnect Cannot read property 'sendRevoke' of undefined {"stack":"TypeError: Cannot read property 'sendRevoke' of undefined\n at ControllerTidalconnect.stopTidalConnect (/volumio/app/plugins/music_service/tidalconnect/tidalconnect_real:1:8526)\n at ControllerTidalconnect.restartService (/volumio/app/plugins/music_service/tidalconnect/tidalconnect_real:1:8818)\n at /volumio/node_modules/v-conf/index.js:165:13\n at /volumio/node_modules/multimap/index.js:150:9\n at Array.forEach ()\n at /volumio/node_modules/multimap/index.js:149:13\n at mapEach (/volumio/node_modules/multimap/index.js:9:5)\n at Multimap.forEachEntry (/volumio/node_modules/multimap/index.js:143:5)\n at Multimap.forEach (/volumio/node_modules/multimap/index.js:148:10)\n at Config.set (/volumio/node_modules/v-conf/index.js:162:20)\n at Promise._successFn (/volumio/app/plugins/audio_interface/alsa_controller/index.js:2112:39)\n at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28)\n at processTicksAndRejections (internal/process/task_queues.js:77:11)"} Jan 11 16:36:59 rivo volumio[3488]: info: Preparing to generate the ALSA configuration file Jan 11 16:36:59 rivo volumiobt[4151]: [96B blob data] Jan 11 16:36:59 rivo volumiobt[4151]: [77B blob data] Jan 11 16:36:59 rivo volumiobt[4151]: [77B blob data] Jan 11 16:36:59 rivo volumiobt[4151]: [33B blob data] Jan 11 16:36:59 rivo volumiobt[4151]: [65B blob data] Jan 11 16:36:59 rivo volumiobt[4151]: [103B blob data] Jan 11 16:36:59 rivo volumiobt[4151]: [bluetoothctl]> -e power on Jan 11 16:36:59 rivo volumiobt[4151]: Invalid command in menu main: -e Jan 11 16:36:59 rivo volumiobt[4151]: Jan 11 16:36:59 rivo volumiobt[4151]: Use "help" for a list of available commands in a menu. Jan 11 16:36:59 rivo volumiobt[4151]: Use "menu " if you want to enter any submenu. Jan 11 16:36:59 rivo volumiobt[4151]: Use "back" if you want to return to menu main. Jan 11 16:36:59 rivo volumiobt[4151]: [bluetoothctl]> agent on Jan 11 16:36:59 rivo volumiobt[4151]: Agent is already registered Jan 11 16:36:59 rivo volumiobt[4151]: [bluetoothctl]> discoverable on Jan 11 16:36:59 rivo volumiobt[4151]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended Jan 11 16:36:59 rivo volumiobt[4151]: [bluetoothctl]> pairable on Jan 11 16:36:59 rivo volumiobt[4151]: [bluetoothctl]> agent NoInputNoOutput Jan 11 16:36:59 rivo volumiobt[4151]: Agent is already registered Jan 11 16:36:59 rivo volumiobt[4151]: [bluetoothctl]> default-agent Jan 11 16:36:59 rivo volumiobt[4151]: [bluetoothctl]> quit Jan 11 16:36:59 rivo volumiobt[4151]: [65B blob data] Jan 11 16:36:59 rivo sudo[4265]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jan 11 16:36:59 rivo sudo[4265]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:36:59 rivo systemd[1]: mpd.service: Succeeded. Jan 11 16:36:59 rivo systemd[1]: Stopped Music Player Daemon. Jan 11 16:36:59 rivo systemd[1]: Starting Music Player Daemon... Jan 11 16:37:00 rivo systemd[1]: Stopping Volumio Tidal Connect Service... Jan 11 16:37:00 rivo systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Jan 11 16:37:00 rivo systemd[1]: vtcs.service: Succeeded. Jan 11 16:37:00 rivo systemd[1]: Stopped Volumio Tidal Connect Service. Jan 11 16:37:00 rivo sudo[4265]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:00 rivo sudo[4271]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jan 11 16:37:00 rivo sudo[4271]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:00 rivo sudo[4271]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:00 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:00 rivo sudo[4274]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jan 11 16:37:00 rivo sudo[4274]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:00 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:37:00 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:00 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:00 rivo systemd[1]: Stopping Volumio Qobuz Connect Service... Jan 11 16:37:00 rivo qobuz-connect[4051]: 20260111 16:37:00.358 [4051.4051] INFO SampleApp: Stopping Local configuration server Jan 11 16:37:00 rivo qobuz-connect[4051]: 20260111 16:37:00.369 [4051.4051] INFO SampleApp: shat down connection on UNIX socket Jan 11 16:37:00 rivo systemd[1]: qobuz-connect.service: Succeeded. Jan 11 16:37:00 rivo systemd[1]: Stopped Volumio Qobuz Connect Service. Jan 11 16:37:00 rivo sudo[4269]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 16:37:00 rivo sudo[4269]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:00 rivo systemd[1]: Started Volumio Qobuz Connect Service. Jan 11 16:37:00 rivo sudo[4274]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:00 rivo sudo[4269]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:00 rivo volumio[3488]: error: MPD error: Error: write EPIPE Jan 11 16:37:00 rivo volumio[3488]: error: write EPIPE {"errno":-32,"code":"EPIPE","syscall":"write"} Jan 11 16:37:00 rivo go-librespot[4135]: time="2026-01-11T16:37:00+01:00" level=debug msg="dealer connection opened" Jan 11 16:37:00 rivo go-librespot[4135]: time="2026-01-11T16:37:00+01:00" level=trace msg="starting accesspoint recv loop" Jan 11 16:37:00 rivo go-librespot[4135]: time="2026-01-11T16:37:00+01:00" level=trace msg="starting dealer recv loop" Jan 11 16:37:00 rivo go-librespot[4135]: time="2026-01-11T16:37:00+01:00" level=trace msg="received accesspoint ping" Jan 11 16:37:00 rivo go-librespot[4135]: time="2026-01-11T16:37:00+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 11 16:37:00 rivo go-librespot[4135]: time="2026-01-11T16:37:00+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 11 16:37:00 rivo go-librespot[4135]: time="2026-01-11T16:37:00+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 11 16:37:00 rivo go-librespot[4135]: time="2026-01-11T16:37:00+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 11 16:37:00 rivo go-librespot[4135]: time="2026-01-11T16:37:00+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 11 16:37:00 rivo go-librespot[4135]: time="2026-01-11T16:37:00+01:00" level=debug msg="received connection id: OTU0ZWFiNTUtM2Q5...OUZFOTQ4Njc5NQ==" Jan 11 16:37:00 rivo go-librespot[4135]: time="2026-01-11T16:37:00+01:00" level=trace msg="received accesspoint pong ack" Jan 11 16:37:00 rivo volumio[3488]: error: MPD error: The expression evaluated to a falsy value: Jan 11 16:37:00 rivo volumio[3488]: assert.ok(self.idling) Jan 11 16:37:00 rivo volumio[3488]: error: The expression evaluated to a falsy value: Jan 11 16:37:00 rivo volumio[3488]: assert.ok(self.idling) Jan 11 16:37:00 rivo volumio[3488]: error: MPD error: Error: write EPIPE Jan 11 16:37:00 rivo volumio[3488]: error: write EPIPE {"errno":-32,"code":"EPIPE","syscall":"write"} Jan 11 16:37:00 rivo volumio[3488]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jan 11 16:37:00 rivo volumio-remote-updater[2828]: [2026-01-11 16:37:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1768145819 101 Jan 11 16:37:00 rivo volumio[3488]: 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: 5 Jan 11 16:37:00 rivo volumio[3488]: info: Onboard LEDs initialized Jan 11 16:37:00 rivo volumio[3488]: info: MPD running with PID4030 Jan 11 16:37:00 rivo volumio[3488]: ,establishing connection Jan 11 16:37:00 rivo volumio[3488]: info: MRS: Getting audio outputs on start Jan 11 16:37:00 rivo volumio[3488]: info: MRS: Requesting all other devices output Jan 11 16:37:00 rivo go-librespot[4135]: time="2026-01-11T16:37:00+01:00" level=debug msg="put connect state because NEW_DEVICE" Jan 11 16:37:00 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:00 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:00 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:00 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:00 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:00 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:00 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:00 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:00 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 16:37:00 rivo volumio[3488]: info: Overriding Software Volume supported Formats Jan 11 16:37:00 rivo volumio[3488]: info: Not Reporting Auto name since its the default one Jan 11 16:37:00 rivo volumio[3488]: info: go-librespot daemon successfully initialized Jan 11 16:37:00 rivo volumio[3488]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 11 16:37:00 rivo volumio[3488]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jan 11 16:37:00 rivo volumio[3488]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 11 16:37:00 rivo volumio[3488]: info: Reading ALSA contributions from plugins. Jan 11 16:37:00 rivo volumio[3488]: info: CoreCommandRouter::servicePushState Jan 11 16:37:00 rivo volumio[3488]: info: CoreStateMachine::pushState Jan 11 16:37:00 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:00 rivo volumio[3488]: info: CoreCommandRouter::volumioPushState Jan 11 16:37:00 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:37:00 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:00 rivo volumio[3488]: info: MRS: Pushing multiroomSync output update for this device Jan 11 16:37:00 rivo volumio[3488]: info: MRS: Pushing multiroomSync output Jan 11 16:37:00 rivo volumio[3488]: error: Help! Some callbacks for volumioPushState are crashing! Jan 11 16:37:00 rivo volumio[3488]: error: Cannot read property 'sendVolumeMute' of undefined Jan 11 16:37:00 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:00 rivo volumio[3488]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received inputs Jan 11 16:37:00 rivo volumio[3488]: info: CoreCommandRouter::volumiosetSourceActiveno-source Jan 11 16:37:00 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 16:37:00 rivo volumio[3488]: info: CoreStateMachine::pushState Jan 11 16:37:00 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:00 rivo volumio[3488]: info: CoreCommandRouter::volumioPushState Jan 11 16:37:00 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:37:00 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:00 rivo volumio[3488]: info: MRS: Pushing multiroomSync output update for this device Jan 11 16:37:00 rivo volumio[3488]: info: MRS: Pushing multiroomSync output Jan 11 16:37:00 rivo volumio[3488]: error: Help! Some callbacks for volumioPushState are crashing! Jan 11 16:37:00 rivo volumio[3488]: error: Cannot read property 'sendVolumeMute' of undefined Jan 11 16:37:01 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:01 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:37:01 rivo volumio[3488]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jan 11 16:37:01 rivo volumio[3488]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Jan 11 16:37:01 rivo volumio[3488]: info: MPD Permissions set Jan 11 16:37:01 rivo volumio[3488]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Jan 11 16:37:01 rivo volumio[3488]: info: QobuzConnect: setDeactiveState invoked Jan 11 16:37:01 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:37:01 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:01 rivo volumio[3488]: info: Executing endpoint qc_getconfig Jan 11 16:37:01 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Jan 11 16:37:01 rivo qobuz-connect[4276]: 20260111 16:37:01.249 [4276.4276] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Jan 11 16:37:01 rivo qobuz-connect[4276]: 20260111 16:37:01.257 [4276.4276] INFO VolumeManager: [0xac80b8f0]: Setting new playback volume: 75 Jan 11 16:37:01 rivo qobuz-connect[4276]: 20260111 16:37:01.257 [4276.4276] INFO VolumeManager: [0xac80b8f0]: Setting new mute state: 0 Jan 11 16:37:01 rivo qobuz-connect[4276]: 20260111 16:37:01.258 [4276.4276] INFO QobuzConnect: [0xac80c2c0]: Client initialized! Jan 11 16:37:01 rivo qobuz-connect[4276]: 20260111 16:37:01.258 [4276.4276] INFO SampleApp: Starting Avahi advertising, name: Rivo, service name: _qobuz-connect._tcp Jan 11 16:37:01 rivo qobuz-connect[4276]: 20260111 16:37:01.281 [4276.4276] INFO LocalConfigManager: [0xac80b1d0]: Starting Local Configuration server Jan 11 16:37:01 rivo qobuz-connect[4276]: 20260111 16:37:01.282 [4276.4276] INFO SampleApp: Starting Local configuration server Jan 11 16:37:01 rivo qobuz-connect[4276]: 20260111 16:37:01.282 [4276.4276] INFO SampleApp: Connected to UNIX socket client 0xac800ed8 Jan 11 16:37:01 rivo volumio[3488]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Jan 11 16:37:01 rivo volumio[3488]: info: QobuzConnect: QOBUZ Connect daemon connected Jan 11 16:37:01 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:01 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:01 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:01 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:01 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:01 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:01 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:01 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 16:37:01 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jan 11 16:37:01 rivo qobuz-connect[4276]: 20260111 16:37:01.399 [4276.4276] INFO SampleApp: Playback volume changed: 75 Jan 11 16:37:01 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:01 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jan 11 16:37:01 rivo volumio[3488]: No protocol specified Jan 11 16:37:01 rivo volumio[3488]: xcb_connection_has_error() returned true Jan 11 16:37:01 rivo volumio[3488]: info: Successfully retrieved User Subscription From TIDAL Jan 11 16:37:01 rivo volumio[3488]: info: Adding TIDAL to Browse Sources Jan 11 16:37:01 rivo volumio[3488]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 16:37:01 rivo volumio[3488]: info: [1768145821657] CoreMusicLibrary::Adding element TIDAL Jan 11 16:37:01 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 16:37:01 rivo volumio[3488]: Cannot find translation for source TIDAL Jan 11 16:37:01 rivo volumio[3488]: info: Adding TIDAL REST API Endpoints Jan 11 16:37:01 rivo volumio[3488]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Jan 11 16:37:01 rivo sudo[4313]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jan 11 16:37:01 rivo sudo[4313]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:01 rivo sudo[4313]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:01 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:37:01 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:01 rivo sudo[4316]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jan 11 16:37:01 rivo sudo[4317]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 16:37:01 rivo sudo[4316]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:01 rivo sudo[4317]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:01 rivo volumio[3488]: 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 Jan 11 16:37:01 rivo volumio[3488]: info: Starting Shairport Sync Jan 11 16:37:01 rivo sudo[4321]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 16:37:01 rivo sudo[4321]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:01 rivo systemd[1]: Started RAAT DAEMON. Jan 11 16:37:01 rivo sudo[4316]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:02 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:37:02 rivo volumio[3488]: info: Raat Daemon started successfully Jan 11 16:37:02 rivo volumio[3488]: info: Asound.conf file written Jan 11 16:37:02 rivo sudo[4325]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 16:37:02 rivo sudo[4325]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:02 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 16:37:02 rivo systemd[1]: shairport-sync.service: Succeeded. Jan 11 16:37:02 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 16:37:02 rivo sudo[4337]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jan 11 16:37:02 rivo sudo[4337]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:02 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 11 16:37:02 rivo sudo[4325]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:02 rivo sudo[4337]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:02 rivo kernel: Fine tdm clk setting range (0~2000000), 12287994 Jan 11 16:37:02 rivo kernel: Fine spdif sysclk setting range(0~2000000), 5644797 Jan 11 16:37:02 rivo kernel: out of value, fixed it Jan 11 16:37:02 rivo kernel: id=0 set inskew=0 Jan 11 16:37:02 rivo volumio[3488]: No protocol specified Jan 11 16:37:02 rivo volumio[3488]: xcb_connection_has_error() returned true Jan 11 16:37:02 rivo volumio[3488]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:eARC_TX CDS:0' : Operation not permitted Jan 11 16:37:02 rivo volumio[3488]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:I2SIn CLK:0' : Operation not permitted Jan 11 16:37:02 rivo volumio[3488]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN audio samplerate:0' : Operation not permitted Jan 11 16:37:02 rivo volumio[3488]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN Audio Type:0' : Operation not permitted Jan 11 16:37:02 rivo volumio[3488]: info: Output device has changed, restarting MPD Jan 11 16:37:02 rivo sudo[4345]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 16:37:02 rivo sudo[4345]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:02 rivo volumio[3488]: info: Output device has changed, restarting Shairport Sync Jan 11 16:37:02 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:02 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 16:37:02 rivo sudo[4345]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:02 rivo sudo[4348]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 16:37:02 rivo sudo[4348]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:02 rivo systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jan 11 16:37:02 rivo systemd[1]: mpd.service: Succeeded. Jan 11 16:37:02 rivo systemd[1]: Stopped Music Player Daemon. Jan 11 16:37:02 rivo volumio[3488]: No protocol specified Jan 11 16:37:02 rivo volumio[3488]: xcb_connection_has_error() returned true Jan 11 16:37:02 rivo volumio[3488]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 16:37:02 rivo volumio[3488]: No protocol specified Jan 11 16:37:02 rivo volumio[3488]: xcb_connection_has_error() returned true Jan 11 16:37:02 rivo systemd[1]: Starting Music Player Daemon... Jan 11 16:37:02 rivo volumio[3488]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jan 11 16:37:02 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:02 rivo volumio[3488]: info: QobuzConnect: setDeactiveState invoked Jan 11 16:37:02 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:37:02 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:02 rivo volumio[3488]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Jan 11 16:37:02 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:02 rivo volumio[3488]: error: Error starting TidalConnect Cannot read property 'sendRevoke' of undefined {"stack":"TypeError: Cannot read property 'sendRevoke' of undefined\n at ControllerTidalconnect.stopTidalConnect (/volumio/app/plugins/music_service/tidalconnect/tidalconnect_real:1:8526)\n at ControllerTidalconnect.restartService (/volumio/app/plugins/music_service/tidalconnect/tidalconnect_real:1:8818)\n at /volumio/node_modules/v-conf/index.js:165:13\n at /volumio/node_modules/multimap/index.js:150:9\n at Array.forEach ()\n at /volumio/node_modules/multimap/index.js:149:13\n at mapEach (/volumio/node_modules/multimap/index.js:9:5)\n at Multimap.forEachEntry (/volumio/node_modules/multimap/index.js:143:5)\n at Multimap.forEach (/volumio/node_modules/multimap/index.js:148:10)\n at Config.set (/volumio/node_modules/v-conf/index.js:162:20)\n at Promise._successFn (/volumio/app/plugins/audio_interface/alsa_controller/index.js:2112:39)\n at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28)\n at processTicksAndRejections (internal/process/task_queues.js:77:11)"} Jan 11 16:37:02 rivo volumio[3488]: info: Preparing to generate the ALSA configuration file Jan 11 16:37:02 rivo sudo[4358]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jan 11 16:37:02 rivo sudo[4358]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:02 rivo sudo[4354]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 16:37:02 rivo sudo[4354]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:02 rivo sudo[4354]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:02 rivo sudo[4358]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:02 rivo volumio[3488]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 11 16:37:02 rivo volumio[3488]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jan 11 16:37:02 rivo volumio[3488]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 11 16:37:02 rivo volumio[3488]: info: Reading ALSA contributions from plugins. Jan 11 16:37:02 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:37:02 rivo sudo[4365]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jan 11 16:37:02 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:37:02 rivo sudo[4365]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:02 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:02 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:37:02 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:37:02 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:02 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:37:02 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:02 rivo volumio[3488]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Jan 11 16:37:02 rivo volumio[3488]: info: MPD Permissions set Jan 11 16:37:02 rivo volumio[3488]: info: TidalConnect service started! Jan 11 16:37:02 rivo volumio[3488]: info: Completed starting Core Plugins Jan 11 16:37:02 rivo volumio[3488]: info: ------------------------------------------- Jan 11 16:37:02 rivo volumio[3488]: info: ----- MyVolumio plugins startup ---- Jan 11 16:37:02 rivo volumio[3488]: info: ------------------------------------------- Jan 11 16:37:02 rivo sudo[4365]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:02 rivo volumio[3488]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 11 16:37:02 rivo volumio[3488]: info: Shairport-Sync Started Jan 11 16:37:02 rivo volumio[3488]: info: CoreStateMachine::pushState Jan 11 16:37:02 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:02 rivo volumio[3488]: info: CoreCommandRouter::volumioPushState Jan 11 16:37:02 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:37:02 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:02 rivo volumio[3488]: info: MRS: Pushing multiroomSync output update for this device Jan 11 16:37:02 rivo volumio[3488]: info: MRS: Pushing multiroomSync output Jan 11 16:37:02 rivo volumio[3488]: error: Help! Some callbacks for volumioPushState are crashing! Jan 11 16:37:02 rivo volumio[3488]: error: Cannot read property 'sendVolumeMute' of undefined Jan 11 16:37:02 rivo sudo[4369]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jan 11 16:37:02 rivo sudo[4369]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:02 rivo volumio[3488]: info: Executing endpoint restartRAATSocket Jan 11 16:37:02 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Jan 11 16:37:03 rivo volumio[3488]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jan 11 16:37:03 rivo qobuz-connect[4276]: 20260111 16:37:03.048 [4276.4276] INFO SampleApp: Stopping Local configuration server Jan 11 16:37:03 rivo systemd[1]: Stopping Volumio Qobuz Connect Service... Jan 11 16:37:03 rivo qobuz-connect[4276]: 20260111 16:37:03.059 [4276.4276] INFO SampleApp: shat down connection on UNIX socket Jan 11 16:37:03 rivo systemd[1]: qobuz-connect.service: Succeeded. Jan 11 16:37:03 rivo systemd[1]: Stopped Volumio Qobuz Connect Service. Jan 11 16:37:03 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:03 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:03 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:03 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:03 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:03 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:03 rivo systemd[1]: Started Volumio Qobuz Connect Service. Jan 11 16:37:03 rivo sudo[4369]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:03 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 16:37:03 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jan 11 16:37:03 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:03 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:03 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 11 16:37:03 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:03 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:37:03 rivo volumio[3488]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Jan 11 16:37:03 rivo volumio[3488]: info: QobuzConnect: setDeactiveState invoked Jan 11 16:37:03 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:37:03 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:03 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:03 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:03 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 16:37:03 rivo volumio[3488]: info: Overriding Software Volume supported Formats Jan 11 16:37:03 rivo volumio[3488]: info: Not Reporting Auto name since its the default one Jan 11 16:37:03 rivo volumio[3488]: info: Executing endpoint qc_getconfig Jan 11 16:37:03 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Jan 11 16:37:03 rivo qobuz-connect[4372]: 20260111 16:37:03.628 [4372.4372] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Jan 11 16:37:03 rivo volumio[3488]: info: TidalConnect service stoped! Jan 11 16:37:03 rivo qobuz-connect[4372]: 20260111 16:37:03.639 [4372.4372] INFO VolumeManager: [0xac9f38f0]: Setting new playback volume: 75 Jan 11 16:37:03 rivo qobuz-connect[4372]: 20260111 16:37:03.645 [4372.4372] INFO VolumeManager: [0xac9f38f0]: Setting new mute state: 0 Jan 11 16:37:03 rivo qobuz-connect[4372]: 20260111 16:37:03.646 [4372.4372] INFO QobuzConnect: [0xac9f42c0]: Client initialized! Jan 11 16:37:03 rivo qobuz-connect[4372]: 20260111 16:37:03.646 [4372.4372] INFO SampleApp: Starting Avahi advertising, name: Rivo, service name: _qobuz-connect._tcp Jan 11 16:37:03 rivo qobuz-connect[4372]: 20260111 16:37:03.688 [4372.4372] INFO LocalConfigManager: [0xac9f31d0]: Starting Local Configuration server Jan 11 16:37:03 rivo qobuz-connect[4372]: 20260111 16:37:03.688 [4372.4372] INFO SampleApp: Starting Local configuration server Jan 11 16:37:03 rivo qobuz-connect[4372]: 20260111 16:37:03.689 [4372.4372] INFO SampleApp: Connected to UNIX socket client 0xac9e8ed8 Jan 11 16:37:03 rivo volumio[3488]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jan 11 16:37:03 rivo volumio[3488]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Jan 11 16:37:03 rivo volumio[3488]: info: QobuzConnect: QOBUZ Connect daemon connected Jan 11 16:37:03 rivo volumio[3488]: info: Starting Shairport Sync Jan 11 16:37:03 rivo qobuz-connect[4372]: 20260111 16:37:03.777 [4372.4372] INFO SampleApp: Playback volume changed: 75 Jan 11 16:37:03 rivo sudo[4392]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 16:37:03 rivo sudo[4392]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:03 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 16:37:03 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:37:03 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:03 rivo systemd[1]: shairport-sync.service: Succeeded. Jan 11 16:37:03 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 16:37:03 rivo volumio[3488]: info: Initializing connection to go-librespot Websocket Jan 11 16:37:03 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 11 16:37:03 rivo sudo[4392]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:03 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jan 11 16:37:04 rivo volumio[3488]: No protocol specified Jan 11 16:37:04 rivo volumio[3488]: xcb_connection_has_error() returned true Jan 11 16:37:04 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:37:04 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:04 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:04 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:37:04 rivo sudo[4404]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jan 11 16:37:04 rivo sudo[4404]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:04 rivo volumio[3488]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Jan 11 16:37:04 rivo volumio[3488]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Jan 11 16:37:04 rivo sudo[4404]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:04 rivo volumio[3488]: info: Shairport-Sync Started Jan 11 16:37:04 rivo sudo[4407]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jan 11 16:37:04 rivo go-librespot[4135]: time="2026-01-11T16:37:04+01:00" level=debug msg="new websocket client" Jan 11 16:37:04 rivo volumio[3488]: SPOTIFY: User informations: {"country":"IT","display_name":"ilaria","email":"ilariarenna86@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/36aaxlfn4e8lhnthersxajod7"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/36aaxlfn4e8lhnthersxajod7","id":"36aaxlfn4e8lhnthersxajod7","images":[],"product":"premium","type":"user","uri":"spotify:user:36aaxlfn4e8lhnthersxajod7"} Jan 11 16:37:04 rivo sudo[4408]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Jan 11 16:37:04 rivo sudo[4408]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:04 rivo sudo[4407]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:04 rivo volumio[3488]: info: Spotify Successfully logged in Jan 11 16:37:04 rivo volumio[3488]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 16:37:04 rivo volumio[3488]: info: [1768145824470] CoreMusicLibrary::Adding element Spotify Jan 11 16:37:04 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 16:37:04 rivo volumio[3488]: Cannot find translation for source TIDAL Jan 11 16:37:04 rivo volumio[3488]: Cannot find translation for source Spotify Jan 11 16:37:04 rivo systemd[1]: Started Volumio Tidal Connect Service. Jan 11 16:37:04 rivo systemd[1]: Stopping RAAT DAEMON... Jan 11 16:37:04 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jan 11 16:37:04 rivo systemd[1]: raat-daemon.service: Succeeded. Jan 11 16:37:04 rivo systemd[1]: Stopped RAAT DAEMON. Jan 11 16:37:04 rivo volumio[3488]: info: Connection to go-librespot Websocket established Jan 11 16:37:04 rivo sudo[4408]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:04 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:04 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:37:04 rivo systemd[1]: Started RAAT DAEMON. Jan 11 16:37:04 rivo sudo[4407]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:04 rivo volumio[3488]: info: RAAT: Requesting Headphone Status Jan 11 16:37:04 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jan 11 16:37:04 rivo volumio[3488]: info: Asound.conf file written Jan 11 16:37:04 rivo sudo[4447]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jan 11 16:37:04 rivo sudo[4447]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:04 rivo sudo[4447]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:05 rivo kernel: Fine tdm clk setting range (0~2000000), 12287994 Jan 11 16:37:05 rivo kernel: Fine spdif sysclk setting range(0~2000000), 5644797 Jan 11 16:37:05 rivo kernel: out of value, fixed it Jan 11 16:37:05 rivo kernel: id=0 set inskew=0 Jan 11 16:37:05 rivo volumio[3488]: No protocol specified Jan 11 16:37:05 rivo volumio[3488]: xcb_connection_has_error() returned true Jan 11 16:37:05 rivo volumio[3488]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:eARC_TX CDS:0' : Operation not permitted Jan 11 16:37:05 rivo volumio[3488]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:I2SIn CLK:0' : Operation not permitted Jan 11 16:37:05 rivo volumio[3488]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN audio samplerate:0' : Operation not permitted Jan 11 16:37:05 rivo volumio[3488]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN Audio Type:0' : Operation not permitted Jan 11 16:37:05 rivo volumio[3488]: info: Output device has changed, restarting MPD Jan 11 16:37:05 rivo sudo[4471]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 16:37:05 rivo sudo[4471]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:05 rivo volumio[3488]: info: Output device has changed, restarting Shairport Sync Jan 11 16:37:05 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:05 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 16:37:05 rivo sudo[4471]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:05 rivo sudo[4473]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 16:37:05 rivo sudo[4473]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:05 rivo volumio[3488]: No protocol specified Jan 11 16:37:05 rivo volumio[3488]: xcb_connection_has_error() returned true Jan 11 16:37:05 rivo volumio[3488]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 16:37:05 rivo volumio[3488]: No protocol specified Jan 11 16:37:05 rivo volumio[3488]: xcb_connection_has_error() returned true Jan 11 16:37:05 rivo volumio[3488]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jan 11 16:37:05 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:05 rivo systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jan 11 16:37:05 rivo systemd[1]: mpd.service: Succeeded. Jan 11 16:37:05 rivo systemd[1]: Stopped Music Player Daemon. Jan 11 16:37:05 rivo systemd[1]: Starting Music Player Daemon... Jan 11 16:37:05 rivo volumio[3488]: info: QobuzConnect: setDeactiveState invoked Jan 11 16:37:05 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:37:05 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:05 rivo volumio[3488]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Jan 11 16:37:05 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:05 rivo volumio[3488]: error: Error starting TidalConnect Cannot read property 'sendRevoke' of undefined {"stack":"TypeError: Cannot read property 'sendRevoke' of undefined\n at ControllerTidalconnect.stopTidalConnect (/volumio/app/plugins/music_service/tidalconnect/tidalconnect_real:1:8526)\n at ControllerTidalconnect.restartService (/volumio/app/plugins/music_service/tidalconnect/tidalconnect_real:1:8818)\n at /volumio/node_modules/v-conf/index.js:165:13\n at /volumio/node_modules/multimap/index.js:150:9\n at Array.forEach ()\n at /volumio/node_modules/multimap/index.js:149:13\n at mapEach (/volumio/node_modules/multimap/index.js:9:5)\n at Multimap.forEachEntry (/volumio/node_modules/multimap/index.js:143:5)\n at Multimap.forEach (/volumio/node_modules/multimap/index.js:148:10)\n at Config.set (/volumio/node_modules/v-conf/index.js:162:20)\n at Promise._successFn (/volumio/app/plugins/audio_interface/alsa_controller/index.js:2112:39)\n at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28)\n at processTicksAndRejections (internal/process/task_queues.js:77:11)"} Jan 11 16:37:05 rivo volumio[3488]: info: Preparing to generate the ALSA configuration file Jan 11 16:37:05 rivo sudo[4484]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jan 11 16:37:05 rivo sudo[4484]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:05 rivo systemd[1]: Stopping Volumio Tidal Connect Service... Jan 11 16:37:05 rivo systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Jan 11 16:37:05 rivo systemd[1]: vtcs.service: Succeeded. Jan 11 16:37:05 rivo systemd[1]: Stopped Volumio Tidal Connect Service. Jan 11 16:37:05 rivo sudo[4480]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 16:37:05 rivo sudo[4480]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:05 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:37:05 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:05 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:37:05 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:05 rivo sudo[4484]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:05 rivo sudo[4490]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jan 11 16:37:05 rivo sudo[4490]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:05 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:05 rivo sudo[4480]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:05 rivo volumio[3488]: info: Raat Daemon started successfully Jan 11 16:37:05 rivo volumio[3488]: error: MPD error: The expression evaluated to a falsy value: Jan 11 16:37:05 rivo volumio[3488]: assert.ok(self.idling) Jan 11 16:37:05 rivo volumio[3488]: error: The expression evaluated to a falsy value: Jan 11 16:37:05 rivo volumio[3488]: assert.ok(self.idling) Jan 11 16:37:05 rivo volumio[3488]: error: MPD error: The expression evaluated to a falsy value: Jan 11 16:37:05 rivo volumio[3488]: assert.ok(self.idling) Jan 11 16:37:05 rivo volumio[3488]: error: The expression evaluated to a falsy value: Jan 11 16:37:05 rivo volumio[3488]: assert.ok(self.idling) Jan 11 16:37:05 rivo volumio[3488]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 11 16:37:05 rivo volumio[3488]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jan 11 16:37:05 rivo sudo[4490]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:05 rivo volumio[3488]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 11 16:37:05 rivo volumio[3488]: info: Reading ALSA contributions from plugins. Jan 11 16:37:05 rivo volumio[3488]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Jan 11 16:37:05 rivo volumio[3488]: info: MPD Permissions set Jan 11 16:37:05 rivo volumio[3488]: info: Checking for updated MCU Firmware Jan 11 16:37:05 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 16:37:05 rivo sudo[4495]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jan 11 16:37:05 rivo sudo[4495]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:05 rivo volumio[3488]: info: Firware on device is on latest version, no need to update Jan 11 16:37:05 rivo volumio[3488]: info: MCU Signalled Headphone Mode Disabled Jan 11 16:37:05 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jan 11 16:37:05 rivo volumio[3488]: info: Reporting Headphone State: false Jan 11 16:37:05 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:05 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:05 rivo volumio[3488]: info: Updating RAAT Signal Path Jan 11 16:37:05 rivo volumio[3488]: info: CoreStateMachine::pushState Jan 11 16:37:05 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:05 rivo volumio[3488]: info: CoreCommandRouter::volumioPushState Jan 11 16:37:05 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:37:05 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:05 rivo volumio[3488]: info: MRS: Pushing multiroomSync output update for this device Jan 11 16:37:05 rivo volumio[3488]: info: MRS: Pushing multiroomSync output Jan 11 16:37:05 rivo volumio[3488]: error: Help! Some callbacks for volumioPushState are crashing! Jan 11 16:37:05 rivo volumio[3488]: error: Cannot read property 'sendVolumeMute' of undefined Jan 11 16:37:05 rivo qobuz-connect[4372]: 20260111 16:37:05.798 [4372.4372] INFO SampleApp: Stopping Local configuration server Jan 11 16:37:05 rivo qobuz-connect[4372]: 20260111 16:37:05.799 [4372.4372] INFO SampleApp: shat down connection on UNIX socket Jan 11 16:37:05 rivo systemd[1]: Stopping Volumio Qobuz Connect Service... Jan 11 16:37:05 rivo volumio[3488]: info: Executing endpoint restartRAATSocket Jan 11 16:37:05 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Jan 11 16:37:05 rivo systemd[1]: qobuz-connect.service: Succeeded. Jan 11 16:37:05 rivo systemd[1]: Stopped Volumio Qobuz Connect Service. Jan 11 16:37:05 rivo systemd[1]: Started Volumio Qobuz Connect Service. Jan 11 16:37:05 rivo sudo[4495]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:05 rivo volumio[3488]: info: Executing endpoint tc_getconfig Jan 11 16:37:05 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Jan 11 16:37:05 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:05 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:37:05 rivo volumio[3488]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jan 11 16:37:05 rivo volumio[3488]: info: TidalConnect service stoped! Jan 11 16:37:05 rivo volumio[3488]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Jan 11 16:37:05 rivo volumio[3488]: info: QobuzConnect: setDeactiveState invoked Jan 11 16:37:05 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:37:05 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 16:37:06 rivo volumio[3488]: info: Overriding Software Volume supported Formats Jan 11 16:37:06 rivo volumio[3488]: info: Not Reporting Auto name since its the default one Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:06 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:06 rivo go-librespot[4135]: time="2026-01-11T16:37:06+01:00" level=debug msg="handling transfer player command from a19a59c199cbc679487861a0459a5c9535daad13" Jan 11 16:37:06 rivo go-librespot[4135]: time="2026-01-11T16:37:06+01:00" level=debug msg="resolved context of track" uri="spotify:search:ricordati+di+me+karaoke" Jan 11 16:37:06 rivo go-librespot[4135]: time="2026-01-11T16:37:06+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:search:ricordati+di+me+karaoke" Jan 11 16:37:06 rivo go-librespot[4135]: time="2026-01-11T16:37:06+01:00" level=debug msg="loading track (paused: true, position: 0ms)" uri="spotify:track:0Z0WTcYhGpw5HS9OO509X9" Jan 11 16:37:06 rivo volumio[3488]: info: Executing endpoint qc_getconfig Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Jan 11 16:37:06 rivo go-librespot[4135]: time="2026-01-11T16:37:06+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 11 16:37:06 rivo go-librespot[4135]: time="2026-01-11T16:37:06+01:00" level=trace msg="emitting websocket event: will_play" Jan 11 16:37:06 rivo qobuz-connect[4498]: 20260111 16:37:06.381 [4498.4498] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Jan 11 16:37:06 rivo qobuz-connect[4498]: 20260111 16:37:06.394 [4498.4498] INFO VolumeManager: [0xabc578f0]: Setting new playback volume: 75 Jan 11 16:37:06 rivo qobuz-connect[4498]: 20260111 16:37:06.395 [4498.4498] INFO VolumeManager: [0xabc578f0]: Setting new mute state: 0 Jan 11 16:37:06 rivo qobuz-connect[4498]: 20260111 16:37:06.396 [4498.4498] INFO QobuzConnect: [0xabc582c0]: Client initialized! Jan 11 16:37:06 rivo qobuz-connect[4498]: 20260111 16:37:06.396 [4498.4498] INFO SampleApp: Starting Avahi advertising, name: Rivo, service name: _qobuz-connect._tcp Jan 11 16:37:06 rivo go-librespot[4135]: time="2026-01-11T16:37:06+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1122" Jan 11 16:37:06 rivo go-librespot[4135]: time="2026-01-11T16:37:06+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Jan 11 16:37:06 rivo volumio[3488]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jan 11 16:37:06 rivo volumio[3488]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:search:ricordati+di+me+karaoke","uri":"spotify:track:0Z0WTcYhGpw5HS9OO509X9","play_origin":"search"}} Jan 11 16:37:06 rivo volumio[3488]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Jan 11 16:37:06 rivo volumio[3488]: info: QobuzConnect: QOBUZ Connect daemon connected Jan 11 16:37:06 rivo qobuz-connect[4498]: 20260111 16:37:06.439 [4498.4498] INFO LocalConfigManager: [0xabc571d0]: Starting Local Configuration server Jan 11 16:37:06 rivo qobuz-connect[4498]: 20260111 16:37:06.440 [4498.4498] INFO SampleApp: Starting Local configuration server Jan 11 16:37:06 rivo qobuz-connect[4498]: 20260111 16:37:06.441 [4498.4498] INFO SampleApp: Connected to UNIX socket client 0xabc4ced8 Jan 11 16:37:06 rivo volumio[3488]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Jan 11 16:37:06 rivo volumio[3488]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Jan 11 16:37:06 rivo go-librespot[4135]: time="2026-01-11T16:37:06+01:00" level=debug msg="selected format OGG_VORBIS_320 (334db4170b0c2c4b294bd55907e9cfe405d2c1bb)" uri="spotify:track:0Z0WTcYhGpw5HS9OO509X9" Jan 11 16:37:06 rivo go-librespot[4135]: time="2026-01-11T16:37:06+01:00" level=debug msg="requested aes key for file 334db4170b0c2c4b294bd55907e9cfe405d2c1bb, gid: 0Z0WTcYhGpw5HS9OO509X9" Jan 11 16:37:06 rivo volumio[3488]: info: Starting Shairport Sync Jan 11 16:37:06 rivo sudo[4523]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jan 11 16:37:06 rivo sudo[4523]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:06 rivo qobuz-connect[4498]: 20260111 16:37:06.531 [4498.4498] INFO SampleApp: Playback volume changed: 75 Jan 11 16:37:06 rivo sudo[4526]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 16:37:06 rivo go-librespot[4135]: time="2026-01-11T16:37:06+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:0Z0WTcYhGpw5HS9OO509X9" Jan 11 16:37:06 rivo sudo[4526]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:06 rivo systemd[1]: Started Volumio Tidal Connect Service. Jan 11 16:37:06 rivo volumio[3488]: No protocol specified Jan 11 16:37:06 rivo volumio[3488]: xcb_connection_has_error() returned true Jan 11 16:37:06 rivo sudo[4523]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:06 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 16:37:06 rivo systemd[1]: shairport-sync.service: Succeeded. Jan 11 16:37:06 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:37:06 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 11 16:37:06 rivo sudo[4534]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jan 11 16:37:06 rivo sudo[4534]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:06 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:06 rivo sudo[4526]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:06 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:06 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:37:06 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:37:06 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:06 rivo sudo[4534]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:06 rivo volumio[3488]: 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: 7 Jan 11 16:37:06 rivo volumio[3488]: info: Asound.conf file unchanged, so no further update is needed Jan 11 16:37:06 rivo volumio[3488]: info: Output device has changed, restarting MPD Jan 11 16:37:06 rivo sudo[4537]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jan 11 16:37:06 rivo sudo[4537]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:07 rivo systemd[1]: Stopping RAAT DAEMON... Jan 11 16:37:07 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jan 11 16:37:07 rivo systemd[1]: raat-daemon.service: Succeeded. Jan 11 16:37:07 rivo systemd[1]: Stopped RAAT DAEMON. Jan 11 16:37:07 rivo volumio[3488]: info: Output device has changed, restarting Shairport Sync Jan 11 16:37:07 rivo sudo[4542]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 16:37:07 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:07 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 16:37:07 rivo sudo[4542]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:07 rivo sudo[4542]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:07 rivo sudo[4544]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 16:37:07 rivo sudo[4544]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:07 rivo systemd[1]: Started RAAT DAEMON. Jan 11 16:37:07 rivo sudo[4537]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:07 rivo go-librespot[4135]: time="2026-01-11T16:37:07+01:00" level=debug msg="fetched first chunk of 20, total size is 10053864 bytes" uri="spotify:track:0Z0WTcYhGpw5HS9OO509X9" Jan 11 16:37:07 rivo go-librespot[4135]: time="2026-01-11T16:37:07+01:00" level=debug msg="created new output device" Jan 11 16:37:07 rivo go-librespot[4135]: time="2026-01-11T16:37:07+01:00" level=info msg="loaded track \"Ricordati di me - Karaoke version\" (paused: true, position: 0ms, duration: 305973ms, prefetched: false)" uri="spotify:track:0Z0WTcYhGpw5HS9OO509X9" Jan 11 16:37:07 rivo volumio[3488]: No protocol specified Jan 11 16:37:07 rivo volumio[3488]: xcb_connection_has_error() returned true Jan 11 16:37:07 rivo volumio[3488]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 16:37:07 rivo volumio[3488]: No protocol specified Jan 11 16:37:07 rivo volumio[3488]: xcb_connection_has_error() returned true Jan 11 16:37:07 rivo volumio[3488]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jan 11 16:37:07 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:07 rivo volumio[3488]: info: QobuzConnect: setDeactiveState invoked Jan 11 16:37:07 rivo go-librespot[4135]: time="2026-01-11T16:37:07+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 11 16:37:07 rivo go-librespot[4135]: time="2026-01-11T16:37:07+01:00" level=trace msg="emitting websocket event: metadata" Jan 11 16:37:07 rivo go-librespot[4135]: time="2026-01-11T16:37:07+01:00" level=trace msg="emitting websocket event: active" Jan 11 16:37:07 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:37:07 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:07 rivo volumio[3488]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Jan 11 16:37:07 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 16:37:07 rivo go-librespot[4135]: time="2026-01-11T16:37:07+01:00" level=debug msg="sending successful reply for dealer request" Jan 11 16:37:07 rivo systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jan 11 16:37:07 rivo systemd[1]: mpd.service: Succeeded. Jan 11 16:37:07 rivo go-librespot[4135]: time="2026-01-11T16:37:07+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 11 16:37:07 rivo systemd[1]: Stopped Music Player Daemon. Jan 11 16:37:07 rivo go-librespot[4135]: time="2026-01-11T16:37:07+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jan 11 16:37:07 rivo volumio[3488]: error: Error starting TidalConnect Cannot read property 'sendRevoke' of undefined {"stack":"TypeError: Cannot read property 'sendRevoke' of undefined\n at ControllerTidalconnect.stopTidalConnect (/volumio/app/plugins/music_service/tidalconnect/tidalconnect_real:1:8526)\n at ControllerTidalconnect.restartService (/volumio/app/plugins/music_service/tidalconnect/tidalconnect_real:1:8818)\n at /volumio/node_modules/v-conf/index.js:165:13\n at /volumio/node_modules/multimap/index.js:150:9\n at Array.forEach ()\n at /volumio/node_modules/multimap/index.js:149:13\n at mapEach (/volumio/node_modules/multimap/index.js:9:5)\n at Multimap.forEachEntry (/volumio/node_modules/multimap/index.js:143:5)\n at Multimap.forEach (/volumio/node_modules/multimap/index.js:148:10)\n at Config.set (/volumio/node_modules/v-conf/index.js:162:20)\n at Promise._successFn (/volumio/app/plugins/audio_interface/alsa_controller/index.js:2112:39)\n at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28)\n at processTicksAndRejections (internal/process/task_queues.js:77:11)"} Jan 11 16:37:07 rivo systemd[1]: Starting Music Player Daemon... Jan 11 16:37:07 rivo go-librespot[4135]: time="2026-01-11T16:37:07+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 11 16:37:07 rivo go-librespot[4135]: time="2026-01-11T16:37:07+01:00" level=trace msg="emitting websocket event: paused" Jan 11 16:37:07 rivo sudo[4565]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jan 11 16:37:07 rivo sudo[4565]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:07 rivo go-librespot[4135]: time="2026-01-11T16:37:07+01:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:0Z0WTcYhGpw5HS9OO509X9" Jan 11 16:37:07 rivo systemd[1]: Stopping Volumio Tidal Connect Service... Jan 11 16:37:07 rivo systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Jan 11 16:37:07 rivo systemd[1]: vtcs.service: Succeeded. Jan 11 16:37:07 rivo systemd[1]: Stopped Volumio Tidal Connect Service. Jan 11 16:37:07 rivo sudo[4565]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:07 rivo go-librespot[4135]: time="2026-01-11T16:37:07+01:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:0Z0WTcYhGpw5HS9OO509X9" Jan 11 16:37:07 rivo sudo[4572]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jan 11 16:37:07 rivo sudo[4572]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:07 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:07 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:37:07 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:37:07 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:07 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 11 16:37:07 rivo go-librespot[4135]: time="2026-01-11T16:37:07+01:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:0Z0WTcYhGpw5HS9OO509X9" Jan 11 16:37:07 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:07 rivo volumio[3488]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 11 16:37:07 rivo sudo[4563]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 16:37:07 rivo sudo[4563]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:07 rivo sudo[4572]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:07 rivo volumio[3488]: info: Shairport-Sync Started Jan 11 16:37:07 rivo volumio[3488]: info: RAAT: Requesting Headphone Status Jan 11 16:37:07 rivo volumio[3488]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jan 11 16:37:07 rivo sudo[4563]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:07 rivo sudo[4574]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jan 11 16:37:07 rivo sudo[4574]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:07 rivo volumio[3488]: info: Getting Spotify volume Jan 11 16:37:07 rivo volumio[3488]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0Z0WTcYhGpw5HS9OO509X9","name":"Ricordati di me - Karaoke version","artist_names":["Italian Hitmakers"],"album_name":"Basi musicale nello stilo dei antonello venditti (instrumental karaoke tracks), Vol. 3","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02f0eeae8f2cbb3bd8fdda7fef","position":0,"duration":305973,"release_date":"year:2014 month:4 day:27","track_number":11,"disc_number":1}} Jan 11 16:37:07 rivo volumio[3488]: SPOTIFY: received: {"type":"active","data":null} Jan 11 16:37:07 rivo volumio[3488]: info: Aligning Spotify Volume to Volumio Volume Jan 11 16:37:07 rivo volumio[3488]: info: CoreCommandRouter::volumioGetState Jan 11 16:37:07 rivo volumio[3488]: info: CorePlayQueue::getTrack 0 Jan 11 16:37:07 rivo volumio[3488]: info: Setting Spotify Volume from Volumio: 100 Jan 11 16:37:07 rivo volumio[3488]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:search:ricordati+di+me+karaoke","uri":"spotify:track:0Z0WTcYhGpw5HS9OO509X9","play_origin":"search"}} Jan 11 16:37:07 rivo volumio[3488]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 16:37:07 rivo volumio[3488]: TypeError: Cannot read property 'service' of undefined Jan 11 16:37:07 rivo volumio[3488]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Jan 11 16:37:07 rivo volumio[3488]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:280:18) Jan 11 16:37:07 rivo volumio[3488]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Jan 11 16:37:07 rivo volumio[3488]: at WebSocket.emit (events.js:400:28) Jan 11 16:37:07 rivo volumio[3488]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Jan 11 16:37:07 rivo volumio[3488]: at Receiver.emit (events.js:400:28) Jan 11 16:37:07 rivo volumio[3488]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Jan 11 16:37:07 rivo volumio[3488]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Jan 11 16:37:07 rivo volumio[3488]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Jan 11 16:37:07 rivo volumio[3488]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Jan 11 16:37:07 rivo volumio[3488]: at writeOrBuffer (internal/streams/writable.js:358:12) Jan 11 16:37:07 rivo volumio[3488]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Jan 11 16:37:07 rivo volumio[3488]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Jan 11 16:37:07 rivo volumio[3488]: at Socket.emit (events.js:400:28) Jan 11 16:37:07 rivo volumio[3488]: at addChunk (internal/streams/readable.js:293:12) Jan 11 16:37:07 rivo volumio[3488]: at readableAddChunk (internal/streams/readable.js:267:9) Jan 11 16:37:07 rivo systemd[1]: Stopping Volumio Qobuz Connect Service... Jan 11 16:37:07 rivo qobuz-connect[4498]: 20260111 16:37:07.750 [4498.4498] INFO SampleApp: Stopping Local configuration server Jan 11 16:37:07 rivo qobuz-connect[4498]: 20260111 16:37:07.771 [4498.4498] INFO SampleApp: shat down connection on UNIX socket Jan 11 16:37:07 rivo volumio[3488]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 16:37:07 rivo systemd[1]: qobuz-connect.service: Succeeded. Jan 11 16:37:07 rivo systemd[1]: Stopped Volumio Qobuz Connect Service. Jan 11 16:37:07 rivo systemd[1]: Started Volumio Qobuz Connect Service. Jan 11 16:37:07 rivo sudo[4574]: pam_unix(sudo:session): session closed for user root Jan 11 16:37:08 rivo go-librespot[4135]: time="2026-01-11T16:37:08+01:00" level=debug msg="update volume requested to 62914/65535" Jan 11 16:37:08 rivo go-librespot[4135]: time="2026-01-11T16:37:08+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Jan 11 16:37:08 rivo go-librespot[4135]: time="2026-01-11T16:37:08+01:00" level=trace msg="emitting websocket event: volume" Jan 11 16:37:09 rivo sudo[4590]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-01-11 16:36 Jan 11 16:37:09 rivo sudo[4590]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 16:37:09 rivo go-librespot[4135]: time="2026-01-11T16:37:09+01:00" level=debug msg="update volume requested to 60292/65535" 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"