-- Logs begin at Mon 2025-06-16 22:57:54 CEST, end at Mon 2025-06-16 22:59:54 CEST. -- Jun 16 22:58:00 rivo systemd[1]: Started Hold until boot process finishes up. Jun 16 22:58:00 rivo systemd[1]: Received SIGRTMIN+21 from PID 2451 (plymouthd). Jun 16 22:58:00 rivo cpufrequtils[3012]: disabled, governor not available...done. Jun 16 22:58:00 rivo systemd[1]: Started LSB: set CPUFreq kernel parameters. Jun 16 22:58:00 rivo kernel: wl_android_wifi_off out Jun 16 22:58:00 rivo kernel: wl_ext_iapsta_dettach_netdev: Enter Jun 16 22:58:00 rivo kernel: dhd_stop: Exit Jun 16 22:58:00 rivo ntpd[3063]: Listen normally on 2 lo 127.0.0.1:123 Jun 16 22:58:00 rivo ntpd[3063]: Listening on routing socket on fd #19 for interface updates Jun 16 22:58:00 rivo ntpd[3063]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 16 22:58:00 rivo ntpd[3063]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 16 22:58:00 rivo sudo[3050]: pam_unix(sudo:session): session closed for user root Jun 16 22:58:00 rivo ifplugd(eth0)[3089]: Using interface eth0/02:00:00:21:08:01 with driver (version: Jan_2016) Jun 16 22:58:00 rivo ifplugd(eth0)[3089]: Using detection mode: SIOCETHTOOL Jun 16 22:58:00 rivo ifplugd(eth0)[3089]: Initialization complete, link beat not detected. Jun 16 22:58:00 rivo sudo[3024]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 16 22:58:00 rivo sudo[3024]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:58:00 rivo dhcpcd[2838]: dummy0: soliciting a DHCP lease Jun 16 22:58:00 rivo dhcpcd[2838]: dummy0: soliciting an IPv6 router Jun 16 22:58:00 rivo dhcpcd[2838]: wlan0: carrier lost Jun 16 22:58:00 rivo dhcpcd[2838]: dummy0: soliciting a DHCP lease Jun 16 22:58:00 rivo dhcpcd[2838]: dummy0: soliciting an IPv6 router Jun 16 22:58:00 rivo dhcpcd[2838]: wlan0: carrier lost Jun 16 22:58:00 rivo sudo[3024]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jun 16 22:58:00 rivo sudo[3024]: pam_unix(sudo:session): session closed for user root Jun 16 22:58:00 rivo systemd[1]: Started Serial Getty on ttyS0. Jun 16 22:58:00 rivo systemd[1]: Reached target Login Prompts. Jun 16 22:58:00 rivo ifplugd[3046]: Network Interface Plugging Daemon...start eth0...done. Jun 16 22:58:00 rivo systemd[1]: Started LSB: Brings up/down network automatically. Jun 16 22:58:00 rivo wireless.js[2848]: Stopped aP Jun 16 22:58:00 rivo wireless.js[2848]: Wireless Networking DISABLED, not starting wireless flow Jun 16 22:58:00 rivo kernel: BT_RADIO going: on Jun 16 22:58:00 rivo kernel: AML_BT: going ON Jun 16 22:58:00 rivo iwconfig[3126]: Error for wireless request "Set Power Management" (8B2C) : Jun 16 22:58:00 rivo kernel: dhd_ioctl_entry: Interface is down Jun 16 22:58:00 rivo iwconfig[3126]: SET failed on device wlan0 ; Invalid argument. Jun 16 22:58:00 rivo systemd[1]: wireless.service: Succeeded. Jun 16 22:58:00 rivo systemd[1]: Started Wireless Services. Jun 16 22:58:00 rivo systemd[1]: Started Volumio Backend Module. Jun 16 22:58:00 rivo systemd[1]: Started Volumio Cpu Tweaker. Jun 16 22:58:00 rivo nmbd[3067]: [2025/06/16 22:58:00.493575, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Jun 16 22:58:00 rivo nmbd[3067]: started asyncdns process 3138 Jun 16 22:58:00 rivo nmbd[3067]: [2025/06/16 22:58:00.497053, 0] ../lib/util/become_daemon.c:149(daemon_status) Jun 16 22:58:00 rivo nmbd[3067]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Jun 16 22:58:00 rivo nmbd[3067]: [2025/06/16 22:58:00.498148, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Jun 16 22:58:00 rivo nmbd[3067]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Jun 16 22:58:00 rivo volumio-cpu-tweak[3129]: Setting RT Priority for mpd Jun 16 22:58:00 rivo rfkill[3124]: unblock set for id 0 Jun 16 22:58:00 rivo volumio-cpu-tweak[3129]: Setting MPD Affinity Jun 16 22:58:00 rivo volumio-cpu-tweak[3129]: pid 3103's current affinity mask: f Jun 16 22:58:00 rivo volumio-cpu-tweak[3129]: pid 3103's new affinity mask: 3 Jun 16 22:58:00 rivo volumio-cpu-tweak[3129]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Jun 16 22:58:00 rivo ntpd[3063]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jun 16 22:58:00 rivo volumio-cpu-tweak[3129]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Jun 16 22:58:00 rivo systemd[1]: volumio_cpu_tweak.service: Succeeded. Jun 16 22:58:01 rivo haveged[2795]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.3.0 CTV); collect: 128K Jun 16 22:58:01 rivo haveged[2795]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 12/40; sz: 15012/57848 Jun 16 22:58:01 rivo haveged[2795]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 8.00187 Jun 16 22:58:01 rivo haveged[2795]: haveged: fills: 0, generated: 0 Jun 16 22:58:01 rivo kernel: meson_uart ffd24000.serial: ttyS1 use xtal(24M) 24000000 change 0 to 9600 Jun 16 22:58:01 rivo kernel: meson_uart ffd24000.serial: ttyS1 use xtal(24M) 24000000 change 9600 to 9600 Jun 16 22:58:01 rivo kernel: meson_uart ffd24000.serial: ttyS1 use xtal(24M) 24000000 change 9600 to 115200 Jun 16 22:58:01 rivo ntpd[3063]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jun 16 22:58:02 rivo systemd[1]: apt-daily.service: Succeeded. Jun 16 22:58:02 rivo systemd[1]: Started Daily apt download activities. Jun 16 22:58:02 rivo dhcpcd[2838]: eth0: carrier acquired Jun 16 22:58:02 rivo dhcpcd[2838]: eth0: carrier acquired Jun 16 22:58:02 rivo kernel: meson6-dwmac ff3f0000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Jun 16 22:58:02 rivo sh[2747]: eth0: carrier acquired Jun 16 22:58:02 rivo dhcpcd[2803]: eth0: carrier acquired Jun 16 22:58:02 rivo dhcpcd[2838]: eth0: IAID 00:21:08:01 Jun 16 22:58:02 rivo dhcpcd[2838]: eth0: IAID 00:21:08:01 Jun 16 22:58:02 rivo sh[2747]: eth0: IAID 00:21:08:01 Jun 16 22:58:02 rivo dhcpcd[2803]: eth0: IAID 00:21:08:01 Jun 16 22:58:02 rivo dhcpcd[2838]: eth0: soliciting a DHCP lease Jun 16 22:58:02 rivo dhcpcd[2838]: eth0: soliciting a DHCP lease Jun 16 22:58:02 rivo dhcpcd[2838]: eth0: offered 192.168.8.173 from 192.168.8.1 Jun 16 22:58:02 rivo dhcpcd[2838]: eth0: offered 192.168.8.173 from 192.168.8.1 Jun 16 22:58:02 rivo dhcpcd[2838]: eth0: probing address 192.168.8.173/24 Jun 16 22:58:02 rivo dhcpcd[2838]: eth0: probing address 192.168.8.173/24 Jun 16 22:58:02 rivo ntpd[3063]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Jun 16 22:58:02 rivo sh[2747]: eth0: soliciting an IPv6 router Jun 16 22:58:02 rivo dhcpcd[2803]: eth0: soliciting an IPv6 router Jun 16 22:58:03 rivo dhcpcd[2838]: eth0: soliciting an IPv6 router Jun 16 22:58:03 rivo dhcpcd[2838]: eth0: soliciting an IPv6 router Jun 16 22:58:03 rivo sh[2747]: eth0: soliciting a DHCP lease Jun 16 22:58:03 rivo dhcpcd[2803]: eth0: soliciting a DHCP lease Jun 16 22:58:03 rivo sh[2747]: eth0: offered 192.168.8.173 from 192.168.8.1 Jun 16 22:58:03 rivo dhcpcd[2803]: eth0: offered 192.168.8.173 from 192.168.8.1 Jun 16 22:58:03 rivo sh[2747]: eth0: probing address 192.168.8.173/24 Jun 16 22:58:03 rivo dhcpcd[2803]: eth0: probing address 192.168.8.173/24 Jun 16 22:58:03 rivo volumio-time-update[2817]: volumio-time-update-util: Fetching time from Volumio... Jun 16 22:58:03 rivo volumio-time-update[2817]: volumio-time-update-util: Date not found in response Jun 16 22:58:03 rivo volumio-time-update[2817]: volumio-time-update-util: Retrying in 5 seconds... Jun 16 22:58:03 rivo ifplugd(eth0)[3089]: Link beat detected. Jun 16 22:58:03 rivo ifplugd(eth0)[3089]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Jun 16 22:58:03 rivo ifplugd(eth0)[3089]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Jun 16 22:58:03 rivo mpd[3103]: Jun 16 22:58 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 16 22:58:03 rivo systemd[1]: Started Music Player Daemon. Jun 16 22:58:03 rivo mpd_monitor.sh[2837]: MPD Monitor Service: MPD restarted due to no mpc output. Jun 16 22:58:03 rivo ntpd[3063]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jun 16 22:58:03 rivo volumio[3128]: info: ------------------------------------------- Jun 16 22:58:03 rivo volumio[3128]: info: ----- Volumio3 ---- Jun 16 22:58:03 rivo volumio[3128]: info: ------------------------------------------- Jun 16 22:58:03 rivo volumio[3128]: info: ----- System startup ---- Jun 16 22:58:03 rivo volumio[3128]: info: ------------------------------------------- Jun 16 22:58:04 rivo volumio-remote-updater[2827]: [2025-06-16 22:58:04] [connect] Successful connection Jun 16 22:58:04 rivo volumio[3128]: info: MYVOLUMIO Environment detected Jun 16 22:58:05 rivo volumio[3128]: info: Plugin folders cleanup Jun 16 22:58:05 rivo volumio[3128]: info: Scanning into folder /volumio/app/plugins/ Jun 16 22:58:05 rivo volumio[3128]: info: Scanning category audio_interface Jun 16 22:58:05 rivo volumio[3128]: info: Scanning category miscellanea Jun 16 22:58:05 rivo volumio[3128]: info: Scanning category music_service Jun 16 22:58:05 rivo volumio[3128]: info: Scanning category plugins.json Jun 16 22:58:05 rivo volumio[3128]: info: Scanning category system_controller Jun 16 22:58:05 rivo volumio[3128]: info: Scanning category user_interface Jun 16 22:58:05 rivo volumio[3128]: info: Scanning into folder /data/plugins/ Jun 16 22:58:05 rivo volumio[3128]: info: Scanning category audio_interface Jun 16 22:58:05 rivo volumio[3128]: info: Scanning category music_service Jun 16 22:58:05 rivo volumio[3128]: info: Plugin folders cleanup completed Jun 16 22:58:05 rivo volumio[3128]: info: ------------------------------------------- Jun 16 22:58:05 rivo volumio[3128]: info: ----- Core plugins startup ---- Jun 16 22:58:05 rivo volumio[3128]: info: ------------------------------------------- Jun 16 22:58:05 rivo volumio[3128]: info: Loading plugins from folder /volumio/app/plugins/ Jun 16 22:58:05 rivo volumio[3128]: info: Adding plugin bluetooth to MyMusic Plugins Jun 16 22:58:05 rivo volumio[3128]: info: Adding plugin multiroom to MyMusic Plugins Jun 16 22:58:05 rivo volumio[3128]: info: Adding plugin upnp to MyMusic Plugins Jun 16 22:58:05 rivo volumio[3128]: info: Adding plugin metavolumio to MyMusic Plugins Jun 16 22:58:05 rivo volumio[3128]: info: Adding plugin airplay_emulation to MyMusic Plugins Jun 16 22:58:05 rivo volumio[3128]: info: Adding plugin cd_controller to MyMusic Plugins Jun 16 22:58:05 rivo volumio[3128]: info: Adding plugin qobuzconnect to MyMusic Plugins Jun 16 22:58:05 rivo volumio[3128]: info: Adding plugin raat to MyMusic Plugins Jun 16 22:58:05 rivo volumio[3128]: info: Adding plugin smart_inputs to MyMusic Plugins Jun 16 22:58:05 rivo volumio[3128]: info: Adding plugin tidalconnect to MyMusic Plugins Jun 16 22:58:05 rivo volumio[3128]: info: Adding plugin upnp_browser to MyMusic Plugins Jun 16 22:58:05 rivo volumio[3128]: info: Loading plugins from folder /data/plugins/ Jun 16 22:58:05 rivo volumio[3128]: info: Loading plugin "system"... Jun 16 22:58:05 rivo volumio[3128]: info: Loading plugin "appearance"... Jun 16 22:58:05 rivo systemd[1]: systemd-rfkill.service: Succeeded. Jun 16 22:58:06 rivo volumio[3128]: info: Loading plugin "network"... Jun 16 22:58:06 rivo volumio[3128]: info: Refreshing Cached IP Addresses Jun 16 22:58:06 rivo sudo[3210]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 16 22:58:06 rivo sudo[3210]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:58:07 rivo volumio[3128]: info: Loading plugin "services"... Jun 16 22:58:07 rivo sudo[3212]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 16 22:58:07 rivo sudo[3212]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:58:07 rivo volumio[3128]: info: Loading plugin "alsa_controller"... Jun 16 22:58:07 rivo sudo[3210]: pam_unix(sudo:session): session closed for user root Jun 16 22:58:07 rivo sudo[3212]: pam_unix(sudo:session): session closed for user root Jun 16 22:58:07 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 16 22:58:07 rivo volumio[3128]: info: Loading plugin "wizard"... Jun 16 22:58:07 rivo volumio[3128]: info: Loading plugin "networkfs"... Jun 16 22:58:07 rivo volumio[3128]: info: Starting Udev Watcher for removable devices Jun 16 22:58:07 rivo volumio[3128]: info: Ignoring mount for partition: BOOT Jun 16 22:58:07 rivo volumio[3128]: info: Ignoring mount for partition: volumio Jun 16 22:58:07 rivo volumio[3128]: info: Ignoring mount for partition: volumio_data Jun 16 22:58:07 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 16 22:58:07 rivo volumio[3128]: info: Loading plugin "volumio_command_line_client"... Jun 16 22:58:07 rivo volumio[3128]: info: Loading plugin "upnp"... Jun 16 22:58:07 rivo volumio[3128]: info: [1750107487279] Starting Upmpd Daemon Jun 16 22:58:07 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 16 22:58:07 rivo volumio[3128]: info: Loading plugin "my_music"... Jun 16 22:58:07 rivo volumio[3128]: info: Loading plugin "mpd"... Jun 16 22:58:07 rivo dhcpcd[2838]: eth0: leased 192.168.8.173 for 86400 seconds Jun 16 22:58:07 rivo dhcpcd[2838]: eth0: adding route to 192.168.8.0/24 Jun 16 22:58:07 rivo dhcpcd[2838]: eth0: leased 192.168.8.173 for 86400 seconds Jun 16 22:58:07 rivo avahi-daemon[2826]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.8.173. Jun 16 22:58:07 rivo avahi-daemon[2826]: New relevant interface eth0.IPv4 for mDNS. Jun 16 22:58:07 rivo avahi-daemon[2826]: Registering new address record for 192.168.8.173 on eth0.IPv4. Jun 16 22:58:07 rivo dhcpcd[2838]: eth0: adding route to 192.168.8.0/24 Jun 16 22:58:07 rivo dhcpcd[2838]: eth0: adding default route via 192.168.8.1 Jun 16 22:58:07 rivo dhcpcd[2838]: eth0: adding default route via 192.168.8.1 Jun 16 22:58:07 rivo dhcpcd[2838]: eth0: dhcp_envoption 213: Operation not supported Jun 16 22:58:07 rivo dhcpcd[2838]: eth0: dhcp_envoption 213: Operation not supported Jun 16 22:58:07 rivo dhcpcd[2838]: eth0: dhcp_envoption 213: Operation not supported Jun 16 22:58:07 rivo volumio[3128]: info: Loading plugin "upnp_browser"... Jun 16 22:58:07 rivo ntpd[3063]: ntpd exiting on signal 15 (Terminated) Jun 16 22:58:07 rivo systemd[1]: Stopping Network Time Service... Jun 16 22:58:07 rivo systemd[1]: ntp.service: Succeeded. Jun 16 22:58:07 rivo systemd[1]: Stopped Network Time Service. Jun 16 22:58:07 rivo systemd[1]: Starting Network Time Service... Jun 16 22:58:07 rivo ntpd[3273]: ntpd 4.2.8p12@1.3728-o (1): Starting Jun 16 22:58:07 rivo ntpd[3273]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Jun 16 22:58:07 rivo systemd[1]: Started Network Time Service. Jun 16 22:58:07 rivo ntpd[3279]: proto: precision = 1.250 usec (-20) Jun 16 22:58:07 rivo dhcpcd[2838]: forked to background, child pid 3280 Jun 16 22:58:07 rivo dhcpcd[2838]: forked to background, child pid 3280 Jun 16 22:58:07 rivo ntpd[3279]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jun 16 22:58:07 rivo ntpd[3279]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Jun 16 22:58:07 rivo systemd[1]: Started DHCP Client Daemon. Jun 16 22:58:07 rivo ntpd[3279]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 902 days ago Jun 16 22:58:07 rivo ntpd[3279]: Listen and drop on 0 v6wildcard [::]:123 Jun 16 22:58:07 rivo ntpd[3279]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jun 16 22:58:07 rivo ntpd[3279]: Listen normally on 2 lo 127.0.0.1:123 Jun 16 22:58:07 rivo ntpd[3279]: Listen normally on 3 eth0 192.168.8.173:123 Jun 16 22:58:07 rivo ntpd[3279]: Listening on routing socket on fd #20 for interface updates Jun 16 22:58:07 rivo ntpd[3279]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 16 22:58:07 rivo ntpd[3279]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 16 22:58:08 rivo volumio-time-update[2817]: volumio-time-update-util: Fetching time from Volumio... Jun 16 22:58:08 rivo sh[2747]: eth0: leased 192.168.8.173 for 86400 seconds Jun 16 22:58:08 rivo dhcpcd[2803]: eth0: leased 192.168.8.173 for 86400 seconds Jun 16 22:58:08 rivo sh[2747]: eth0: adding route to 192.168.8.0/24 Jun 16 22:58:08 rivo sh[2747]: eth0: adding default route via 192.168.8.1 Jun 16 22:58:08 rivo sh[2747]: eth0: dhcp_envoption 213: Operation not supported Jun 16 22:58:08 rivo dhcpcd[2803]: eth0: adding route to 192.168.8.0/24 Jun 16 22:58:08 rivo dhcpcd[2803]: eth0: adding default route via 192.168.8.1 Jun 16 22:58:08 rivo dhcpcd[2803]: eth0: dhcp_envoption 213: Operation not supported Jun 16 22:58:08 rivo dhcpcd[2803]: eth0: dhcp_envoption 213: Operation not supported Jun 16 22:58:08 rivo volumio[3128]: info: Plugin bluetooth is not enabled Jun 16 22:58:08 rivo volumio[3128]: info: Loading plugin "alarm-clock"... Jun 16 22:58:08 rivo volumio-time-update[2817]: volumio-time-update-util: Setting system time to: 2025-06-16 22:59:27 Jun 16 22:58:08 rivo sudo[3314]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-06-16 22:59:27 Jun 16 22:58:08 rivo sudo[3314]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:58:08 rivo dbus-daemon[2828]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.5' (uid=0 pid=3316 comm="timedatectl set-time 2025-06-16 22:59:27 " label="kernel") Jun 16 22:58:08 rivo systemd[1]: Starting Time & Date Service... Jun 16 22:58:08 rivo ntpd[3279]: ntpd exiting on signal 15 (Terminated) Jun 16 22:58:08 rivo systemd[1]: Stopping Network Time Service... Jun 16 22:58:08 rivo systemd[1]: ntp.service: Succeeded. Jun 16 22:58:08 rivo systemd[1]: Stopped Network Time Service. Jun 16 22:58:08 rivo systemd[1]: Starting Network Time Service... Jun 16 22:58:08 rivo ntpd[3322]: ntpd 4.2.8p12@1.3728-o (1): Starting Jun 16 22:58:08 rivo ntpd[3322]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Jun 16 22:58:08 rivo systemd[1]: Started Network Time Service. Jun 16 22:58:08 rivo sh[2747]: forked to background, child pid 3329 Jun 16 22:58:08 rivo dhcpcd[2803]: forked to background, child pid 3329 Jun 16 22:58:08 rivo ntpd[3328]: proto: precision = 1.250 usec (-20) Jun 16 22:58:08 rivo ntpd[3328]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jun 16 22:58:08 rivo ntpd[3328]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Jun 16 22:58:08 rivo ntpd[3328]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 902 days ago Jun 16 22:58:08 rivo ntpd[3328]: Listen and drop on 0 v6wildcard [::]:123 Jun 16 22:58:08 rivo ntpd[3328]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jun 16 22:58:08 rivo ntpd[3328]: Listen normally on 2 lo 127.0.0.1:123 Jun 16 22:58:08 rivo ntpd[3328]: Listen normally on 3 eth0 192.168.8.173:123 Jun 16 22:58:08 rivo ntpd[3328]: Listening on routing socket on fd #20 for interface updates Jun 16 22:58:08 rivo ntpd[3328]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 16 22:58:08 rivo ntpd[3328]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 16 22:58:08 rivo volumio[3128]: info: Loading plugin "manifestui"... Jun 16 22:58:08 rivo dbus-daemon[2828]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 16 22:58:08 rivo systemd[1]: Started Time & Date Service. Jun 16 22:59:27 rivo systemd-timedated[3318]: Changed local time to Mon Jun 16 22:59:27 2025 Jun 16 22:59:27 rivo sudo[3314]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:27 rivo volumio-time-update[2817]: volumio-time-update-util: System time updated successfully. Jun 16 22:59:27 rivo systemd[1]: Started Volumio Time Update Utility. Jun 16 22:59:27 rivo ifplugd(eth0)[3089]: client: ifup: interface eth0 already configured Jun 16 22:59:27 rivo sh[2747]: eth0=eth0 Jun 16 22:59:27 rivo ifplugd(eth0)[3089]: Program executed successfully. Jun 16 22:59:27 rivo volumio[3128]: info: Loading plugin "metavolumio"... Jun 16 22:59:27 rivo kernel: meson_uart ffd24000.serial: ttyS1 use xtal(24M) 24000000 change 115200 to 2000000 Jun 16 22:59:27 rivo systemd[1]: Starting Load/Save RF Kill Switch Status... Jun 16 22:59:27 rivo systemd[1]: Started Load/Save RF Kill Switch Status. Jun 16 22:59:27 rivo systemd[1]: Starting Bluetooth service... Jun 16 22:59:27 rivo bluetoothd[3360]: Bluetooth daemon 5.50 Jun 16 22:59:27 rivo bluetoothd[3360]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Jun 16 22:59:27 rivo systemd[1]: Started Bluetooth service. Jun 16 22:59:27 rivo systemd[1]: Reached target Bluetooth. Jun 16 22:59:27 rivo bluetoothd[3360]: Starting SDP server Jun 16 22:59:27 rivo bluetoothd[3360]: Excluding (cli) sap Jun 16 22:59:27 rivo dbus-daemon[2828]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.7' (uid=0 pid=3360 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap " label="kernel") Jun 16 22:59:27 rivo bluetoothd[3360]: Bluetooth management interface 1.14 initialized Jun 16 22:59:27 rivo systemd[1]: Starting Hostname Service... Jun 16 22:59:27 rivo kernel: IPVS: Creating netns size=1928 id=2 Jun 16 22:59:27 rivo dbus-daemon[2828]: [system] Successfully activated service 'org.freedesktop.hostname1' Jun 16 22:59:27 rivo systemd[1]: Started Hostname Service. Jun 16 22:59:27 rivo ntpd[3328]: Soliciting pool server 193.25.222.136 Jun 16 22:59:28 rivo kernel: nf_conntrack: default automatic helper assignment has been turned off for security reasons and CT-based firewall rule not found. Use the iptables CT target to attach helpers instead. Jun 16 22:59:28 rivo systemd[1]: Started Samba NMB Daemon. Jun 16 22:59:28 rivo nmbd[3067]: [2025/06/16 22:59:28.862259, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 16 22:59:28 rivo nmbd[3067]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Jun 16 22:59:28 rivo systemd[1]: Starting Samba Winbind Daemon... Jun 16 22:59:28 rivo ntpd[3328]: Soliciting pool server 162.159.200.123 Jun 16 22:59:29 rivo ntpd[3328]: Soliciting pool server 193.59.134.156 Jun 16 22:59:29 rivo winbindd[3367]: [2025/06/16 22:59:29.236315, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Jun 16 22:59:29 rivo winbindd[3367]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jun 16 22:59:29 rivo winbindd[3367]: [2025/06/16 22:59:29.249911, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 16 22:59:29 rivo winbindd[3367]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jun 16 22:59:29 rivo systemd[1]: Started Samba Winbind Daemon. Jun 16 22:59:29 rivo systemd[1]: Starting Samba SMB Daemon... Jun 16 22:59:29 rivo volumio[3128]: info: Plugin airplay_emulation is not enabled Jun 16 22:59:29 rivo volumio[3128]: info: Plugin cd_controller is not enabled Jun 16 22:59:29 rivo volumio[3128]: info: Loading plugin "last_100"... Jun 16 22:59:29 rivo volumio[3128]: info: Loading plugin "qobuzconnect"... Jun 16 22:59:29 rivo volumio[3128]: info: Plugin raat is not enabled Jun 16 22:59:29 rivo volumio[3128]: info: Loading plugin "streaming_services"... Jun 16 22:59:29 rivo smbd[3371]: [2025/06/16 22:59:29.839318, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 16 22:59:29 rivo smbd[3371]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jun 16 22:59:29 rivo systemd[1]: Started Samba SMB Daemon. Jun 16 22:59:29 rivo systemd[1]: Reached target Multi-User System. Jun 16 22:59:29 rivo systemd[1]: Reached target Graphical Interface. Jun 16 22:59:29 rivo systemd[1]: Starting Update UTMP about System Runlevel Changes... Jun 16 22:59:29 rivo systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jun 16 22:59:29 rivo systemd[1]: Started Update UTMP about System Runlevel Changes. Jun 16 22:59:29 rivo systemd[1]: Startup finished in 12.829s (kernel) + 17.539s (userspace) = 30.369s. Jun 16 22:59:29 rivo ntpd[3328]: Soliciting pool server 89.161.47.136 Jun 16 22:59:29 rivo ntpd[3328]: Soliciting pool server 46.175.224.7 Jun 16 22:59:29 rivo ntpd[3328]: Soliciting pool server 213.222.217.11 Jun 16 22:59:30 rivo ntpd[3328]: Soliciting pool server 178.215.228.24 Jun 16 22:59:30 rivo ntpd[3328]: Soliciting pool server 89.25.168.148 Jun 16 22:59:30 rivo ntpd[3328]: Soliciting pool server 46.174.178.150 Jun 16 22:59:30 rivo volumio[3128]: info: Starting Streaming Service Transparent Proxy Jun 16 22:59:30 rivo ntpd[3328]: Soliciting pool server 162.159.200.1 Jun 16 22:59:31 rivo volumio[3128]: info: Loading plugin "tidalconnect"... Jun 16 22:59:31 rivo volumio[3128]: info: Loading plugin "webradio"... Jun 16 22:59:31 rivo volumio[3128]: info: Loading plugin "i2s_dacs"... Jun 16 22:59:31 rivo volumio[3128]: info: I2S DAC not set, start Auto-detection Jun 16 22:59:31 rivo volumio[3128]: info: Loading plugin "volumiodiscovery"... Jun 16 22:59:31 rivo volumio[3128]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 16 22:59:31 rivo volumio[3128]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 16 22:59:31 rivo volumio[3128]: *** WARNING *** For more information see Jun 16 22:59:31 rivo node[3128]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 16 22:59:31 rivo volumio[3128]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 16 22:59:31 rivo volumio[3128]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 16 22:59:31 rivo volumio[3128]: *** WARNING *** For more information see Jun 16 22:59:31 rivo node[3128]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 16 22:59:31 rivo node[3128]: *** WARNING *** For more information see Jun 16 22:59:31 rivo node[3128]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 16 22:59:31 rivo node[3128]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 16 22:59:31 rivo node[3128]: *** WARNING *** For more information see Jun 16 22:59:31 rivo volumio[3128]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 16 22:59:31 rivo volumio[3128]: info: Discovery: Started advertising with name: Rivo Jun 16 22:59:31 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 16 22:59:31 rivo volumio[3128]: info: Loading plugin "spop"... Jun 16 22:59:31 rivo ntpd[3328]: Soliciting pool server 91.210.128.220 Jun 16 22:59:31 rivo ntpd[3328]: Soliciting pool server 94.154.96.7 Jun 16 22:59:32 rivo volumio[3128]: STREAMING PROXY: Starting server on port 3245 Jun 16 22:59:32 rivo volumio[3128]: Node JS runtime: 14 Jun 16 22:59:32 rivo systemd[1]: systemd-rfkill.service: Succeeded. Jun 16 22:59:32 rivo ntpd[3328]: Soliciting pool server 2a05:9404::15e Jun 16 22:59:33 rivo volumio[3128]: info: Plugin multiroom is not enabled Jun 16 22:59:33 rivo volumio[3128]: info: Loading plugin "outputs"... Jun 16 22:59:33 rivo volumio[3128]: info: Loading plugin "albumart"... Jun 16 22:59:33 rivo volumio[3128]: info: Plugin example_plugin is not enabled Jun 16 22:59:33 rivo volumio[3128]: info: Loading plugin "hi_res_audio"... Jun 16 22:59:33 rivo volumio[3128]: Forking 3 albumart workers Jun 16 22:59:34 rivo volumio[3128]: Starting albumart workers Jun 16 22:59:34 rivo volumio[3128]: Starting albumart workers Jun 16 22:59:34 rivo volumio[3128]: Starting albumart workers Jun 16 22:59:34 rivo volumio-remote-updater[2827]: [2025-06-16 22:59:34] [connect] Successful connection Jun 16 22:59:35 rivo volumio[3128]: info: Applying required configuration parameters for plugin hi_res_audio Jun 16 22:59:35 rivo volumio[3128]: info: Loading plugin "inputs"... Jun 16 22:59:36 rivo volumio[3128]: info: Loading plugin "qobuz"... Jun 16 22:59:37 rivo ntpd[3328]: receive: Unexpected origin timestamp 0xebfb0438.f0ed6665 does not match aorg 0000000000.00000000 from server@162.159.200.1 xmt 0xebfb0439.7d60a582 Jun 16 22:59:37 rivo ntpd[3328]: receive: Unexpected origin timestamp 0xebfb0438.f0f2bacf does not match aorg 0000000000.00000000 from server@89.161.47.136 xmt 0xebfb0439.7e49fc68 Jun 16 22:59:38 rivo volumio[3128]: info: Loading plugin "smart_inputs"... Jun 16 22:59:39 rivo volumio[3128]: info: Loading plugin "tidal"... Jun 16 22:59:41 rivo volumio[3128]: info: Loading plugin "rivocontrol"... Jun 16 22:59:41 rivo volumio[3128]: info: Adding this device properties Jun 16 22:59:41 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , setThisDeviceVolumioProperties Jun 16 22:59:41 rivo volumio[3128]: info: Setting Additional Device Volumio Properties: [object Object] Jun 16 22:59:41 rivo volumio[3128]: info: Loading plugin "updater_comm"... Jun 16 22:59:41 rivo volumio[3128]: info: Loading plugin "cec_controller"... Jun 16 22:59:42 rivo volumio[3128]: info: Applying required configuration parameters for plugin cec_controller Jun 16 22:59:42 rivo volumio[3128]: info: Plugin mpdemulation is not enabled Jun 16 22:59:42 rivo volumio[3128]: info: Loading plugin "rest_api"... Jun 16 22:59:42 rivo volumio[3128]: info: Loading plugin "websocket"... Jun 16 22:59:42 rivo volumio[3128]: info: Starting Socket.io Server version 2.3.0 Jun 16 22:59:42 rivo volumio[3128]: info: Loading plugin "fusiondsp"... Jun 16 22:59:42 rivo volumio[3128]: info: Applying required configuration parameters for plugin fusiondsp Jun 16 22:59:42 rivo volumio[3128]: info: Loading i18n strings for locale pl Jun 16 22:59:42 rivo volumio[3128]: Updating browse sources language Jun 16 22:59:42 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::initPlayerControls Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 22:59:43 rivo volumio[3128]: Express server listening on port 3000 Jun 16 22:59:43 rivo volumio[3128]: [Metrics] WebUI: 21s 602.24ms Jun 16 22:59:43 rivo volumio[3128]: info: CoreStateMachine::resetVolumioState Jun 16 22:59:43 rivo volumio[3128]: info: CoreStateMachine::getcurrentVolume Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::volumioRetrievevolume Jun 16 22:59:43 rivo volumio[3128]: info: CoreStateMachine::pushState Jun 16 22:59:43 rivo volumio[3128]: info: CorePlayQueue::getTrack 0 Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::volumioPushState Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 22:59:43 rivo sudo[3466]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 16 22:59:43 rivo sudo[3466]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:43 rivo sudo[3466]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:43 rivo volumio[3128]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Jun 16 22:59:43 rivo volumio[3128]: info: Completed loading Core Plugins Jun 16 22:59:43 rivo sudo[3468]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 16 22:59:43 rivo sudo[3468]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:43 rivo volumio[3128]: info: Preparing to generate the ALSA configuration file Jun 16 22:59:43 rivo sudo[3468]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:43 rivo volumio[3128]: info: Volumio Network Manager: Network status updated: 0 Jun 16 22:59:43 rivo volumio[3128]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Jun 16 22:59:43 rivo volumio[3128]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jun 16 22:59:43 rivo volumio[3128]: info: Reading ALSA contributions from plugins. Jun 16 22:59:43 rivo volumio[3128]: info: Reloading queue from file Jun 16 22:59:43 rivo volumio[3128]: info: CoreStateMachine::setRepeat false single undefined Jun 16 22:59:43 rivo volumio[3128]: info: CoreStateMachine::pushState Jun 16 22:59:43 rivo volumio[3128]: info: CorePlayQueue::getTrack 0 Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::volumioPushState Jun 16 22:59:43 rivo volumio[3128]: info: CoreStateMachine::setRandom null Jun 16 22:59:43 rivo volumio[3128]: info: CoreStateMachine::pushState Jun 16 22:59:43 rivo volumio[3128]: info: CorePlayQueue::getTrack 0 Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::volumioPushState Jun 16 22:59:43 rivo volumio[3128]: info: Asound.conf file unchanged, so no further update is needed Jun 16 22:59:43 rivo volumio[3128]: info: Output device has changed, restarting MPD Jun 16 22:59:43 rivo sudo[3479]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 16 22:59:43 rivo sudo[3479]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:43 rivo systemd[1]: Started UPnP Renderer front-end to MPD. Jun 16 22:59:43 rivo sudo[3482]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 16 22:59:43 rivo sudo[3482]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:43 rivo sudo[3479]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:43 rivo volumio[3128]: info: ___________ START PLUGINS ___________ Jun 16 22:59:43 rivo sudo[3482]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:43 rivo volumio[3128]: info: ControllerMpd::onStart: Initializing MPD Jun 16 22:59:43 rivo volumio[3128]: info: Creating MPD Configuration file Jun 16 22:59:43 rivo sudo[3486]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 16 22:59:43 rivo sudo[3486]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:43 rivo systemd[1]: Stopping Music Player Daemon... Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 22:59:43 rivo volumio[3128]: info: [1750107583794] CoreMusicLibrary::Adding element Serwery Mediów Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 22:59:43 rivo sudo[3496]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 16 22:59:43 rivo sudo[3496]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:43 rivo sudo[3496]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:43 rivo sudo[3498]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 16 22:59:43 rivo sudo[3498]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:43 rivo volumio[3128]: info: Adding METAVOLUMIO REST API Endpoints Jun 16 22:59:43 rivo volumio[3128]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Jun 16 22:59:43 rivo volumio[3128]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Jun 16 22:59:43 rivo volumio[3128]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Jun 16 22:59:43 rivo volumio[3128]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 22:59:43 rivo volumio[3128]: info: [1750107583835] CoreMusicLibrary::Adding element Last_100 Jun 16 22:59:43 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 22:59:43 rivo volumio[3128]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Jun 16 22:59:43 rivo volumio[3128]: info: QobuzConnect: Starting Qobuz Connect socket and service Jun 16 22:59:43 rivo volumio[3128]: info: Streaming services startup Jun 16 22:59:43 rivo volumio[3128]: info: Starting Streaming Daemon Jun 16 22:59:43 rivo sudo[3505]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jun 16 22:59:43 rivo sudo[3505]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:43 rivo sudo[3505]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:43 rivo systemd[1]: mpd.service: Succeeded. Jun 16 22:59:43 rivo systemd[1]: Stopped Music Player Daemon. Jun 16 22:59:43 rivo sudo[3508]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 16 22:59:43 rivo sudo[3508]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:44 rivo sudo[3509]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jun 16 22:59:44 rivo sudo[3509]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:44 rivo systemd[1]: Starting Music Player Daemon... Jun 16 22:59:44 rivo sudo[3508]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:44 rivo systemd[1]: Started Volumio Qobuz Connect Service. Jun 16 22:59:44 rivo volumio[3128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 22:59:44 rivo volumio[3128]: info: [1750107584071] CoreMusicLibrary::Adding element Webradio Jun 16 22:59:44 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 22:59:44 rivo sudo[3509]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:44 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 16 22:59:44 rivo volumio[3128]: info: Initializing BBC Radios Jun 16 22:59:44 rivo sudo[3520]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 16 22:59:44 rivo sudo[3520]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:44 rivo sudo[3520]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:44 rivo sudo[3513]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 16 22:59:44 rivo sudo[3513]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:44 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 16 22:59:44 rivo sudo[3513]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:44 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 22:59:44 rivo volumio[3128]: info: Creating Spotify config file Jun 16 22:59:44 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:44 rivo volumio[3128]: error: Hi Res Audio Failed Login: Missing Login Data Jun 16 22:59:44 rivo volumio[3128]: info: Adding HIGHRESAUDIO REST API Endpoints Jun 16 22:59:44 rivo volumio[3128]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Jun 16 22:59:44 rivo volumio[3128]: info: Initializing Serial Communication on port /dev/ttyS3 Jun 16 22:59:44 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 0 to 9600 Jun 16 22:59:44 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 9600 to 9600 Jun 16 22:59:44 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 9600 to 115200 Jun 16 22:59:44 rivo volumio[3128]: info: Touch Event Listener Process Starting Jun 16 22:59:44 rivo volumio[3128]: info: Adding inputs REST Endpoints Jun 16 22:59:44 rivo volumio[3128]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Jun 16 22:59:44 rivo volumio[3128]: info: Scanning Audio Inputs Jun 16 22:59:44 rivo sudo[3537]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xinput --test-xi2 --root Jun 16 22:59:44 rivo sudo[3537]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:44 rivo sudo[3537]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:44 rivo volumio[3128]: info: Checking against Known Cards name Jun 16 22:59:44 rivo volumio[3128]: info: Checking against Known Cards name Jun 16 22:59:44 rivo volumio[3128]: info: Checking against Known Cards name Jun 16 22:59:44 rivo volumio[3128]: info: Checking against Known Cards name Jun 16 22:59:44 rivo volumio[3128]: info: Checking against Known Cards name Jun 16 22:59:44 rivo volumio[3128]: info: Adding Server instance for streaming Jun 16 22:59:44 rivo volumio[3128]: info: Refreshing TIDAL token Jun 16 22:59:44 rivo sudo[3548]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x25 0x0 Jun 16 22:59:44 rivo sudo[3548]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:44 rivo sudo[3548]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:44 rivo sudo[3551]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x28 0x0 Jun 16 22:59:44 rivo sudo[3551]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:44 rivo sudo[3551]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:44 rivo sudo[3554]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x29 0x1 Jun 16 22:59:44 rivo sudo[3554]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:44 rivo sudo[3554]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:44 rivo sudo[3557]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x33 0x1 Jun 16 22:59:44 rivo sudo[3557]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:44 rivo sudo[3557]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:44 rivo volumio[3128]: info: Apply VIM3L Onboard LEDs Settings Jun 16 22:59:44 rivo volumio[3128]: info: Turning On Onboard LEDs Jun 16 22:59:44 rivo sudo[3561]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/sys_led/trigger Jun 16 22:59:44 rivo sudo[3561]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:44 rivo volumio[3128]: info: Starting CEC Event listener Jun 16 22:59:44 rivo sudo[3561]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:44 rivo volumio[3128]: info: Loading i18n strings for locale pl Jun 16 22:59:44 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jun 16 22:59:44 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:44 rivo volumio[3128]: info: FusionDsp - mixtype--------------------- None Jun 16 22:59:44 rivo volumio[3128]: info: Volumio Calling Home Jun 16 22:59:44 rivo sudo[3565]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/red_red/trigger Jun 16 22:59:44 rivo sudo[3565]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:44 rivo sudo[3565]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:44 rivo volumio[3128]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Jun 16 22:59:44 rivo volumio[3128]: info: Preparing to generate the ALSA configuration file Jun 16 22:59:44 rivo volumio[3128]: info: Stopping AccessToken refresher cron for QOBUZ Jun 16 22:59:45 rivo volumio[3128]: info: AccessToken refresher cron started for QOBUZ Jun 16 22:59:45 rivo volumio[3128]: info: Adding QOBUZ REST API Endpoints Jun 16 22:59:45 rivo volumio[3128]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Jun 16 22:59:45 rivo volumio[3128]: info: Discovery: adding a93508e6-08f3-42e5-b55f-02762c606e07 Jun 16 22:59:45 rivo volumio[3128]: info: Discovery: Found device Rivo Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::volumioGetState Jun 16 22:59:45 rivo volumio[3128]: info: CorePlayQueue::getTrack 0 Jun 16 22:59:45 rivo volumio[3128]: info: Serial port opened successfully Jun 16 22:59:45 rivo volumio[3128]: info: Sending serial start messages Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: Reporting MCU Network Status: 0 Jun 16 22:59:45 rivo volumio[3128]: info: MP1 GPIO: Signalled system ready via GPIO Jun 16 22:59:45 rivo volumio[3128]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jun 16 22:59:45 rivo volumio[3128]: info: Reading ALSA contributions from plugins. Jun 16 22:59:45 rivo volumio[3128]: info: Touch Event Listener Process Closed Jun 16 22:59:45 rivo volumio[3128]: error: Cannot start Volumio Streaming Daemon Jun 16 22:59:45 rivo volumio[3128]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 16 22:59:45 rivo volumio[3128]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 16 22:59:45 rivo volumio[3128]: info: MPD Permissions set Jun 16 22:59:45 rivo volumio[3128]: info: MPD Permissions set Jun 16 22:59:45 rivo volumio[3128]: info: Upmpdcli Daemon Started Jun 16 22:59:45 rivo volumio[3128]: info: Executing endpoint qc_getconfig Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Jun 16 22:59:45 rivo qobuz-connect[3519]: 20250616 22:59:45.360 [3519.3519] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Jun 16 22:59:45 rivo volumio[3128]: info: Spotify config file written Jun 16 22:59:45 rivo sudo[3572]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jun 16 22:59:45 rivo sudo[3572]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:45 rivo systemd[1]: Started go-librespot Daemon. Jun 16 22:59:45 rivo sudo[3572]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:45 rivo go-librespot[3574]: Librespot-go daemon starting... Jun 16 22:59:45 rivo volumio[3128]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jun 16 22:59:45 rivo volumio[3128]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Jun 16 22:59:45 rivo volumio[3128]: info: QobuzConnect: QOBUZ Connect daemon connected Jun 16 22:59:45 rivo qobuz-connect[3519]: 20250616 22:59:45.552 [3519.3519] INFO VolumeManager: [0xac27f908]: Setting new playback volume: 75 Jun 16 22:59:45 rivo qobuz-connect[3519]: 20250616 22:59:45.552 [3519.3519] INFO VolumeManager: [0xac27f908]: Setting new mute state: 0 Jun 16 22:59:45 rivo qobuz-connect[3519]: 20250616 22:59:45.552 [3519.3519] INFO QobuzConnect: [0xac2802d8]: Client initialized! Jun 16 22:59:45 rivo qobuz-connect[3519]: 20250616 22:59:45.552 [3519.3519] INFO SampleApp: Starting Avahi advertising, name: Rivo, service name: _qobuz-connect._tcp Jun 16 22:59:45 rivo volumio[3128]: info: Volumio called home Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo qobuz-connect[3519]: 20250616 22:59:45.571 [3519.3519] INFO LocalConfigManager: [0xac27f1e8]: Starting Local Configuration server Jun 16 22:59:45 rivo qobuz-connect[3519]: 20250616 22:59:45.572 [3519.3519] INFO SampleApp: Starting Local configuration server Jun 16 22:59:45 rivo qobuz-connect[3519]: 20250616 22:59:45.572 [3519.3519] INFO SampleApp: Playback volume changed: 75 Jun 16 22:59:45 rivo qobuz-connect[3519]: 20250616 22:59:45.573 [3519.3519] INFO SampleApp: Connected to UNIX socket client 0xac274ed8 Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jun 16 22:59:45 rivo go-librespot[3574]: time="2025-06-16T22:59:45+02:00" level=info msg="generated new device id: 77deac60db020d8498656cbca6a77debf2dcf97b" Jun 16 22:59:45 rivo go-librespot[3574]: time="2025-06-16T22:59:45+02:00" level=debug msg="stored credentials found for kuperaszzz" Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::volumioGetState Jun 16 22:59:45 rivo volumio[3128]: info: CorePlayQueue::getTrack 0 Jun 16 22:59:45 rivo volumio[3128]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jun 16 22:59:45 rivo volumio[3128]: info: CoreCommandRouter::volumioGetState Jun 16 22:59:45 rivo volumio[3128]: info: CorePlayQueue::getTrack 0 Jun 16 22:59:45 rivo volumio[3128]: info: Asound.conf file unchanged, so no further update is needed Jun 16 22:59:45 rivo volumio[3128]: info: Output device has changed, restarting MPD Jun 16 22:59:46 rivo sudo[3599]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 16 22:59:46 rivo volumio[3128]: info: QobuzConnect: setDeactiveState invoked Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::volumioGetState Jun 16 22:59:46 rivo volumio[3128]: info: CorePlayQueue::getTrack 0 Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:46 rivo sudo[3599]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:46 rivo sudo[3599]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:46 rivo sudo[3602]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 16 22:59:46 rivo sudo[3602]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:46 rivo systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jun 16 22:59:46 rivo systemd[1]: mpd.service: Succeeded. Jun 16 22:59:46 rivo systemd[1]: Stopped Music Player Daemon. Jun 16 22:59:46 rivo systemd[1]: Starting Music Player Daemon... Jun 16 22:59:46 rivo sudo[3615]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jun 16 22:59:46 rivo sudo[3615]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::volumioGetState Jun 16 22:59:46 rivo volumio[3128]: info: CorePlayQueue::getTrack 0 Jun 16 22:59:46 rivo systemd[1]: systemd-fsckd.service: Succeeded. Jun 16 22:59:46 rivo sudo[3615]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:46 rivo volumio[3128]: info: Access Token successfully retrieved Jun 16 22:59:46 rivo sudo[3629]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jun 16 22:59:46 rivo sudo[3629]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:46 rivo qobuz-connect[3519]: 20250616 22:59:46.292 [3519.3519] INFO SampleApp: Stopping Local configuration server Jun 16 22:59:46 rivo systemd[1]: Stopping Volumio Qobuz Connect Service... Jun 16 22:59:46 rivo volumio[3128]: info: MPD Permissions set Jun 16 22:59:46 rivo qobuz-connect[3519]: 20250616 22:59:46.303 [3519.3519] INFO SampleApp: shat down connection on UNIX socket Jun 16 22:59:46 rivo go-librespot[3574]: time="2025-06-16T22:59:46+02:00" level=debug msg="obtained new client token: AAB74LYAivGarX+9QKnXXZ3yZlMz/QldTNQQRyHxuLUVXV7l8QINtAGbHsAgK+0Tnqe2mvbm3BAyUoQ5epsWP7hPCl3kXoq08xoyiOxvZlBhKFXH93TUmaNjqWMDoRzPnnusEh9CmSwe/ELCuZ1TubMou767qdABB9W3bHRnilT9cbx/jC2eKhBpmlVUN7xwBZSojinitAyfEY4Qt8QUhckZO2dS4KS7JZxdKJFzuPVZ0Jyx7wYCWHfysKGeng==" Jun 16 22:59:46 rivo systemd[1]: qobuz-connect.service: Succeeded. Jun 16 22:59:46 rivo systemd[1]: Stopped Volumio Qobuz Connect Service. Jun 16 22:59:46 rivo volumio[3128]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 16 22:59:46 rivo volumio[3128]: SPOTIFY: BQDwLH0sTo7xJn1Hz5I_ANDJ_105FC8UcSUeGZKLc0SUIjN-aLwwuZFCJqH40KXOOFHJze9ZpY_RL08HXztnf9-Gwbn7uxGhRLA-2XQz3vIo2hbqgVwKl3YSrHmMbDleUK7UpQhOAPqx-W835e-oEMDqe2pzcjcYev1GCYkpUurbGuqP1iV8ztwLNqVgxz-jrrxIKBh_X5WnUpuDEGX576_xkt4b1S3Vb-vIEFQyt3vPFDK3pYMTq_q8AznYcmG_2jf2IWFHr-T6S7IX0Nyb0cr39aA Jun 16 22:59:46 rivo volumio[3128]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 16 22:59:46 rivo volumio[3128]: info: New Spotify access token = BQDwLH0sTo7xJn1Hz5I_ANDJ_105FC8UcSUeGZKLc0SUIjN-aLwwuZFCJqH40KXOOFHJze9ZpY_RL08HXztnf9-Gwbn7uxGhRLA-2XQz3vIo2hbqgVwKl3YSrHmMbDleUK7UpQhOAPqx-W835e-oEMDqe2pzcjcYev1GCYkpUurbGuqP1iV8ztwLNqVgxz-jrrxIKBh_X5WnUpuDEGX576_xkt4b1S3Vb-vIEFQyt3vPFDK3pYMTq_q8AznYcmG_2jf2IWFHr-T6S7IX0Nyb0cr39aA Jun 16 22:59:46 rivo volumio[3128]: info: Spotify credentials grant success - running version from March 24, 2019 Jun 16 22:59:46 rivo systemd[1]: Started Volumio Qobuz Connect Service. Jun 16 22:59:46 rivo sudo[3629]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:46 rivo volumio[3128]: info: Reporting MCU Network Status: 1 Jun 16 22:59:46 rivo volumio[3128]: info: Volumio Network Manager: Network status updated: 1 Jun 16 22:59:46 rivo sudo[3620]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 16 22:59:46 rivo sudo[3620]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:46 rivo sudo[3620]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:46 rivo volumio[3128]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Jun 16 22:59:46 rivo volumio[3128]: info: QobuzConnect: setDeactiveState invoked Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::volumioGetState Jun 16 22:59:46 rivo volumio[3128]: info: CorePlayQueue::getTrack 0 Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jun 16 22:59:46 rivo go-librespot[3574]: time="2025-06-16T22:59:46+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:46 rivo volumio[3128]: info: Executing endpoint qc_getconfig Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Jun 16 22:59:46 rivo qobuz-connect[3634]: 20250616 22:59:46.534 [3634.3634] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Jun 16 22:59:46 rivo qobuz-connect[3634]: 20250616 22:59:46.541 [3634.3634] INFO VolumeManager: [0xac499908]: Setting new playback volume: 75 Jun 16 22:59:46 rivo qobuz-connect[3634]: 20250616 22:59:46.541 [3634.3634] INFO VolumeManager: [0xac499908]: Setting new mute state: 0 Jun 16 22:59:46 rivo qobuz-connect[3634]: 20250616 22:59:46.541 [3634.3634] INFO QobuzConnect: [0xac49a2d8]: Client initialized! Jun 16 22:59:46 rivo qobuz-connect[3634]: 20250616 22:59:46.541 [3634.3634] INFO SampleApp: Starting Avahi advertising, name: Rivo, service name: _qobuz-connect._tcp Jun 16 22:59:46 rivo volumio[3128]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Jun 16 22:59:46 rivo volumio[3128]: info: QobuzConnect: QOBUZ Connect daemon connected Jun 16 22:59:46 rivo qobuz-connect[3634]: 20250616 22:59:46.558 [3634.3634] INFO LocalConfigManager: [0xac4991e8]: Starting Local Configuration server Jun 16 22:59:46 rivo qobuz-connect[3634]: 20250616 22:59:46.558 [3634.3634] INFO SampleApp: Starting Local configuration server Jun 16 22:59:46 rivo qobuz-connect[3634]: 20250616 22:59:46.559 [3634.3634] INFO SampleApp: Connected to UNIX socket client 0xac48eed8 Jun 16 22:59:46 rivo volumio[3128]: SPOTIFY: User informations: {"country":"PL","display_name":"Mariusz","email":"kupraczmariusz@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/kuperaszzz"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/kuperaszzz","id":"kuperaszzz","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85a4540c233b3d6e8d4072d777","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82a4540c233b3d6e8d4072d777","width":64}],"product":"premium","type":"user","uri":"spotify:user:kuperaszzz"} Jun 16 22:59:46 rivo go-librespot[3574]: time="2025-06-16T22:59:46+02:00" level=debug msg="completed keyexchange" Jun 16 22:59:46 rivo volumio[3128]: info: Spotify Successfully logged in Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 22:59:46 rivo volumio[3128]: info: [1750107586653] CoreMusicLibrary::Adding element Spotify Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 22:59:46 rivo volumio[3128]: Cannot find translation for source Spotify Jun 16 22:59:46 rivo qobuz-connect[3634]: 20250616 22:59:46.683 [3634.3634] INFO SampleApp: Playback volume changed: 75 Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::volumioGetState Jun 16 22:59:46 rivo volumio[3128]: info: CorePlayQueue::getTrack 0 Jun 16 22:59:46 rivo volumio[3128]: info: Successfully retrieved User Session From TIDAL Jun 16 22:59:46 rivo volumio[3128]: info: camilladsp spawned new process with pid 3652, instance 1, run: true Jun 16 22:59:46 rivo volumio[3128]: info: camilladsp service started and running in background, instance 1 Jun 16 22:59:46 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 22:59:46 rivo kernel: aml_spdif_open Jun 16 22:59:46 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 16 22:59:46 rivo kernel: spdif_a keep clk continuous Jun 16 22:59:46 rivo kernel: aml_spdif_close Jun 16 22:59:46 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 16 22:59:46 rivo kernel: aml_spdif_open Jun 16 22:59:46 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 16 22:59:46 rivo kernel: set normal 512 fs /4 fs Jun 16 22:59:46 rivo kernel: set spdifout clk:5644800, mpll:22579200 Jun 16 22:59:46 rivo kernel: get spdifout clk:5644797, mpll:22579186 Jun 16 22:59:46 rivo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Jun 16 22:59:46 rivo kernel: set normal 512 fs /4 fs Jun 16 22:59:46 rivo kernel: set spdifout clk:5644800, mpll:22579200 Jun 16 22:59:46 rivo kernel: get spdifout clk:5644797, mpll:22579186 Jun 16 22:59:46 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Jun 16 22:59:46 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Jun 16 22:59:46 rivo volumio[3128]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA Jun 16 22:59:47 rivo volumio[3128]: info: FusionDsp loaded Jun 16 22:59:47 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 22:59:47 rivo sudo[3664]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jun 16 22:59:47 rivo sudo[3664]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:47 rivo volumio[3128]: info: FusionDsp - Reporting Fusion DSP Enabled Jun 16 22:59:47 rivo volumio[3128]: info: Adding Signal Path Element [object Object] Jun 16 22:59:47 rivo volumio[3128]: info: Adding fusiondspeq DSP Signal Path Element Jun 16 22:59:47 rivo volumio[3128]: info: FusionDsp - ---- installed callbackRead Jun 16 22:59:47 rivo volumio[3128]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 16 22:59:47 rivo systemd[1]: Started FusionDsp Daemon. Jun 16 22:59:47 rivo volumio[3128]: info: FusionDsp - Effects disabled Jun 16 22:59:47 rivo sudo[3664]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:47 rivo volumio[3128]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jun 16 22:59:47 rivo go-librespot[3574]: time="2025-06-16T22:59:47+02:00" level=debug msg="completed challenge" Jun 16 22:59:47 rivo volumio[3128]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 16 22:59:47 rivo volumio[3128]: info: TidalConnect service stoped! Jun 16 22:59:47 rivo volumio[3128]: info: Turning Off Onboard LEDs Jun 16 22:59:47 rivo go-librespot[3574]: time="2025-06-16T22:59:47+02:00" level=debug msg="authenticated as kuperaszzz" Jun 16 22:59:47 rivo volumio[3128]: info: Successfully retrieved User Subscription From TIDAL Jun 16 22:59:47 rivo volumio[3128]: info: Adding TIDAL to Browse Sources Jun 16 22:59:47 rivo volumio[3128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 22:59:47 rivo volumio[3128]: info: [1750107587280] CoreMusicLibrary::Adding element TIDAL Jun 16 22:59:47 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 22:59:47 rivo volumio[3128]: Cannot find translation for source Spotify Jun 16 22:59:47 rivo volumio[3128]: Cannot find translation for source TIDAL Jun 16 22:59:47 rivo volumio[3128]: info: Stopping AccessToken refresher cron Jun 16 22:59:47 rivo sudo[3674]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/sys_led/trigger Jun 16 22:59:47 rivo sudo[3674]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:47 rivo sudo[3674]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:47 rivo sudo[3677]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/red_red/trigger Jun 16 22:59:47 rivo sudo[3677]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:47 rivo sudo[3677]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:47 rivo volumio[3128]: info: AccessToken refresher cron started Jun 16 22:59:47 rivo volumio[3128]: info: Adding TIDAL REST API Endpoints Jun 16 22:59:47 rivo volumio[3128]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Jun 16 22:59:47 rivo volumio[3128]: info: Onboard LEDs initialized Jun 16 22:59:47 rivo volumio[3128]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Jun 16 22:59:47 rivo volumio[3128]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Jun 16 22:59:47 rivo go-librespot[3574]: time="2025-06-16T22:59:47+02:00" level=debug msg="authenticated as kuperaszzz" Jun 16 22:59:47 rivo sudo[3684]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Jun 16 22:59:47 rivo sudo[3684]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 22:59:47 rivo go-librespot[3574]: time="2025-06-16T22:59:47+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jun 16 22:59:47 rivo systemd[1]: Started Volumio Tidal Connect Service. Jun 16 22:59:47 rivo sudo[3684]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:47 rivo go-librespot[3574]: time="2025-06-16T22:59:47+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jun 16 22:59:47 rivo go-librespot[3574]: time="2025-06-16T22:59:47+02:00" level=debug msg="dealer connection opened" Jun 16 22:59:47 rivo go-librespot[3574]: time="2025-06-16T22:59:47+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jun 16 22:59:47 rivo go-librespot[3574]: time="2025-06-16T22:59:47+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jun 16 22:59:47 rivo go-librespot[3574]: time="2025-06-16T22:59:47+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jun 16 22:59:47 rivo go-librespot[3574]: time="2025-06-16T22:59:47+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jun 16 22:59:47 rivo go-librespot[3574]: time="2025-06-16T22:59:47+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jun 16 22:59:47 rivo go-librespot[3574]: time="2025-06-16T22:59:47+02:00" level=debug msg="received connection id: YTk1YTA0NGEtMmRlZS00Y2VkLTlhYTktZTYyNGU0M2RlODYyK2RlYWxlcit0Y3A6Ly8wYWNhNTgxYy5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArRDhFODNGOTQ1NzE5NTMzRjRBQjgzQjlEMTk4MEUzQzk5NzFFRjZGMDc3N0RGQzcwNUMxRkQ3RERCMUFGMjcxMQ==" Jun 16 22:59:47 rivo volumio[3128]: info: Executing endpoint tc_getconfig Jun 16 22:59:47 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Jun 16 22:59:48 rivo vtcs[3686]: STARTING TidalConnect services, version: 1.4.0.34 Jun 16 22:59:48 rivo go-librespot[3574]: time="2025-06-16T22:59:48+02:00" level=debug msg="put connect state because NEW_DEVICE" Jun 16 22:59:48 rivo vtcs[3686]: STARTED TidalConnect services. Jun 16 22:59:48 rivo volumio[3128]: info: Executing endpoint tc_connect Jun 16 22:59:48 rivo volumio[3128]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Jun 16 22:59:48 rivo volumio[3128]: info: Connecting to TidalConnect Jun 16 22:59:48 rivo volumio[3128]: info: CoreCommandRouter::servicePushState Jun 16 22:59:48 rivo volumio[3128]: info: CoreStateMachine::pushState Jun 16 22:59:48 rivo volumio[3128]: info: CorePlayQueue::getTrack 0 Jun 16 22:59:48 rivo volumio[3128]: info: CoreCommandRouter::volumioPushState Jun 16 22:59:48 rivo volumio[3128]: info: CoreCommandRouter::volumioGetState Jun 16 22:59:48 rivo volumio[3128]: info: CorePlayQueue::getTrack 0 Jun 16 22:59:48 rivo volumio[3128]: info: CorePlayQueue::getTrack 0 Jun 16 22:59:48 rivo volumio[3128]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect Jun 16 22:59:48 rivo volumio[3128]: info: CoreCommandRouter::servicePushState Jun 16 22:59:48 rivo volumio[3128]: info: CoreStateMachine::pushState Jun 16 22:59:48 rivo volumio[3128]: info: CorePlayQueue::getTrack 0 Jun 16 22:59:48 rivo volumio[3128]: info: CoreCommandRouter::volumioPushState Jun 16 22:59:48 rivo volumio[3128]: info: CoreCommandRouter::volumioGetState Jun 16 22:59:48 rivo volumio[3128]: info: CorePlayQueue::getTrack 0 Jun 16 22:59:48 rivo volumio[3128]: info: CorePlayQueue::getTrack 0 Jun 16 22:59:48 rivo volumio[3128]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect Jun 16 22:59:48 rivo mpd[3638]: Jun 16 22:59 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 16 22:59:48 rivo systemd[1]: Started Music Player Daemon. Jun 16 22:59:48 rivo sudo[3498]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:48 rivo volumio[3128]: Upnp client error: Error: This socket has been ended by the other party Jun 16 22:59:48 rivo sudo[3602]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:48 rivo sudo[3486]: pam_unix(sudo:session): session closed for user root Jun 16 22:59:48 rivo volumio[3128]: error: MPD error: The expression evaluated to a falsy value: Jun 16 22:59:48 rivo volumio[3128]: assert.ok(self.idling) Jun 16 22:59:48 rivo volumio[3128]: error: The expression evaluated to a falsy value: Jun 16 22:59:48 rivo volumio[3128]: assert.ok(self.idling) Jun 16 22:59:48 rivo volumio[3128]: error: MPD error: The expression evaluated to a falsy value: Jun 16 22:59:48 rivo volumio[3128]: assert.ok(self.idling) Jun 16 22:59:48 rivo volumio[3128]: error: The expression evaluated to a falsy value: Jun 16 22:59:48 rivo volumio[3128]: assert.ok(self.idling) Jun 16 22:59:48 rivo volumio[3128]: error: updateQueue error: null Jun 16 22:59:48 rivo volumio[3128]: info: MPD running with PID3638 Jun 16 22:59:48 rivo volumio[3128]: ,establishing connection Jun 16 22:59:48 rivo volumio[3128]: error: updateQueue error: null Jun 16 22:59:48 rivo volumio[3128]: info: go-librespot daemon successfully initialized Jun 16 22:59:48 rivo volumio[3484]: Generating RSA private key, 4096 bit long modulus (2 primes) Jun 16 22:59:50 rivo volumio-remote-updater[2827]: [2025-06-16 22:59:50] [connect] Successful connection Jun 16 22:59:50 rivo volumio-remote-updater[2827]: [2025-06-16 22:59:50] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1750107590 101 Jun 16 22:59:50 rivo volumio[3128]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 4 Jun 16 22:59:50 rivo volumio[3128]: info: TidalConnect service started! Jun 16 22:59:50 rivo volumio[3128]: info: Completed starting Core Plugins Jun 16 22:59:50 rivo volumio[3128]: info: ------------------------------------------- Jun 16 22:59:50 rivo volumio[3128]: info: ----- MyVolumio plugins startup ---- Jun 16 22:59:50 rivo volumio[3128]: info: ------------------------------------------- Jun 16 22:59:50 rivo volumio[3128]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 16 22:59:51 rivo go-librespot[3574]: time="2025-06-16T22:59:51+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 16 22:59:51 rivo go-librespot[3574]: time="2025-06-16T22:59:51+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 338" Jun 16 22:59:51 rivo go-librespot[3574]: time="2025-06-16T22:59:51+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 16 22:59:51 rivo go-librespot[3574]: time="2025-06-16T22:59:51+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1741" Jun 16 22:59:51 rivo volumio[3128]: info: Initializing connection to go-librespot Websocket Jun 16 22:59:51 rivo go-librespot[3574]: time="2025-06-16T22:59:51+02:00" level=debug msg="new websocket client" Jun 16 22:59:51 rivo volumio[3128]: info: Connection to go-librespot Websocket established Jun 16 22:59:53 rivo go-librespot[3574]: time="2025-06-16T22:59:53+02:00" level=debug msg="handling transfer player command from a1145e71ee3ec0c8ff2c4663b8fa7f893ffeb57e" Jun 16 22:59:53 rivo go-librespot[3574]: time="2025-06-16T22:59:53+02:00" level=trace msg="fetched new page 0 with 31 items (list: 31)" Jun 16 22:59:53 rivo go-librespot[3574]: time="2025-06-16T22:59:53+02:00" level=debug msg="loading track spotify:track:70RkgofUfQHLl2FT2Mx5zq (paused: false, position: 2284ms)" Jun 16 22:59:53 rivo go-librespot[3574]: time="2025-06-16T22:59:53+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 16 22:59:53 rivo go-librespot[3574]: time="2025-06-16T22:59:53+02:00" level=trace msg="emitting websocket event: will_play" Jun 16 22:59:53 rivo volumio[3128]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:70RkgofUfQHLl2FT2Mx5zq","play_origin":""}} Jun 16 22:59:53 rivo go-librespot[3574]: time="2025-06-16T22:59:53+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Jun 16 22:59:53 rivo go-librespot[3574]: time="2025-06-16T22:59:53+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:70RkgofUfQHLl2FT2Mx5zq" Jun 16 22:59:53 rivo go-librespot[3574]: time="2025-06-16T22:59:53+02:00" level=debug msg="requested aes key for file 45a944e5f38e069cc6d3521480677ec813fb7f73, gid: 70RkgofUfQHLl2FT2Mx5zq" Jun 16 22:59:53 rivo go-librespot[3574]: time="2025-06-16T22:59:53+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1663" Jun 16 22:59:53 rivo volumio[3128]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jun 16 22:59:53 rivo go-librespot[3574]: time="2025-06-16T22:59:53+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1276" Jun 16 22:59:53 rivo go-librespot[3574]: time="2025-06-16T22:59:53+02:00" level=debug msg="fetched first chunk of 11, total size is 5333172 bytes" Jun 16 22:59:53 rivo go-librespot[3574]: time="2025-06-16T22:59:53+02:00" level=trace msg="seek to 2284ms (diff: 205ms, samples: 100724, bytes: 65555)" Jun 16 22:59:53 rivo volumio[3128]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jun 16 22:59:53 rivo go-librespot[3574]: time="2025-06-16T22:59:53+02:00" level=info msg="loaded track \"Rinzler\" (uri: spotify:track:70RkgofUfQHLl2FT2Mx5zq, paused: false, position: 2284ms, duration: 137635ms)" Jun 16 22:59:53 rivo volumio[3128]: info: FusionDsp - ---- read samplerate from file: 44100 Jun 16 22:59:53 rivo volumio[3128]: info: camilladsp stopping service pid 3652... Jun 16 22:59:53 rivo kernel: spdif_a keep clk continuous Jun 16 22:59:53 rivo kernel: aml_spdif_close Jun 16 22:59:53 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 16 22:59:54 rivo volumio[3128]: info: camilladsp service terminated, instance 1 Jun 16 22:59:54 rivo volumio[3128]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 16 22:59:54 rivo volumio[3128]: info: FusionDsp - Effects disabled Jun 16 22:59:54 rivo volumio[3128]: info: camilladsp service started and running in background, instance 1 Jun 16 22:59:54 rivo volumio[3128]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jun 16 22:59:54 rivo volumio[3128]: info: FusionDsp - ---- read samplerate from file: 44100 Jun 16 22:59:54 rivo volumio[3128]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 16 22:59:54 rivo volumio[3128]: info: FusionDsp - Effects disabled Jun 16 22:59:54 rivo volumio[3128]: error: FusionDsp - WebSocket error: [object Object] Jun 16 22:59:54 rivo go-librespot[3574]: time="2025-06-16T22:59:54+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 16 22:59:54 rivo go-librespot[3574]: time="2025-06-16T22:59:54+02:00" level=trace msg="emitting websocket event: metadata" Jun 16 22:59:54 rivo go-librespot[3574]: time="2025-06-16T22:59:54+02:00" level=trace msg="emitting websocket event: active" Jun 16 22:59:54 rivo go-librespot[3574]: time="2025-06-16T22:59:54+02:00" level=debug msg="sending successful reply for delaer request" Jun 16 22:59:54 rivo volumio[3128]: info: camilladsp spawned new process with pid 3730, instance 1, run: true Jun 16 22:59:54 rivo volumio[3128]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:70RkgofUfQHLl2FT2Mx5zq","name":"Rinzler","artist_names":["Daft Punk"],"album_name":"TRON: Legacy - The Complete Edition (Original Motion Picture Soundtrack)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e028323143296ff7b2801e32789","position":2284,"duration":137635,"release_date":"year:2010 month:12 day:3","track_number":7,"disc_number":1}} Jun 16 22:59:54 rivo volumio[3128]: SPOTIFY: received: {"type":"active","data":null} Jun 16 22:59:54 rivo go-librespot[3574]: time="2025-06-16T22:59:54+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 16 22:59:54 rivo go-librespot[3574]: time="2025-06-16T22:59:54+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 16 22:59:54 rivo volumio[3128]: info: Aligning Spotify Volume to Volumio Volume Jun 16 22:59:54 rivo volumio[3128]: info: CoreCommandRouter::volumioGetState Jun 16 22:59:54 rivo volumio[3128]: info: CorePlayQueue::getTrack 0 Jun 16 22:59:54 rivo go-librespot[3574]: time="2025-06-16T22:59:54+02:00" level=debug msg="fetched chunk 1/10, size: 524288" Jun 16 22:59:54 rivo kernel: aml_spdif_open Jun 16 22:59:54 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 16 22:59:54 rivo kernel: set normal 512 fs /4 fs Jun 16 22:59:54 rivo kernel: set spdifout clk:5644800, mpll:22579200 Jun 16 22:59:54 rivo kernel: get spdifout clk:5644797, mpll:22579186 Jun 16 22:59:54 rivo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Jun 16 22:59:54 rivo kernel: set normal 512 fs /4 fs Jun 16 22:59:54 rivo kernel: set spdifout clk:5644800, mpll:22579200 Jun 16 22:59:54 rivo kernel: get spdifout clk:5644797, mpll:22579186 Jun 16 22:59:54 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Jun 16 22:59:54 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Jun 16 22:59:54 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Jun 16 22:59:54 rivo go-librespot[3574]: time="2025-06-16T22:59:54+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 16 22:59:54 rivo go-librespot[3574]: time="2025-06-16T22:59:54+02:00" level=trace msg="emitting websocket event: playing" Jun 16 22:59:54 rivo volumio[3128]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:70RkgofUfQHLl2FT2Mx5zq","play_origin":""}} Jun 16 22:59:54 rivo volumio[3128]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 16 22:59:54 rivo volumio[3128]: TypeError: Cannot read property 'service' of undefined Jun 16 22:59:54 rivo volumio[3128]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Jun 16 22:59:54 rivo volumio[3128]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:262:18) Jun 16 22:59:54 rivo volumio[3128]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Jun 16 22:59:54 rivo volumio[3128]: at WebSocket.emit (events.js:400:28) Jun 16 22:59:54 rivo volumio[3128]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1203:20) Jun 16 22:59:54 rivo volumio[3128]: at Receiver.emit (events.js:400:28) Jun 16 22:59:54 rivo volumio[3128]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:608:16 Jun 16 22:59:54 rivo volumio[3128]: at internal/process/task_queues.js:141:7 Jun 16 22:59:54 rivo volumio[3128]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) Jun 16 22:59:54 rivo volumio[3128]: at AsyncResource.runMicrotask (internal/process/task_queues.js:138:8) Jun 16 22:59:54 rivo volumio[3128]: at runMicrotasks () Jun 16 22:59:54 rivo volumio[3128]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Jun 16 22:59:54 rivo volumio[3128]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 16 22:59:54 rivo go-librespot[3574]: time="2025-06-16T22:59:54+02:00" level=debug msg="fetched chunk 2/10, size: 524288" Jun 16 22:59:54 rivo go-librespot[3574]: time="2025-06-16T22:59:54+02:00" level=debug msg="fetched chunk 3/10, size: 524288" Jun 16 22:59:54 rivo sudo[3748]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-16 22:58 Jun 16 22:59:54 rivo sudo[3748]: 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 06:24:39 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="c8a59422b1bfedffc72f72cef58ad20b"