-- Logs begin at Mon 2024-11-18 03:08:47 PST, end at Sat 2025-03-08 18:10:24 PST. -- Mar 08 18:09:42 rivo systemd[1]: systemd-rfkill.service: Succeeded. Mar 08 18:09:42 rivo systemd-timedated[3278]: Changed local time to Sat Mar 8 18:09:42 2025 Mar 08 18:09:42 rivo sudo[3276]: pam_unix(sudo:session): session closed for user root Mar 08 18:09:42 rivo startkiosk.sh[3291]: Starting Volumio Kiosk with arguments for cursor display Mar 08 18:09:42 rivo volumio-time-update[2815]: volumio-time-update-util: System time updated successfully. Mar 08 18:09:42 rivo systemd[1]: Started Volumio Time Update Utility. Mar 08 18:09:42 rivo systemd[1]: Starting Daily man-db regeneration... Mar 08 18:09:42 rivo systemd[1]: Starting Daily apt download activities... Mar 08 18:09:42 rivo volumio-cpu-tweak[3290]: Setting RT Priority for mpd Mar 08 18:09:42 rivo volumio-cpu-tweak[3290]: Setting MPD Affinity Mar 08 18:09:42 rivo volumio-cpu-tweak[3290]: pid 3097's current affinity mask: f Mar 08 18:09:42 rivo volumio-cpu-tweak[3290]: pid 3097's new affinity mask: 3 Mar 08 18:09:42 rivo volumio-cpu-tweak[3290]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Mar 08 18:09:42 rivo volumio-cpu-tweak[3290]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Mar 08 18:09:42 rivo systemd[1]: volumio_cpu_tweak.service: Succeeded. Mar 08 18:09:42 rivo systemd[1]: man-db.service: Succeeded. Mar 08 18:09:42 rivo systemd[1]: Started Daily man-db regeneration. Mar 08 18:09:42 rivo ntpd[3272]: Soliciting pool server 198.46.254.130 Mar 08 18:09:42 rivo startkiosk.sh[3291]: X.Org X Server 1.20.4 Mar 08 18:09:42 rivo startkiosk.sh[3291]: X Protocol Version 11, Revision 0 Mar 08 18:09:42 rivo startkiosk.sh[3291]: Build Operating System: Linux 4.19.0-18-armmp-lpae armv7l Debian Mar 08 18:09:42 rivo startkiosk.sh[3291]: Current Operating System: Linux rivo 4.9.241 #30 SMP PREEMPT Tue Oct 15 16:31:40 CEST 2024 aarch64 Mar 08 18:09:42 rivo startkiosk.sh[3291]: Kernel command line: imgpart=UUID=9281938e-eb40-4fd9-af60-342eea236dec imgfile=/volumio_current.sqsh bootpart=UUID=0058-3849 datapart=UUID=1205715d-fe94-45fc-8518-ada4f74f7025 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:11:26:01 fan=auto hwver=Unknow coherent_pool=2M quiet loglevel=0 splash plymouth.ignore-serial-consoles initramfs.clear splash bootdelay=7 Mar 08 18:09:42 rivo startkiosk.sh[3291]: Build Date: 18 December 2021 09:05:36AM Mar 08 18:09:42 rivo startkiosk.sh[3291]: xorg-server 2:1.20.4-1+deb10u4 (https://www.debian.org/support) Mar 08 18:09:42 rivo startkiosk.sh[3291]: Current version of pixman: 0.36.0 Mar 08 18:09:42 rivo startkiosk.sh[3291]: Before reporting problems, check http://wiki.x.org Mar 08 18:09:42 rivo startkiosk.sh[3291]: to make sure that you have the latest version. Mar 08 18:09:42 rivo startkiosk.sh[3291]: Markers: (--) probed, (**) from config file, (==) default setting, Mar 08 18:09:42 rivo startkiosk.sh[3291]: (++) from command line, (!!) notice, (II) informational, Mar 08 18:09:42 rivo startkiosk.sh[3291]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Mar 08 18:09:42 rivo startkiosk.sh[3291]: (==) Log file: "/var/log/Xorg.0.log", Time: Sat Mar 8 18:09:42 2025 Mar 08 18:09:42 rivo startkiosk.sh[3291]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Mar 08 18:09:42 rivo kernel: fb: osd[0] canvas.idx =0x40 Mar 08 18:09:42 rivo kernel: fb: osd[0] canvas.addr=0x70000000 Mar 08 18:09:42 rivo kernel: fb: osd[0] canvas.width=7680 Mar 08 18:09:42 rivo kernel: fb: osd[0] canvas.height=1080 Mar 08 18:09:42 rivo kernel: fb: osd[0] frame.width=1920 Mar 08 18:09:42 rivo kernel: fb: osd[0] frame.height=1080 Mar 08 18:09:42 rivo kernel: fb: osd[0] out_addr_id =0x1 Mar 08 18:09:42 rivo kernel: fb: osd[0] enable: 0 (Xorg) Mar 08 18:09:43 rivo systemd[1]: apt-daily.service: Succeeded. Mar 08 18:09:43 rivo systemd[1]: Started Daily apt download activities. Mar 08 18:09:43 rivo systemd[1]: Starting Daily apt upgrade and clean activities... Mar 08 18:09:43 rivo ntpd[3272]: Soliciting pool server 141.11.234.67 Mar 08 18:09:43 rivo ntpd[3272]: Soliciting pool server 89.116.246.10 Mar 08 18:09:43 rivo kernel: fb: osd[0] enable: 1 (Xorg) Mar 08 18:09:44 rivo systemd[1]: apt-daily-upgrade.service: Succeeded. Mar 08 18:09:44 rivo systemd[1]: Started Daily apt upgrade and clean activities. Mar 08 18:09:44 rivo ntpd[3272]: Soliciting pool server 104.167.215.195 Mar 08 18:09:44 rivo ntpd[3272]: Soliciting pool server 144.202.66.214 Mar 08 18:09:44 rivo ntpd[3272]: Soliciting pool server 198.137.202.32 Mar 08 18:09:44 rivo nmbd[3049]: [2025/03/08 18:09:44.361232, 0] ../lib/util/become_daemon.c:138(daemon_ready) Mar 08 18:09:44 rivo kernel: nf_conntrack: default automatic helper assignment has been turned off for security reasons and CT-based firewall rule not found. Use the iptables CT target to attach helpers instead. Mar 08 18:09:44 rivo nmbd[3049]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Mar 08 18:09:44 rivo systemd[1]: Started Samba NMB Daemon. Mar 08 18:09:44 rivo systemd[1]: Starting Samba Winbind Daemon... Mar 08 18:09:44 rivo kernel: fb: osd[0] enable: 1 (Xorg) Mar 08 18:09:44 rivo winbindd[3455]: [2025/03/08 18:09:44.762471, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Mar 08 18:09:44 rivo winbindd[3455]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Mar 08 18:09:44 rivo winbindd[3455]: [2025/03/08 18:09:44.776606, 0] ../lib/util/become_daemon.c:138(daemon_ready) Mar 08 18:09:44 rivo systemd[1]: Started Samba Winbind Daemon. Mar 08 18:09:44 rivo winbindd[3455]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Mar 08 18:09:44 rivo systemd[1]: Starting Samba SMB Daemon... Mar 08 18:09:45 rivo ntpd[3272]: Soliciting pool server 23.150.41.123 Mar 08 18:09:45 rivo ntpd[3272]: Soliciting pool server 69.30.247.121 Mar 08 18:09:45 rivo ntpd[3272]: Soliciting pool server 51.81.226.229 Mar 08 18:09:45 rivo ntpd[3272]: Soliciting pool server 162.159.200.123 Mar 08 18:09:45 rivo smbd[3483]: [2025/03/08 18:09:45.444838, 0] ../lib/util/become_daemon.c:138(daemon_ready) Mar 08 18:09:45 rivo systemd[1]: Started Samba SMB Daemon. Mar 08 18:09:45 rivo smbd[3483]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Mar 08 18:09:45 rivo systemd[1]: Reached target Multi-User System. Mar 08 18:09:45 rivo systemd[1]: Reached target Graphical Interface. Mar 08 18:09:45 rivo systemd[1]: Starting Update UTMP about System Runlevel Changes... Mar 08 18:09:45 rivo volumio[3289]: info: ------------------------------------------- Mar 08 18:09:45 rivo volumio[3289]: info: ----- Volumio3 ---- Mar 08 18:09:45 rivo volumio[3289]: info: ------------------------------------------- Mar 08 18:09:45 rivo volumio[3289]: info: ----- System startup ---- Mar 08 18:09:45 rivo volumio[3289]: info: ------------------------------------------- Mar 08 18:09:45 rivo systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Mar 08 18:09:45 rivo systemd[1]: Started Update UTMP about System Runlevel Changes. Mar 08 18:09:45 rivo systemd[1]: Startup finished in 13.027s (kernel) + 23.991s (userspace) = 37.019s. Mar 08 18:09:46 rivo ntpd[3272]: Soliciting pool server 104.152.220.5 Mar 08 18:09:46 rivo ntpd[3272]: Soliciting pool server 51.81.209.232 Mar 08 18:09:46 rivo volumio[3289]: info: MYVOLUMIO Environment detected Mar 08 18:09:46 rivo volumio[3289]: info: Plugin folders cleanup Mar 08 18:09:46 rivo volumio[3289]: info: Scanning into folder /volumio/app/plugins/ Mar 08 18:09:46 rivo volumio[3289]: info: Scanning category audio_interface Mar 08 18:09:46 rivo volumio[3289]: info: Scanning category miscellanea Mar 08 18:09:46 rivo volumio[3289]: info: Scanning category music_service Mar 08 18:09:46 rivo volumio[3289]: info: Scanning category plugins.json Mar 08 18:09:46 rivo volumio[3289]: info: Scanning category system_controller Mar 08 18:09:46 rivo volumio[3289]: info: Scanning category user_interface Mar 08 18:09:46 rivo volumio[3289]: info: Scanning into folder /data/plugins/ Mar 08 18:09:46 rivo volumio[3289]: info: Scanning category music_service Mar 08 18:09:46 rivo volumio[3289]: info: Plugin folders cleanup completed Mar 08 18:09:46 rivo volumio[3289]: info: ------------------------------------------- Mar 08 18:09:46 rivo volumio[3289]: info: ----- Core plugins startup ---- Mar 08 18:09:46 rivo volumio[3289]: info: ------------------------------------------- Mar 08 18:09:46 rivo volumio[3289]: info: Loading plugins from folder /volumio/app/plugins/ Mar 08 18:09:46 rivo volumio[3289]: info: Adding plugin bluetooth to MyMusic Plugins Mar 08 18:09:46 rivo volumio[3289]: info: Adding plugin multiroom to MyMusic Plugins Mar 08 18:09:46 rivo volumio[3289]: info: Adding plugin upnp to MyMusic Plugins Mar 08 18:09:46 rivo volumio[3289]: info: Adding plugin metavolumio to MyMusic Plugins Mar 08 18:09:46 rivo volumio[3289]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 08 18:09:46 rivo volumio[3289]: info: Adding plugin cd_controller to MyMusic Plugins Mar 08 18:09:46 rivo volumio[3289]: info: Adding plugin raat to MyMusic Plugins Mar 08 18:09:46 rivo volumio[3289]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 08 18:09:46 rivo volumio[3289]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 08 18:09:46 rivo volumio[3289]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 08 18:09:46 rivo volumio[3289]: info: Loading plugins from folder /data/plugins/ Mar 08 18:09:46 rivo volumio[3289]: info: Loading plugin "system"... Mar 08 18:09:47 rivo volumio[3289]: info: Loading plugin "appearance"... Mar 08 18:09:47 rivo ntpd[3272]: Soliciting pool server 23.168.136.132 Mar 08 18:09:47 rivo ntpd[3272]: Soliciting pool server 2607:f1c0:f04e:fd00::1 Mar 08 18:09:48 rivo volumio[3289]: info: Loading plugin "network"... Mar 08 18:09:48 rivo volumio[3289]: info: Refreshing Cached IP Addresses Mar 08 18:09:48 rivo sudo[3518]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 08 18:09:48 rivo sudo[3518]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:09:48 rivo sudo[3520]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 08 18:09:48 rivo sudo[3520]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:09:48 rivo sudo[3518]: pam_unix(sudo:session): session closed for user root Mar 08 18:09:48 rivo volumio[3289]: info: Loading plugin "services"... Mar 08 18:09:48 rivo volumio[3289]: info: Loading plugin "alsa_controller"... Mar 08 18:09:48 rivo sudo[3520]: pam_unix(sudo:session): session closed for user root Mar 08 18:09:48 rivo sudo[3532]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 08 18:09:48 rivo sudo[3532]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:09:48 rivo kernel: wl_escan_set_scan: ioctl_ver=2 Mar 08 18:09:48 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:48 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:48 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:48 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:48 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:48 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:48 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:48 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:48 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:48 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:48 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:48 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:48 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:48 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 08 18:09:48 rivo volumio[3289]: info: Loading plugin "wizard"... Mar 08 18:09:48 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:48 rivo volumio[3289]: info: Loading plugin "networkfs"... Mar 08 18:09:48 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:48 rivo volumio[3289]: info: Starting Udev Watcher for removable devices Mar 08 18:09:49 rivo volumio[3289]: info: Ignoring mount for partition: BOOT Mar 08 18:09:49 rivo volumio[3289]: info: Ignoring mount for partition: volumio Mar 08 18:09:49 rivo volumio[3289]: info: Ignoring mount for partition: volumio_data Mar 08 18:09:49 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 08 18:09:49 rivo volumio[3289]: info: Loading plugin "volumio_command_line_client"... Mar 08 18:09:49 rivo volumio[3289]: info: Loading plugin "upnp"... Mar 08 18:09:49 rivo volumio[3289]: info: [1741486189098] Starting Upmpd Daemon Mar 08 18:09:49 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 08 18:09:49 rivo volumio[3289]: info: Loading plugin "my_music"... Mar 08 18:09:49 rivo volumio[3289]: info: Loading plugin "mpd"... Mar 08 18:09:49 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo volumio[3289]: info: Loading plugin "upnp_browser"... Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:50 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:51 rivo volumio[3289]: info: Loading plugin "bluetooth"... Mar 08 18:09:51 rivo volumio[3289]: info: [1741486191350] Starting BluetoothController Mar 08 18:09:51 rivo volumio-remote-updater[2813]: [2025-03-08 18:09:51] [connect] Successful connection Mar 08 18:09:51 rivo volumio[3289]: info: Loading plugin "alarm-clock"... Mar 08 18:09:51 rivo volumio[3289]: info: Loading plugin "manifestui"... Mar 08 18:09:51 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:52 rivo volumio[3289]: info: Loading plugin "metavolumio"... Mar 08 18:09:52 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:53 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:53 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:53 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 8 Mar 08 18:09:53 rivo volumio[3289]: info: Loading plugin "airplay_emulation"... Mar 08 18:09:53 rivo volumio[3289]: info: Starting Shairport Sync Mar 08 18:09:53 rivo volumio[3289]: info: Loading plugin "cd_controller"... Mar 08 18:09:54 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04da40000 drv_status 0x0 e_type 69 e_states 0 Mar 08 18:09:54 rivo sudo[3532]: pam_unix(sudo:session): session closed for user root Mar 08 18:09:54 rivo volumio[3289]: info: Loading plugin "last_100"... Mar 08 18:09:54 rivo volumio[3289]: info: Loading plugin "raat"... Mar 08 18:09:54 rivo volumio[3289]: info: RAAT Plugin loaded Mar 08 18:09:54 rivo volumio[3289]: info: Adding restartRAATSocket REST API Endpoint Mar 08 18:09:54 rivo volumio[3289]: info: Adding restartRAATSocket REST Endpoint for plugin: music_service/raat Mar 08 18:09:54 rivo volumio[3289]: info: Loading plugin "streaming_services"... Mar 08 18:09:55 rivo systemd[1]: systemd-fsckd.service: Succeeded. Mar 08 18:09:56 rivo volumio[3289]: info: Starting Streaming Service Transparent Proxy Mar 08 18:09:57 rivo volumio[3289]: info: Loading plugin "tidalconnect"... Mar 08 18:09:57 rivo volumio[3289]: info: Loading plugin "webradio"... Mar 08 18:09:57 rivo volumio[3289]: info: Loading plugin "i2s_dacs"... Mar 08 18:09:57 rivo volumio[3289]: info: I2S DAC not set, start Auto-detection Mar 08 18:09:57 rivo volumio[3289]: info: Loading plugin "volumiodiscovery"... Mar 08 18:09:57 rivo volumio[3289]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 08 18:09:57 rivo volumio[3289]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 08 18:09:57 rivo node[3289]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 08 18:09:57 rivo volumio[3289]: *** WARNING *** For more information see Mar 08 18:09:57 rivo volumio[3289]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 08 18:09:57 rivo volumio[3289]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 08 18:09:57 rivo volumio[3289]: *** WARNING *** For more information see Mar 08 18:09:57 rivo node[3289]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 08 18:09:57 rivo volumio[3289]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 08 18:09:57 rivo node[3289]: *** WARNING *** For more information see Mar 08 18:09:57 rivo node[3289]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 08 18:09:57 rivo node[3289]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 08 18:09:57 rivo node[3289]: *** WARNING *** For more information see Mar 08 18:09:57 rivo volumio[3289]: info: Discovery: Started advertising with name: Rivo Mar 08 18:09:57 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 08 18:09:57 rivo volumio[3289]: info: Loading plugin "spop"... Mar 08 18:09:58 rivo sh[2739]: timed out Mar 08 18:09:58 rivo sh[2739]: dhcpcd exited Mar 08 18:09:58 rivo dhcpcd[2789]: timed out Mar 08 18:09:58 rivo systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Mar 08 18:09:58 rivo sh[2739]: ifup: failed to bring up eth0 Mar 08 18:09:58 rivo dhcpcd[2789]: dhcpcd exited Mar 08 18:09:58 rivo systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Mar 08 18:09:58 rivo volumio[3289]: STREAMING PROXY: Starting server on port 3245 Mar 08 18:09:58 rivo volumio[3289]: Node JS runtime: 14 Mar 08 18:10:00 rivo volumio[3289]: info: Loading plugin "multiroom"... Mar 08 18:10:02 rivo volumio[3289]: info: Applying required configuration parameters for plugin multiroom Mar 08 18:10:02 rivo sudo[3744]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Mar 08 18:10:02 rivo sudo[3744]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:02 rivo sudo[3744]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:02 rivo volumio[3289]: info: MRS: MultiRoom plugin initialized Mar 08 18:10:02 rivo volumio[3289]: info: MRS: STOPPING SNAPCLIENT Mar 08 18:10:02 rivo volumio[3289]: info: MRS: Snap server stop Mar 08 18:10:02 rivo volumio[3289]: info: MRS: STOPPING volumioStreaming Mar 08 18:10:02 rivo sudo[3760]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Mar 08 18:10:02 rivo sudo[3760]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:02 rivo sudo[3762]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Mar 08 18:10:02 rivo sudo[3762]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:02 rivo volumio[3289]: info: Loading plugin "outputs"... Mar 08 18:10:02 rivo volumio[3289]: info: Loading plugin "albumart"... Mar 08 18:10:02 rivo sudo[3767]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Mar 08 18:10:02 rivo sudo[3767]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:02 rivo sudo[3768]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Mar 08 18:10:02 rivo sudo[3768]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:02 rivo sudo[3768]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:02 rivo sudo[3760]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:02 rivo sudo[3762]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:02 rivo volumio[3289]: info: Plugin example_plugin is not enabled Mar 08 18:10:02 rivo volumio[3289]: info: Loading plugin "hi_res_audio"... Mar 08 18:10:02 rivo sudo[3767]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:03 rivo volumio[3289]: Forking 3 albumart workers Mar 08 18:10:04 rivo volumio[3289]: Starting albumart workers Mar 08 18:10:04 rivo volumio[3289]: Starting albumart workers Mar 08 18:10:04 rivo volumio[3289]: Starting albumart workers Mar 08 18:10:04 rivo volumio[3289]: info: Applying required configuration parameters for plugin hi_res_audio Mar 08 18:10:04 rivo volumio[3289]: info: Loading plugin "inputs"... Mar 08 18:10:05 rivo volumio[3289]: info: Loading plugin "qobuz"... Mar 08 18:10:06 rivo volumio-remote-updater[2813]: [2025-03-08 18:10:06] [connect] Successful connection Mar 08 18:10:07 rivo volumio[3289]: info: Loading plugin "smart_inputs"... Mar 08 18:10:07 rivo volumio[3289]: info: Loading plugin "tidal"... Mar 08 18:10:08 rivo systemd[1]: systemd-hostnamed.service: Succeeded. Mar 08 18:10:09 rivo volumio[3289]: info: Loading plugin "rivocontrol"... Mar 08 18:10:09 rivo volumio[3289]: info: Adding this device properties Mar 08 18:10:09 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , setThisDeviceVolumioProperties Mar 08 18:10:09 rivo volumio[3289]: info: Setting Additional Device Volumio Properties: [object Object] Mar 08 18:10:09 rivo volumio[3289]: info: Loading plugin "updater_comm"... Mar 08 18:10:10 rivo volumio[3289]: info: Loading plugin "cec_controller"... Mar 08 18:10:10 rivo volumio[3289]: info: Applying required configuration parameters for plugin cec_controller Mar 08 18:10:10 rivo volumio[3289]: info: Plugin mpdemulation is not enabled Mar 08 18:10:10 rivo volumio[3289]: info: Loading plugin "rest_api"... Mar 08 18:10:10 rivo volumio[3289]: info: Loading plugin "websocket"... Mar 08 18:10:10 rivo volumio[3289]: info: Starting Socket.io Server version 2.3.0 Mar 08 18:10:10 rivo volumio[3289]: info: Loading i18n strings for locale en Mar 08 18:10:10 rivo volumio[3289]: Updating browse sources language Mar 08 18:10:10 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 08 18:10:10 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 08 18:10:10 rivo volumio[3289]: info: CoreCommandRouter::initPlayerControls Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 08 18:10:11 rivo volumio[3289]: Express server listening on port 3000 Mar 08 18:10:11 rivo volumio[3289]: [Metrics] WebUI: 25s 876.31ms Mar 08 18:10:11 rivo volumio[3289]: info: CoreStateMachine::resetVolumioState Mar 08 18:10:11 rivo volumio[3289]: info: CoreStateMachine::getcurrentVolume Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::volumioRetrievevolume Mar 08 18:10:11 rivo volumio[3289]: info: CoreStateMachine::pushState Mar 08 18:10:11 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::volumioPushState Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 08 18:10:11 rivo sudo[3849]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 08 18:10:11 rivo sudo[3849]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:11 rivo sudo[3849]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:11 rivo volumio[3289]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Mar 08 18:10:11 rivo volumio[3289]: info: Completed loading Core Plugins Mar 08 18:10:11 rivo sudo[3851]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 08 18:10:11 rivo volumio[3289]: info: Preparing to generate the ALSA configuration file Mar 08 18:10:11 rivo sudo[3851]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:11 rivo sudo[3851]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:11 rivo volumio[3289]: info: Cannot read play queue from file Mar 08 18:10:11 rivo volumio[3289]: info: Volumio Network Manager: Network status updated: 2 Mar 08 18:10:11 rivo volumio[3289]: info: MRS: Removed streaming files Mar 08 18:10:11 rivo volumio[3289]: info: MRS: volumioStreaming STOPPED Mar 08 18:10:11 rivo volumio[3289]: info: MRS: SNAPSERVER STOPPED Mar 08 18:10:11 rivo volumio[3289]: info: MRS: SNAPCLIENT STOPPED Mar 08 18:10:11 rivo volumio[3289]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Mar 08 18:10:11 rivo volumio[3289]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Mar 08 18:10:11 rivo volumio[3289]: info: Reading ALSA contributions from plugins. Mar 08 18:10:11 rivo volumio-remote-updater[2813]: [2025-03-08 18:10:11] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1741486206 101 Mar 08 18:10:11 rivo volumio[3289]: 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: 1 Mar 08 18:10:11 rivo volumio[3289]: info: CoreStateMachine::setRepeat false single undefined Mar 08 18:10:11 rivo volumio[3289]: info: CoreStateMachine::pushState Mar 08 18:10:11 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::volumioPushState Mar 08 18:10:11 rivo volumio[3289]: info: CoreStateMachine::setRandom null Mar 08 18:10:11 rivo volumio[3289]: info: CoreStateMachine::pushState Mar 08 18:10:11 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::volumioPushState Mar 08 18:10:11 rivo volumio[3289]: info: Discovery: adding 5d535139-7c0c-497e-ba2f-256a26496108 Mar 08 18:10:11 rivo volumio[3289]: info: Discovery: Found device Rivo Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::volumioGetState Mar 08 18:10:11 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:11 rivo sudo[3866]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 08 18:10:11 rivo sudo[3866]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:11 rivo volumio[3289]: info: MRS: Pushing multiroomSync output for this device Mar 08 18:10:11 rivo volumio[3289]: info: MRS: Pushing multiroomSync output Mar 08 18:10:11 rivo volumio[3289]: info: Adding audio output: Mar 08 18:10:11 rivo volumio[3289]: info: Adding audio output: Mar 08 18:10:11 rivo volumio[3289]: info: Asound.conf file unchanged, so no further update is needed Mar 08 18:10:11 rivo volumio[3289]: info: Output device has changed, restarting MPD Mar 08 18:10:11 rivo kernel: fb: mem_free_work, free memory: addr:800000 Mar 08 18:10:11 rivo sudo[3869]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 08 18:10:11 rivo volumio[3289]: info: Output device has changed, restarting Shairport Sync Mar 08 18:10:11 rivo sudo[3869]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:11 rivo systemd[1]: Started UPnP Renderer front-end to MPD. Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:11 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 08 18:10:11 rivo sudo[3866]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:11 rivo sudo[3869]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:11 rivo sudo[3871]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 08 18:10:11 rivo sudo[3871]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:12 rivo systemd[1]: Stopping Music Player Daemon... Mar 08 18:10:12 rivo volumio[3289]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 08 18:10:12 rivo volumio[3289]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:12 rivo volumio[3289]: info: ___________ START PLUGINS ___________ Mar 08 18:10:12 rivo systemd[1]: mpd.service: Succeeded. Mar 08 18:10:12 rivo systemd[1]: Stopped Music Player Daemon. Mar 08 18:10:12 rivo volumio[3289]: info: ControllerMpd::onStart: Initializing MPD Mar 08 18:10:12 rivo volumio[3289]: info: Creating MPD Configuration file Mar 08 18:10:12 rivo systemd[1]: Starting Music Player Daemon... Mar 08 18:10:12 rivo kernel: aml_spdif_open Mar 08 18:10:12 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Mar 08 18:10:12 rivo kernel: spdif_a keep clk continuous Mar 08 18:10:12 rivo kernel: aml_spdif_close Mar 08 18:10:12 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 08 18:10:12 rivo sudo[3889]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 08 18:10:12 rivo sudo[3889]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:12 rivo volumio[3289]: info: [1741486212203] CoreMusicLibrary::Adding element Media Servers Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 08 18:10:12 rivo sudo[3889]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 08 18:10:12 rivo sudo[3893]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 08 18:10:12 rivo sudo[3893]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:12 rivo volumio[3289]: info: Adding METAVOLUMIO REST API Endpoints Mar 08 18:10:12 rivo volumio[3289]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Mar 08 18:10:12 rivo volumio[3289]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Mar 08 18:10:12 rivo volumio[3289]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Mar 08 18:10:12 rivo volumio[3289]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 08 18:10:12 rivo systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Mar 08 18:10:12 rivo systemd[1]: mpd.service: Succeeded. Mar 08 18:10:12 rivo systemd[1]: Stopped Music Player Daemon. Mar 08 18:10:12 rivo sudo[3896]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Rivo Mar 08 18:10:12 rivo sudo[3896]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:12 rivo systemd[1]: Starting Music Player Daemon... Mar 08 18:10:12 rivo sudo[3896]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:12 rivo volumio[3289]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 08 18:10:12 rivo volumio[3289]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 08 18:10:12 rivo volumio[3289]: info: Preparing CD Folders Mar 08 18:10:12 rivo volumio[3289]: info: Adding CD REST API Endpoints Mar 08 18:10:12 rivo volumio[3289]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Mar 08 18:10:12 rivo volumio[3289]: info: Starting UDEV Watcher for CD Mar 08 18:10:12 rivo volumio[3289]: info: Detecting CD presence with UDEV Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Mar 08 18:10:12 rivo sudo[3898]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 08 18:10:12 rivo sudo[3898]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:12 rivo sudo[3898]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 08 18:10:12 rivo volumio[3289]: info: [1741486212498] CoreMusicLibrary::Adding element Last_100 Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 08 18:10:12 rivo volumio[3289]: info: Starting RAAT Plugin Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Mar 08 18:10:12 rivo volumio[3289]: info: Additional UI Settings Added for plugin music_service/raat Mar 08 18:10:12 rivo volumio[3289]: info: Registering DSP Elements listener and retrieving current ones Mar 08 18:10:12 rivo volumio[3289]: info: Additional DSP elements updated Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:12 rivo volumio[3289]: info: Updating RAAT Signal Path Mar 08 18:10:12 rivo volumio[3289]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Mar 08 18:10:12 rivo volumio[3289]: info: Streaming services startup Mar 08 18:10:12 rivo volumio[3289]: info: Starting Streaming Daemon Mar 08 18:10:12 rivo sudo[3912]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 08 18:10:12 rivo sudo[3912]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:12 rivo sudo[3912]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 08 18:10:12 rivo volumio[3289]: info: [1741486212689] CoreMusicLibrary::Adding element Webradio Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 08 18:10:12 rivo volumio[3289]: info: Initializing BBC Radios Mar 08 18:10:12 rivo sudo[3920]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 08 18:10:12 rivo sudo[3920]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:12 rivo sudo[3920]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 08 18:10:12 rivo volumio[3289]: info: Creating Spotify config file Mar 08 18:10:12 rivo systemd[1]: systemd-timedated.service: Succeeded. Mar 08 18:10:12 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Mar 08 18:10:13 rivo volumio[3289]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 08 18:10:13 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:13 rivo volumio[3289]: error: Hi Res Audio Failed Login: Missing Login Data Mar 08 18:10:13 rivo volumio[3289]: info: Adding HIGHRESAUDIO REST API Endpoints Mar 08 18:10:13 rivo volumio[3289]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Mar 08 18:10:13 rivo volumio[3289]: info: Initializing Serial Communication on port /dev/ttyS3 Mar 08 18:10:13 rivo volumio[3289]: info: Touch Event Listener Process Starting Mar 08 18:10:13 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 0 to 9600 Mar 08 18:10:13 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 9600 to 9600 Mar 08 18:10:13 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 9600 to 115200 Mar 08 18:10:13 rivo kernel: aml_spdif_open Mar 08 18:10:13 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Mar 08 18:10:13 rivo kernel: spdif_a keep clk continuous Mar 08 18:10:13 rivo kernel: aml_spdif_close Mar 08 18:10:13 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Mar 08 18:10:13 rivo volumio[3289]: info: Adding inputs REST Endpoints Mar 08 18:10:13 rivo volumio[3289]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Mar 08 18:10:13 rivo volumio[3289]: info: Scanning Audio Inputs Mar 08 18:10:13 rivo sudo[3940]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xinput --test-xi2 --root Mar 08 18:10:13 rivo sudo[3940]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:13 rivo volumio[3289]: info: Checking against Known Cards name Mar 08 18:10:13 rivo volumio[3289]: info: Checking against Known Cards name Mar 08 18:10:13 rivo volumio[3289]: info: Checking against Known Cards name Mar 08 18:10:13 rivo volumio[3289]: info: Checking against Known Cards name Mar 08 18:10:13 rivo volumio[3289]: info: Checking against Known Cards name Mar 08 18:10:13 rivo volumio[3289]: info: Adding Server instance for streaming Mar 08 18:10:13 rivo sudo[3951]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x25 0x0 Mar 08 18:10:13 rivo sudo[3951]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:13 rivo sudo[3951]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:13 rivo sudo[3954]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x28 0x0 Mar 08 18:10:13 rivo sudo[3954]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:13 rivo sudo[3954]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:13 rivo sudo[3957]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x29 0x1 Mar 08 18:10:13 rivo sudo[3957]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:13 rivo sudo[3957]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:13 rivo sudo[3960]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x33 0x1 Mar 08 18:10:13 rivo sudo[3960]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:13 rivo sudo[3960]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:13 rivo volumio[3289]: info: Apply VIM3L Onboard LEDs Settings Mar 08 18:10:13 rivo volumio[3289]: info: Turning On Onboard LEDs Mar 08 18:10:13 rivo volumio[3289]: info: Starting CEC Event listener Mar 08 18:10:13 rivo sudo[3964]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/sys_led/trigger Mar 08 18:10:13 rivo sudo[3964]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:13 rivo volumio[3289]: info: Volumio Calling Home Mar 08 18:10:13 rivo sudo[3964]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:13 rivo sudo[3969]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/red_red/trigger Mar 08 18:10:13 rivo sudo[3969]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:13 rivo volumio[3289]: (node:3289) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Mar 08 18:10:13 rivo volumio[3289]: (Use `node --trace-deprecation ...` to show where the warning was created) Mar 08 18:10:13 rivo sudo[3969]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:13 rivo volumio[3289]: info: Stopping AccessToken refresher cron for QOBUZ Mar 08 18:10:13 rivo volumio[3289]: info: AccessToken refresher cron started for QOBUZ Mar 08 18:10:13 rivo volumio[3289]: info: Stopping AccessToken refresher cron Mar 08 18:10:14 rivo volumio[3289]: info: AccessToken refresher cron started Mar 08 18:10:14 rivo volumio[3289]: info: Adding TIDAL REST API Endpoints Mar 08 18:10:14 rivo volumio[3289]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Mar 08 18:10:14 rivo volumio[3289]: info: Adding QOBUZ REST API Endpoints Mar 08 18:10:14 rivo volumio[3289]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Mar 08 18:10:14 rivo volumio[3289]: info: Serial port opened successfully Mar 08 18:10:14 rivo volumio[3289]: info: Sending serial start messages Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: Reporting MCU Network Status: 2 Mar 08 18:10:14 rivo volumio[3289]: info: MP1 GPIO: Signalled system ready via GPIO Mar 08 18:10:14 rivo volumio[3289]: error: Cannot start Volumio Streaming Daemon Mar 08 18:10:14 rivo volumio[3289]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 08 18:10:14 rivo volumio[3289]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 08 18:10:14 rivo volumio[3289]: info: RAAT Albumart path created successfully Mar 08 18:10:14 rivo volumio[3289]: info: Bluetooth name changed to Rivo Mar 08 18:10:14 rivo volumio[3289]: info: MPD Permissions set Mar 08 18:10:14 rivo volumio[3289]: info: MPD Permissions set Mar 08 18:10:14 rivo volumio[3289]: info: Upmpdcli Daemon Started Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setDeviceVolumeOverride Mar 08 18:10:14 rivo volumio[3289]: info: Setting Device Volume Override Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::volumioUpdateVolumeSettings Mar 08 18:10:14 rivo volumio[3289]: info: Updating Volume Controller Parameters: Device: 0,2 Name: S/PDIF + AES/EBU Mixer: Audio hdmi-out mute Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Mar 08 18:10:14 rivo volumio[3289]: info: Disabling external Volume Control Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreStateMachine::pushState Mar 08 18:10:14 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::volumioPushState Mar 08 18:10:14 rivo volumio[3289]: info: MRS: Pushing multiroomSync output update for this device Mar 08 18:10:14 rivo volumio[3289]: info: MRS: Pushing multiroomSync output Mar 08 18:10:14 rivo volumio[3289]: info: CoreStateMachine::pushState Mar 08 18:10:14 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::volumioPushState Mar 08 18:10:14 rivo volumio[3289]: info: MRS: Pushing multiroomSync output update for this device Mar 08 18:10:14 rivo volumio[3289]: info: MRS: Pushing multiroomSync output Mar 08 18:10:14 rivo volumio[3289]: info: Volumio called home Mar 08 18:10:14 rivo volumio[3289]: info: Spotify config file written Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Mar 08 18:10:14 rivo volumio[3289]: info: Setting Additional System Software info: Hardware Revision: 2.1 Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Mar 08 18:10:14 rivo volumio[3289]: info: Setting HW Firmware info: undefined Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Mar 08 18:10:14 rivo volumio[3289]: info: Setting HW Version info: 2.1 Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Mar 08 18:10:14 rivo volumio[3289]: info: Setting Additional System Software info: Hardware Revision: 2.1, Firmware Version: 0.3.4 Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Mar 08 18:10:14 rivo volumio[3289]: info: Setting HW Firmware info: 0.3.4 Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Mar 08 18:10:14 rivo volumio[3289]: info: Setting HW Version info: 2.1 Mar 08 18:10:14 rivo volumio[3289]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Mar 08 18:10:14 rivo volumio[3289]: info: MCU Signalled Headphone Mode Disabled Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Mar 08 18:10:14 rivo volumio[3289]: info: Reporting Headphone State: false Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: Updating RAAT Signal Path Mar 08 18:10:14 rivo volumio[3289]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Mar 08 18:10:14 rivo volumio[3289]: info: MCU Signalled Sleep Mode Disabled Mar 08 18:10:14 rivo sudo[3990]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 08 18:10:14 rivo sudo[3990]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:14 rivo volumio[3289]: info: Enabling Advanced system settings configuration Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , addAdditionalUISections Mar 08 18:10:14 rivo volumio[3289]: info: Additional UI Settings Added for plugin music_service/inputs Mar 08 18:10:14 rivo volumio[3289]: info: MCU Signalled Auto Boot Mode On Power Disabled Mar 08 18:10:14 rivo systemd[1]: Started go-librespot Daemon. Mar 08 18:10:14 rivo sudo[3990]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:14 rivo go-librespot[3994]: Librespot-go daemon starting... Mar 08 18:10:14 rivo sudo[3993]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force on Mar 08 18:10:14 rivo sudo[3993]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:14 rivo volumio[3289]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo sudo[3993]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:14 rivo kernel: fb: osd[0] enable: 1 (Xorg) Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Mar 08 18:10:14 rivo go-librespot[3994]: time="2025-03-08T18:10:14-08:00" level=info msg="generated new device id: 491a55480982276f8dc66d8054e67e6109a49be6" Mar 08 18:10:14 rivo go-librespot[3994]: time="2025-03-08T18:10:14-08:00" level=debug msg="stored credentials found for cormarch" Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 08 18:10:14 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Mar 08 18:10:15 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 08 18:10:15 rivo volumio[3289]: error: Serial API: Failed to decode command: MAXVOL, message: 100 Mar 08 18:10:15 rivo volumio[3289]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 08 18:10:15 rivo mpd[3909]: Mar 08 18:10 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 08 18:10:15 rivo systemd[1]: Started Music Player Daemon. Mar 08 18:10:15 rivo sudo[3871]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:15 rivo sudo[3893]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:15 rivo sudo[4019]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms 0 0 0 Mar 08 18:10:15 rivo sudo[4019]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:15 rivo sudo[4019]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:15 rivo sudo[4022]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Mar 08 18:10:15 rivo sudo[4022]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:15 rivo volumio[3289]: Upnp client error: Error: This socket has been ended by the other party Mar 08 18:10:15 rivo systemd[1]: Started Volumio Bluetooth Module. Mar 08 18:10:15 rivo volumio[3289]: info: Starting Shairport Sync Mar 08 18:10:15 rivo sudo[4022]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:15 rivo volumio[3289]: info: Starting Shairport Sync Mar 08 18:10:15 rivo sudo[4030]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Mar 08 18:10:15 rivo sudo[4030]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:15 rivo volumiobt[4026]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Mar 08 18:10:15 rivo sudo[4030]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:15 rivo sudo[4031]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 08 18:10:15 rivo sudo[4031]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:15 rivo volumio[3289]: info: Starting Shairport Sync Mar 08 18:10:15 rivo go-librespot[3994]: time="2025-03-08T18:10:15-08:00" level=debug msg="obtained new client token: AAD6iatBfQ5Mk/PJ3wir59u76smRvwvX6jKs4OPf8PoG0NMW8MHPeVGzF/xYnLG1lTM1xI1uwG5kK8MsbzGdNJJeyabkXJSpnoQ8plBn07rNotLBw3PZLDzhceiGBookFJpPEWD8gN8T49QXoYl9SigjQsDYHd9gBrPqokHTSKzHgGDUWRNxD2hmji8bqXNfbu5Z98lIXxmqqpIgw4l2qcmJZAT63cGzQ25UpbROMX1ktoyH/gaM+O6w2ZE1iWw=" Mar 08 18:10:15 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 08 18:10:15 rivo volumio[3289]: info: Adding Inputs via Serial API Mar 08 18:10:15 rivo volumio[3289]: info: CoreStateMachine::pushState Mar 08 18:10:15 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:15 rivo sudo[4036]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 08 18:10:15 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 08 18:10:15 rivo volumio[3289]: info: CoreCommandRouter::volumioPushState Mar 08 18:10:15 rivo sudo[4036]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:15 rivo systemd[1]: shairport-sync.service: Succeeded. Mar 08 18:10:15 rivo volumio[3289]: info: MRS: Pushing multiroomSync output update for this device Mar 08 18:10:15 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 08 18:10:15 rivo volumio[3289]: info: MRS: Pushing multiroomSync output Mar 08 18:10:15 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 08 18:10:15 rivo sudo[4031]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:15 rivo sudo[4038]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 08 18:10:15 rivo sudo[4038]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:15 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 08 18:10:15 rivo systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Mar 08 18:10:15 rivo systemd[1]: shairport-sync.service: Succeeded. Mar 08 18:10:15 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 08 18:10:15 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 08 18:10:15 rivo sudo[4036]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:15 rivo volumio[3289]: info: CoreCommandRouter::volumioGetState Mar 08 18:10:15 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:15 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 08 18:10:15 rivo systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Mar 08 18:10:15 rivo systemd[1]: shairport-sync.service: Succeeded. Mar 08 18:10:15 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 08 18:10:15 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 08 18:10:15 rivo sudo[4038]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:15 rivo volumio[3289]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 08 18:10:15 rivo go-librespot[3994]: time="2025-03-08T18:10:15-08:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 08 18:10:15 rivo volumio[3289]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 08 18:10:15 rivo volumio[3289]: error: MPD error: The expression evaluated to a falsy value: Mar 08 18:10:15 rivo volumio[3289]: assert.ok(self.idling) Mar 08 18:10:15 rivo volumio[3289]: error: The expression evaluated to a falsy value: Mar 08 18:10:15 rivo volumio[3289]: assert.ok(self.idling) Mar 08 18:10:16 rivo volumio[3289]: info: CoreCommandRouter::volumioGetState Mar 08 18:10:16 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:16 rivo go-librespot[3994]: time="2025-03-08T18:10:16-08:00" level=debug msg="completed keyexchange" Mar 08 18:10:16 rivo volumio[3289]: info: Shairport-Sync Started Mar 08 18:10:16 rivo volumio[3289]: Error adding Membership: Error: addMembership EINVAL Mar 08 18:10:16 rivo volumio[3289]: info: Shairport-Sync Started Mar 08 18:10:16 rivo volumio[3289]: info: MPD running with PID3909 Mar 08 18:10:16 rivo volumio[3289]: ,establishing connection Mar 08 18:10:16 rivo volumio[3289]: info: Volumio BT Module successfully started Mar 08 18:10:16 rivo volumio[3289]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 08 18:10:16 rivo volumio[3289]: error: updateQueue error: null Mar 08 18:10:16 rivo volumio[3289]: info: TidalConnect service stoped! Mar 08 18:10:16 rivo volumio[3289]: info: Shairport-Sync Started Mar 08 18:10:16 rivo volumio[3289]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 08 18:10:16 rivo volumio[3289]: SPOTIFY: BQA9HMXqofa2PV6JGdMwVNAbHJLheYN_Ro1TmHy51TNo-rzygAFXg9NaMJf_FD9ZohDp4TfW3_25oMUg16NScgL8kzedcV6vqGVWOSYSTS57-FBDlgGN6fU8-bf7qUycjxCyqewb9Y0GLUaZ4u5_5uIQHLIf38Nz-LJPV4gxSBYbXL9irv6Ff-FheaQAN-VjvAEoKg5iQDPYFzFobgQc2eizO9gldw81vMKMpu9Hj5DnxsmSeDqY4KuixJGcNeumoJwj7uMp0RUR4zvk Mar 08 18:10:16 rivo volumio[3289]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 08 18:10:16 rivo volumio[3289]: info: New Spotify access token = BQA9HMXqofa2PV6JGdMwVNAbHJLheYN_Ro1TmHy51TNo-rzygAFXg9NaMJf_FD9ZohDp4TfW3_25oMUg16NScgL8kzedcV6vqGVWOSYSTS57-FBDlgGN6fU8-bf7qUycjxCyqewb9Y0GLUaZ4u5_5uIQHLIf38Nz-LJPV4gxSBYbXL9irv6Ff-FheaQAN-VjvAEoKg5iQDPYFzFobgQc2eizO9gldw81vMKMpu9Hj5DnxsmSeDqY4KuixJGcNeumoJwj7uMp0RUR4zvk Mar 08 18:10:16 rivo volumio[3289]: info: Spotify credentials grant success - running version from March 24, 2019 Mar 08 18:10:16 rivo volumio[3289]: info: CoreCommandRouter::servicePushState Mar 08 18:10:16 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:16 rivo volumio[3289]: verbose: STATE SERVICE {"status":"play","service":"inputs","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"","seek":0,"duration":0,"samplerate":"","bitdepth":"","stream":true,"disableUiControls":true,"channels":2} Mar 08 18:10:16 rivo volumio[3289]: verbose: CURRENT POSITION 0 Mar 08 18:10:16 rivo volumio[3289]: info: CoreStateMachine::syncState stateService play Mar 08 18:10:16 rivo volumio[3289]: info: CoreStateMachine::syncState currentStatus stop Mar 08 18:10:16 rivo volumio[3289]: info: CoreCommandRouter::volumiosetSourceActiveno-source Mar 08 18:10:16 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 08 18:10:16 rivo volumio[3289]: error: updateQueue error: null Mar 08 18:10:16 rivo volumio[3289]: info: Turning Off Onboard LEDs Mar 08 18:10:16 rivo volumio[3289]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Mar 08 18:10:16 rivo volumio[3289]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Mar 08 18:10:16 rivo sudo[4059]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/sys_led/trigger Mar 08 18:10:16 rivo sudo[4059]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:16 rivo sudo[4059]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:16 rivo sudo[4063]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/red_red/trigger Mar 08 18:10:16 rivo sudo[4063]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:16 rivo volumio[3289]: info: MCU Signalled Playback Inactive Mar 08 18:10:16 rivo sudo[4064]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Mar 08 18:10:16 rivo sudo[4064]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:16 rivo go-librespot[3994]: time="2025-03-08T18:10:16-08:00" level=debug msg="completed challenge" Mar 08 18:10:16 rivo sudo[4063]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:16 rivo volumio[3289]: info: Onboard LEDs initialized Mar 08 18:10:16 rivo systemd[1]: Started Volumio Tidal Connect Service. Mar 08 18:10:16 rivo go-librespot[3994]: time="2025-03-08T18:10:16-08:00" level=debug msg="authenticated as cormarch" Mar 08 18:10:16 rivo sudo[4064]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:16 rivo sudo[4067]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Mar 08 18:10:16 rivo sudo[4067]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 08 18:10:16 rivo volumio[3289]: SPOTIFY: User informations: {"country":"US","display_name":"cormarch","email":"jgradycole36@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/cormarch"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/cormarch","id":"cormarch","images":[],"product":"premium","type":"user","uri":"spotify:user:cormarch"} Mar 08 18:10:16 rivo volumio[3289]: info: Spotify Successfully logged in Mar 08 18:10:16 rivo volumio[3289]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 08 18:10:16 rivo volumio[3289]: info: [1741486216742] CoreMusicLibrary::Adding element Spotify Mar 08 18:10:16 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 08 18:10:16 rivo volumiobt[4026]: pulseaudio: no process found Mar 08 18:10:16 rivo sudo[4067]: pam_unix(sudo:session): session closed for user root Mar 08 18:10:16 rivo volumio[3289]: Cannot find translation for source Spotify Mar 08 18:10:16 rivo go-librespot[3994]: time="2025-03-08T18:10:16-08:00" level=debug msg="authenticated as cormarch" Mar 08 18:10:16 rivo volumio[3872]: Generating RSA private key, 4096 bit long modulus (2 primes) Mar 08 18:10:16 rivo dbus-daemon[2828]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.21' (uid=1000 pid=4089 comm="/usr/bin/pulseaudio --high-priority=true " label="kernel") Mar 08 18:10:16 rivo volumio[3289]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 4 Mar 08 18:10:16 rivo go-librespot[3994]: time="2025-03-08T18:10:16-08:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 08 18:10:16 rivo systemd[1]: Starting RealtimeKit Scheduling Policy Service... Mar 08 18:10:16 rivo volumio[3289]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 08 18:10:16 rivo kernel: IPVS: Creating netns size=1928 id=3 Mar 08 18:10:17 rivo dbus-daemon[2828]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Mar 08 18:10:17 rivo systemd[1]: Started RealtimeKit Scheduling Policy Service. Mar 08 18:10:17 rivo rtkit-daemon[4090]: Successfully called chroot. Mar 08 18:10:17 rivo rtkit-daemon[4090]: Successfully dropped privileges. Mar 08 18:10:17 rivo rtkit-daemon[4090]: Successfully limited resources. Mar 08 18:10:17 rivo rtkit-daemon[4090]: Running. Mar 08 18:10:17 rivo rtkit-daemon[4090]: Canary thread running. Mar 08 18:10:17 rivo dbus-daemon[2828]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.22' (uid=0 pid=4090 comm="/usr/lib/rtkit/rtkit-daemon " label="kernel") Mar 08 18:10:17 rivo rtkit-daemon[4090]: Watchdog thread running. Mar 08 18:10:17 rivo go-librespot[3994]: time="2025-03-08T18:10:17-08:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 08 18:10:17 rivo systemd[1]: Starting Authorization Manager... Mar 08 18:10:17 rivo volumio[3289]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 08 18:10:17 rivo polkitd[4093]: started daemon version 0.105 using authority implementation `local' version `0.105' Mar 08 18:10:17 rivo dbus-daemon[2828]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Mar 08 18:10:17 rivo systemd[1]: Started Authorization Manager. Mar 08 18:10:17 rivo go-librespot[3994]: time="2025-03-08T18:10:17-08:00" level=debug msg="dealer connection opened" Mar 08 18:10:17 rivo go-librespot[3994]: time="2025-03-08T18:10:17-08:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 08 18:10:17 rivo go-librespot[3994]: time="2025-03-08T18:10:17-08:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 08 18:10:17 rivo go-librespot[3994]: time="2025-03-08T18:10:17-08:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 08 18:10:17 rivo go-librespot[3994]: time="2025-03-08T18:10:17-08:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 08 18:10:17 rivo go-librespot[3994]: time="2025-03-08T18:10:17-08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Mar 08 18:10:17 rivo go-librespot[3994]: time="2025-03-08T18:10:17-08:00" level=debug msg="received connection id: NTE5M2RmNmMtNmNkNS00ZDM1LWEyNWYtZTc5MTE1ZmE4OTZjK2RlYWxlcit0Y3A6Ly8wYWNiZGE1Zi5pcC5ndWMzLnNwb3RpZnkubmV0OjU3MDArNzA5OTlGRUU5OEVDMTVENzRGRTc3NkY4OENGNEE0NUI3NTA1ODkyNDE0NjJFQzhCRTVCQjBEOUQ3REQxQTQ2QQ==" Mar 08 18:10:17 rivo go-librespot[3994]: time="2025-03-08T18:10:17-08:00" level=debug msg="put connect state because NEW_DEVICE" Mar 08 18:10:17 rivo volumio[3289]: info: Executing endpoint tc_getconfig Mar 08 18:10:17 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Mar 08 18:10:17 rivo vtcs[4068]: STARTING TidalConnect services, version: 1.4.0.34 Mar 08 18:10:17 rivo vtcs[4068]: STARTED TidalConnect services. Mar 08 18:10:17 rivo volumio[3289]: info: Executing endpoint tc_connect Mar 08 18:10:17 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Mar 08 18:10:17 rivo volumio[3289]: info: Connecting to TidalConnect Mar 08 18:10:17 rivo volumio[3289]: info: CoreCommandRouter::servicePushState Mar 08 18:10:17 rivo volumio[3289]: info: CoreStateMachine::pushState Mar 08 18:10:17 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:17 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 08 18:10:17 rivo volumio[3289]: info: CoreCommandRouter::volumioPushState Mar 08 18:10:17 rivo volumio[3289]: info: MRS: Pushing multiroomSync output update for this device Mar 08 18:10:17 rivo volumio[3289]: info: MRS: Pushing multiroomSync output Mar 08 18:10:17 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:17 rivo volumio[3289]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Mar 08 18:10:17 rivo volumio[3289]: verbose: CURRENT POSITION 0 Mar 08 18:10:17 rivo volumio[3289]: info: CoreStateMachine::syncState stateService stop Mar 08 18:10:17 rivo volumio[3289]: info: CoreStateMachine::syncState currentStatus play Mar 08 18:10:17 rivo volumio[3289]: info: CoreCommandRouter::volumioPushState Mar 08 18:10:17 rivo volumio[3289]: info: MRS: Pushing multiroomSync output update for this device Mar 08 18:10:17 rivo volumio[3289]: info: MRS: Pushing multiroomSync output Mar 08 18:10:17 rivo volumio[3289]: info: CoreStateMachine::stPlaybackTimer Mar 08 18:10:17 rivo volumio[3289]: info: CoreCommandRouter::servicePushState Mar 08 18:10:17 rivo volumio[3289]: info: CoreStateMachine::pushState Mar 08 18:10:17 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:17 rivo volumio[3289]: info: CoreCommandRouter::volumioPushState Mar 08 18:10:17 rivo volumio[3289]: info: MRS: Pushing multiroomSync output update for this device Mar 08 18:10:17 rivo volumio[3289]: info: MRS: Pushing multiroomSync output Mar 08 18:10:17 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:17 rivo volumio[3289]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Mar 08 18:10:17 rivo volumio[3289]: verbose: CURRENT POSITION 0 Mar 08 18:10:17 rivo volumio[3289]: info: CoreStateMachine::syncState stateService stop Mar 08 18:10:17 rivo volumio[3289]: info: CoreStateMachine::syncState currentStatus stop Mar 08 18:10:17 rivo volumio[3289]: info: CoreStateMachine::pushState Mar 08 18:10:17 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:17 rivo volumio[3289]: info: CoreCommandRouter::volumioPushState Mar 08 18:10:17 rivo volumio[3289]: info: MRS: Pushing multiroomSync output update for this device Mar 08 18:10:17 rivo volumio[3289]: info: MRS: Pushing multiroomSync output Mar 08 18:10:17 rivo volumio[3289]: info: No code Mar 08 18:10:17 rivo volumio[3289]: info: CoreStateMachine::pushState Mar 08 18:10:17 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:17 rivo volumio[3289]: info: CoreCommandRouter::volumioPushState Mar 08 18:10:17 rivo volumio[3289]: info: MRS: Pushing multiroomSync output update for this device Mar 08 18:10:17 rivo volumio[3289]: info: MRS: Pushing multiroomSync output Mar 08 18:10:17 rivo pulseaudio[4089]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Mar 08 18:10:17 rivo pulseaudio[4089]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Mar 08 18:10:17 rivo bluetoothd[3207]: Endpoint registered: sender=:1.42 path=/MediaEndpoint/A2DPSource Mar 08 18:10:17 rivo bluetoothd[3207]: Endpoint registered: sender=:1.42 path=/MediaEndpoint/A2DPSink Mar 08 18:10:17 rivo volumiobt[4026]: Applying permissions Mar 08 18:10:17 rivo volumiobt[4026]: Setting BT discoverable and pairable Mar 08 18:10:17 rivo pulseaudio[4089]: 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 Mar 08 18:10:17 rivo volumiobt[4026]: Agent registered Mar 08 18:10:17 rivo volumiobt[4026]: [bluetooth]# -e power on Mar 08 18:10:17 rivo volumiobt[4026]: Invalid command in menu main: -e Mar 08 18:10:17 rivo volumiobt[4026]: Mar 08 18:10:17 rivo volumiobt[4026]: Use "help" for a list of available commands in a menu. Mar 08 18:10:17 rivo volumiobt[4026]: Use "menu " if you want to enter any submenu. Mar 08 18:10:17 rivo volumiobt[4026]: Use "back" if you want to return to menu main. Mar 08 18:10:17 rivo volumiobt[4026]: [bluetooth]# agent on Mar 08 18:10:17 rivo volumiobt[4026]: Agent is already registered Mar 08 18:10:17 rivo volumiobt[4026]: [bluetooth]# discoverable on Mar 08 18:10:17 rivo volumiobt[4026]: [bluetooth]# pairable on Mar 08 18:10:17 rivo volumiobt[4026]: [bluetooth]# agent NoInputNoOutput Mar 08 18:10:17 rivo volumiobt[4026]: Agent is already registered Mar 08 18:10:17 rivo volumiobt[4026]: [bluetooth]# default-agent Mar 08 18:10:17 rivo volumiobt[4026]: [bluetooth]# quit Mar 08 18:10:17 rivo volumiobt[4026]: [59B blob data] Mar 08 18:10:17 rivo volumio[3289]: info: MRS: Getting audio outputs on start Mar 08 18:10:17 rivo volumio[3289]: info: MRS: Requesting all other devices output Mar 08 18:10:18 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 08 18:10:18 rivo volumio[3289]: info: go-librespot daemon successfully initialized Mar 08 18:10:19 rivo volumio[3289]: 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 Mar 08 18:10:19 rivo volumio[3289]: info: TidalConnect service started! Mar 08 18:10:19 rivo volumio[3289]: info: Completed starting Core Plugins Mar 08 18:10:19 rivo volumio[3289]: info: ------------------------------------------- Mar 08 18:10:19 rivo volumio[3289]: info: ----- MyVolumio plugins startup ---- Mar 08 18:10:19 rivo volumio[3289]: info: ------------------------------------------- Mar 08 18:10:19 rivo volumio[3289]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 08 18:10:20 rivo go-librespot[3994]: time="2025-03-08T18:10:20-08:00" level=debug msg="handling transfer player command from 016f0a50b0b5651b44ccfb2a664a3edca32568fc" Mar 08 18:10:20 rivo go-librespot[3994]: time="2025-03-08T18:10:20-08:00" level=debug msg="loading track spotify:track:63dBps7Nnj9il6ah0HoDAd (paused: false, position: 107865ms)" Mar 08 18:10:20 rivo go-librespot[3994]: time="2025-03-08T18:10:20-08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 08 18:10:20 rivo go-librespot[3994]: time="2025-03-08T18:10:20-08:00" level=trace msg="emitting websocket event: will_play" Mar 08 18:10:20 rivo go-librespot[3994]: time="2025-03-08T18:10:20-08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Mar 08 18:10:20 rivo go-librespot[3994]: time="2025-03-08T18:10:20-08:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:63dBps7Nnj9il6ah0HoDAd" Mar 08 18:10:20 rivo go-librespot[3994]: time="2025-03-08T18:10:20-08:00" level=debug msg="requested aes key for file e3e7bf4eefa8e65e591598d8d8ef1f07deee9cc0, gid: 63dBps7Nnj9il6ah0HoDAd" Mar 08 18:10:20 rivo go-librespot[3994]: time="2025-03-08T18:10:20-08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1329" Mar 08 18:10:20 rivo go-librespot[3994]: time="2025-03-08T18:10:20-08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1107" Mar 08 18:10:20 rivo volumio[3289]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 08 18:10:21 rivo volumio[3289]: info: Initializing connection to go-librespot Websocket Mar 08 18:10:21 rivo go-librespot[3994]: time="2025-03-08T18:10:21-08:00" level=debug msg="new websocket client" Mar 08 18:10:21 rivo volumio[3289]: info: Connection to go-librespot Websocket established Mar 08 18:10:21 rivo go-librespot[3994]: time="2025-03-08T18:10:21-08:00" level=debug msg="fetched first chunk of 18, total size is 8937562 bytes" Mar 08 18:10:21 rivo go-librespot[3994]: time="2025-03-08T18:10:21-08:00" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Mar 08 18:10:21 rivo go-librespot[3994]: time="2025-03-08T18:10:21-08:00" level=debug msg="fetched chunk 3/17, size: 524288" Mar 08 18:10:22 rivo go-librespot[3994]: time="2025-03-08T18:10:22-08:00" level=debug msg="fetched chunk 1/17, size: 524288" Mar 08 18:10:22 rivo volumio[3289]: 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: 6 Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::volumioGetVisibleSources Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::volumioGetState Mar 08 18:10:22 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 08 18:10:22 rivo volumio[3289]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Mar 08 18:10:22 rivo volumio[3289]: info: Received Get System Info Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 08 18:10:22 rivo volumio[3289]: info: Discovery: Getting this device information Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::volumioGetState Mar 08 18:10:22 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::volumioGetState Mar 08 18:10:22 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:22 rivo volumio[3289]: info: Listing playlists Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::volumioGetState Mar 08 18:10:22 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 08 18:10:22 rivo volumio[3289]: info: Received Get System Info Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 08 18:10:22 rivo volumio[3289]: info: Discovery: Getting this device information Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::volumioGetState Mar 08 18:10:22 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::volumioGetVisibleSources Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::volumioGetState Mar 08 18:10:22 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::volumioGetState Mar 08 18:10:22 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 08 18:10:22 rivo volumio[3289]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Mar 08 18:10:22 rivo volumio[3289]: info: Received Get System Info Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 08 18:10:22 rivo volumio[3289]: info: Discovery: Getting this device information Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::volumioGetState Mar 08 18:10:22 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 08 18:10:22 rivo volumio[3289]: info: CoreCommandRouter::volumioGetState Mar 08 18:10:22 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:22 rivo volumio[3289]: info: Listing playlists Mar 08 18:10:22 rivo go-librespot[3994]: time="2025-03-08T18:10:22-08:00" level=debug msg="fetched chunk 2/17, size: 524288" Mar 08 18:10:22 rivo go-librespot[3994]: time="2025-03-08T18:10:22-08:00" level=debug msg="fetched chunk 8/17, size: 524288" Mar 08 18:10:22 rivo go-librespot[3994]: time="2025-03-08T18:10:22-08:00" level=trace msg="seek to 107865ms (diff: 102ms, samples: 4756846, bytes: 4590741)" Mar 08 18:10:22 rivo go-librespot[3994]: time="2025-03-08T18:10:22-08:00" level=debug msg="fetched chunk 11/17, size: 524288" Mar 08 18:10:23 rivo go-librespot[3994]: time="2025-03-08T18:10:23-08:00" level=debug msg="fetched chunk 10/17, size: 524288" Mar 08 18:10:23 rivo kernel: aml_spdif_open Mar 08 18:10:23 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Mar 08 18:10:23 rivo go-librespot[3994]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:257:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 65536, but target_pcm volumioOutput has buffer size 32768 Mar 08 18:10:23 rivo go-librespot[3994]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:268:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 65536, but target_pcm volumioOutput has buffer size 32768 Mar 08 18:10:23 rivo kernel: set normal 512 fs /4 fs Mar 08 18:10:23 rivo kernel: set spdifout clk:5644800, mpll:22579200 Mar 08 18:10:23 rivo kernel: get spdifout clk:5644797, mpll:22579186 Mar 08 18:10:23 rivo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Mar 08 18:10:23 rivo kernel: set normal 512 fs /4 fs Mar 08 18:10:23 rivo kernel: set spdifout clk:5644800, mpll:22579200 Mar 08 18:10:23 rivo kernel: get spdifout clk:5644797, mpll:22579186 Mar 08 18:10:23 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Mar 08 18:10:23 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Mar 08 18:10:23 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Mar 08 18:10:23 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Mar 08 18:10:23 rivo go-librespot[3994]: time="2025-03-08T18:10:23-08:00" level=info msg="loaded track \"La Tempesta Colorata\" (uri: spotify:track:63dBps7Nnj9il6ah0HoDAd, paused: false, position: 107865ms, duration: 210500ms)" Mar 08 18:10:23 rivo go-librespot[3994]: time="2025-03-08T18:10:23-08:00" level=debug msg="fetched chunk 9/17, size: 524288" Mar 08 18:10:23 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Mar 08 18:10:23 rivo go-librespot[3994]: time="2025-03-08T18:10:23-08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 08 18:10:23 rivo go-librespot[3994]: time="2025-03-08T18:10:23-08:00" level=trace msg="emitting websocket event: metadata" Mar 08 18:10:23 rivo go-librespot[3994]: time="2025-03-08T18:10:23-08:00" level=trace msg="emitting websocket event: active" Mar 08 18:10:23 rivo go-librespot[3994]: time="2025-03-08T18:10:23-08:00" level=debug msg="sending successful reply for delaer request" Mar 08 18:10:23 rivo volumio[3289]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:63dBps7Nnj9il6ah0HoDAd","name":"La Tempesta Colorata","artist_names":["Valentina Magaletti"],"album_name":"La Tempesta Colorata","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0213647366a58aceea7757ba87","position":107865,"duration":210500}} Mar 08 18:10:23 rivo go-librespot[3994]: time="2025-03-08T18:10:23-08:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Mar 08 18:10:23 rivo volumio[3289]: SPOTIFY: received: {"type":"active","data":null} Mar 08 18:10:23 rivo go-librespot[3994]: time="2025-03-08T18:10:23-08:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Mar 08 18:10:23 rivo go-librespot[3994]: time="2025-03-08T18:10:23-08:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Mar 08 18:10:23 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback disable Mar 08 18:10:23 rivo volumio[3289]: info: Aligning Spotify Volume to Volumio Volume Mar 08 18:10:23 rivo volumio[3289]: info: CoreCommandRouter::volumioGetState Mar 08 18:10:23 rivo volumio[3289]: info: CorePlayQueue::getTrack 0 Mar 08 18:10:23 rivo volumio[3289]: info: Setting Spotify Volume from Volumio: 100 Mar 08 18:10:23 rivo go-librespot[3994]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:912:(_snd_pcm_volumioswitch_advance) PCM volumioMultiRoomServer cannot write to target PCM volumioOutput as it has failed its update check. Mar 08 18:10:23 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Mar 08 18:10:23 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Mar 08 18:10:23 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Mar 08 18:10:23 rivo go-librespot[3994]: time="2025-03-08T18:10:23-08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 08 18:10:23 rivo go-librespot[3994]: time="2025-03-08T18:10:23-08:00" level=trace msg="emitting websocket event: playing" Mar 08 18:10:23 rivo volumio[3289]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:63dBps7Nnj9il6ah0HoDAd","play_origin":"playlist"}} Mar 08 18:10:23 rivo volumio[3289]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 08 18:10:23 rivo volumio[3289]: TypeError: Cannot read property 'service' of undefined Mar 08 18:10:23 rivo volumio[3289]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:322:50) Mar 08 18:10:23 rivo volumio[3289]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:248:18) Mar 08 18:10:23 rivo volumio[3289]: at WebSocket.message (/data/plugins/music_service/spop/index.js:175:14) Mar 08 18:10:23 rivo volumio[3289]: at WebSocket.emit (events.js:400:28) Mar 08 18:10:23 rivo volumio[3289]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1192:20) Mar 08 18:10:23 rivo volumio[3289]: at Receiver.emit (events.js:400:28) Mar 08 18:10:23 rivo volumio[3289]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:560:14) Mar 08 18:10:23 rivo volumio[3289]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:478:17) Mar 08 18:10:23 rivo volumio[3289]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:22) Mar 08 18:10:23 rivo volumio[3289]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:180:18 Mar 08 18:10:23 rivo volumio[3289]: at internal/process/task_queues.js:141:7 Mar 08 18:10:23 rivo volumio[3289]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) Mar 08 18:10:23 rivo volumio[3289]: at AsyncResource.runMicrotask (internal/process/task_queues.js:138:8) Mar 08 18:10:23 rivo volumio[3289]: at runMicrotasks () Mar 08 18:10:23 rivo volumio[3289]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Mar 08 18:10:23 rivo volumio[3289]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 08 18:10:23 rivo volumio[3872]: ........................................................................++++ Mar 08 18:10:23 rivo go-librespot[3994]: time="2025-03-08T18:10:23-08:00" level=debug msg="fetched chunk 12/17, size: 524288" Mar 08 18:10:24 rivo sudo[4152]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-08 18:09 Mar 08 18:10:24 rivo sudo[4152]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 05:04:03 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="b3e66dc85ea2c87aca7db72b97d00dff"