-- Logs begin at Fri 2025-02-21 15:51:55 CET, end at Fri 2025-02-21 15:53:55 CET. -- Feb 21 15:52:00 volumiorp5 sudo[1073]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:00 volumiorp5 wireless.js[776]: SETTING APPROPRIATE REG DOMAIN: NL Feb 21 15:52:00 volumiorp5 sudo[1078]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Feb 21 15:52:00 volumiorp5 sudo[1078]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:00 volumiorp5 sudo[1078]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:00 volumiorp5 sudo[1080]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set NL Feb 21 15:52:00 volumiorp5 sudo[1080]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:00 volumiorp5 sudo[1080]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:00 volumiorp5 wireless.js[776]: SUCCESSFULLY SET NEW REGDOMAIN: NL Feb 21 15:52:00 volumiorp5 wireless.js[776]: Start wireless flow Feb 21 15:52:00 volumiorp5 wireless.js[776]: Stopped hotspot (if there).. Feb 21 15:52:00 volumiorp5 sudo[1085]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Feb 21 15:52:00 volumiorp5 sudo[1085]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:00 volumiorp5 sudo[1085]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:00 volumiorp5 sudo[1087]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Feb 21 15:52:00 volumiorp5 sudo[1087]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:00 volumiorp5 kernel: macb 1f00100000.ethernet eth0: Link is Up - 1Gbps/Full - flow control tx Feb 21 15:52:00 volumiorp5 ntpd[982]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Feb 21 15:52:00 volumiorp5 sh[701]: eth0: carrier acquired Feb 21 15:52:00 volumiorp5 dhcpcd[749]: eth0: carrier acquired Feb 21 15:52:00 volumiorp5 sudo[1087]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:00 volumiorp5 sh[701]: DUID 00:01:00:01:2e:f2:a2:d6:2c:cf:67:c8:c5:84 Feb 21 15:52:00 volumiorp5 sh[701]: eth0: IAID 67:c8:c5:84 Feb 21 15:52:00 volumiorp5 dhcpcd[749]: DUID 00:01:00:01:2e:f2:a2:d6:2c:cf:67:c8:c5:84 Feb 21 15:52:00 volumiorp5 dhcpcd[749]: eth0: IAID 67:c8:c5:84 Feb 21 15:52:00 volumiorp5 sh[701]: eth0: adding address fe80::8fd:4f6e:fe18:4227 Feb 21 15:52:00 volumiorp5 sh[701]: ipv6_addaddr1: Permission denied Feb 21 15:52:00 volumiorp5 dhcpcd[749]: eth0: adding address fe80::8fd:4f6e:fe18:4227 Feb 21 15:52:00 volumiorp5 dhcpcd[749]: ipv6_addaddr1: Permission denied Feb 21 15:52:00 volumiorp5 wireless.js[776]: DHCP IP Feb 21 15:52:00 volumiorp5 wireless.js[776]: Start ap Feb 21 15:52:00 volumiorp5 wpa_supplicant[1090]: Successfully initialized wpa_supplicant Feb 21 15:52:00 volumiorp5 sudo[1091]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Feb 21 15:52:00 volumiorp5 sudo[1091]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:00 volumiorp5 dhcpcd[1092]: dev: loaded udev Feb 21 15:52:00 volumiorp5 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Feb 21 15:52:00 volumiorp5 dhcpcd-run-hooks[1101]: wlan0: starting wpa_supplicant Feb 21 15:52:00 volumiorp5 ifplugd(eth0)[1015]: Link beat detected. Feb 21 15:52:00 volumiorp5 dhcpcd-run-hooks[1106]: wlan0: failed to start wpa_supplicant Feb 21 15:52:00 volumiorp5 dhcpcd-run-hooks[1107]: wlan0: Successfully initialized wpa_supplicant nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Ma Feb 21 15:52:00 volumiorp5 dhcpcd[1092]: wlan0: connected to Access Point `' Feb 21 15:52:00 volumiorp5 dhcpcd[1092]: DUID 00:01:00:01:2e:f2:a2:d6:2c:cf:67:c8:c5:84 Feb 21 15:52:00 volumiorp5 dhcpcd[1092]: eth0: IAID 67:c8:c5:84 Feb 21 15:52:00 volumiorp5 dhcpcd[1092]: eth0: adding address fe80::8fd:4f6e:fe18:4227 Feb 21 15:52:00 volumiorp5 dhcpcd[1092]: ipv6_addaddr1: Permission denied Feb 21 15:52:00 volumiorp5 dhcpcd[1092]: wlan0: waiting for carrier Feb 21 15:52:00 volumiorp5 ifplugd(eth0)[1015]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Feb 21 15:52:00 volumiorp5 ifplugd(eth0)[1015]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Feb 21 15:52:00 volumiorp5 sh[701]: eth0: soliciting an IPv6 router Feb 21 15:52:00 volumiorp5 dhcpcd[749]: eth0: soliciting an IPv6 router Feb 21 15:52:01 volumiorp5 sh[701]: eth0: soliciting a DHCP lease Feb 21 15:52:01 volumiorp5 dhcpcd[749]: eth0: soliciting a DHCP lease Feb 21 15:52:01 volumiorp5 systemd[1]: systemd-rfkill.service: Succeeded. Feb 21 15:52:01 volumiorp5 volumio-remote-updater[770]: [2025-02-21 15:52:01] [info] asio async_connect error: system:111 (Connection refused) Feb 21 15:52:01 volumiorp5 volumio-remote-updater[770]: [2025-02-21 15:52:01] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Feb 21 15:52:01 volumiorp5 volumio-remote-updater[770]: [2025-02-21 15:52:01] [error] handle_connect error: Underlying Transport Error Feb 21 15:52:01 volumiorp5 volumio-time-update[778]: volumio-time-update-util: Fetching time from Volumio... Feb 21 15:52:01 volumiorp5 volumio-time-update[778]: volumio-time-update-util: Date not found in response Feb 21 15:52:01 volumiorp5 volumio-time-update[778]: volumio-time-update-util: Retrying in 5 seconds... Feb 21 15:52:01 volumiorp5 sh[701]: eth0: offered 192.168.0.102 from 192.168.0.1 Feb 21 15:52:01 volumiorp5 dhcpcd[749]: eth0: offered 192.168.0.102 from 192.168.0.1 Feb 21 15:52:01 volumiorp5 dhcpcd[1092]: eth0: soliciting a DHCP lease Feb 21 15:52:01 volumiorp5 dhcpcd[1092]: eth0: soliciting an IPv6 router Feb 21 15:52:01 volumiorp5 wireless.js[776]: trying... Feb 21 15:52:01 volumiorp5 sudo[1130]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 21 15:52:01 volumiorp5 sudo[1130]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:01 volumiorp5 sudo[1130]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:01 volumiorp5 sh[701]: eth0: probing address 192.168.0.102/24 Feb 21 15:52:01 volumiorp5 dhcpcd[749]: eth0: probing address 192.168.0.102/24 Feb 21 15:52:01 volumiorp5 bthelper[908]: Changing power off succeeded Feb 21 15:52:02 volumiorp5 dhcpcd[1092]: eth0: offered 192.168.0.102 from 192.168.0.1 Feb 21 15:52:02 volumiorp5 bthelper[908]: [CHG] Controller 2C:CF:67:C8:C5:86 Class: 0x0000041c Feb 21 15:52:02 volumiorp5 bthelper[908]: Changing power on succeeded Feb 21 15:52:02 volumiorp5 dhcpcd[1092]: eth0: probing address 192.168.0.102/24 Feb 21 15:52:02 volumiorp5 wireless.js[776]: trying... Feb 21 15:52:02 volumiorp5 sudo[1134]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 21 15:52:02 volumiorp5 sudo[1134]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:02 volumiorp5 sudo[1134]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:03 volumiorp5 wireless.js[776]: trying... Feb 21 15:52:03 volumiorp5 sudo[1137]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 21 15:52:03 volumiorp5 sudo[1137]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:03 volumiorp5 sudo[1137]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:04 volumiorp5 wireless.js[776]: trying... Feb 21 15:52:04 volumiorp5 sudo[1140]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 21 15:52:04 volumiorp5 sudo[1140]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:04 volumiorp5 sudo[1140]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:05 volumiorp5 wireless.js[776]: trying... Feb 21 15:52:05 volumiorp5 sudo[1143]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 21 15:52:05 volumiorp5 sudo[1143]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:05 volumiorp5 sudo[1143]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:06 volumiorp5 volumio-time-update[778]: volumio-time-update-util: Fetching time from Volumio... Feb 21 15:52:06 volumiorp5 volumio-time-update[778]: volumio-time-update-util: Date not found in response Feb 21 15:52:06 volumiorp5 volumio-time-update[778]: volumio-time-update-util: Retrying in 5 seconds... Feb 21 15:52:06 volumiorp5 sh[701]: eth0: leased 192.168.0.102 for 86400 seconds Feb 21 15:52:06 volumiorp5 sh[701]: eth0: adding route to 192.168.0.0/24 Feb 21 15:52:06 volumiorp5 sh[701]: eth0: adding default route via 192.168.0.1 Feb 21 15:52:06 volumiorp5 dhcpcd[749]: eth0: leased 192.168.0.102 for 86400 seconds Feb 21 15:52:06 volumiorp5 dhcpcd[749]: eth0: adding route to 192.168.0.0/24 Feb 21 15:52:06 volumiorp5 dhcpcd[749]: eth0: adding default route via 192.168.0.1 Feb 21 15:52:06 volumiorp5 avahi-daemon[767]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.0.102. Feb 21 15:52:06 volumiorp5 avahi-daemon[767]: New relevant interface eth0.IPv4 for mDNS. Feb 21 15:52:06 volumiorp5 avahi-daemon[767]: Registering new address record for 192.168.0.102 on eth0.IPv4. Feb 21 15:52:06 volumiorp5 sh[701]: forked to background, child pid 1170 Feb 21 15:52:06 volumiorp5 dhcpcd[749]: forked to background, child pid 1170 Feb 21 15:52:06 volumiorp5 ifplugd(eth0)[1015]: client: ifup: interface eth0 already configured Feb 21 15:52:06 volumiorp5 sh[701]: eth0=eth0 Feb 21 15:52:06 volumiorp5 wpa_supplicant[1105]: wlan0: Trying to associate with SSID 'UPC2711479' Feb 21 15:52:06 volumiorp5 dhcpcd[1092]: wlan0: carrier acquired Feb 21 15:52:06 volumiorp5 dhcpcd[1092]: wlan0: connected to Access Point `UPC2711479' Feb 21 15:52:06 volumiorp5 wpa_supplicant[1105]: wlan0: Associated with 20:b8:2b:15:e3:5e Feb 21 15:52:06 volumiorp5 wpa_supplicant[1105]: wlan0: CTRL-EVENT-CONNECTED - Connection to 20:b8:2b:15:e3:5e completed [id=0 id_str=] Feb 21 15:52:06 volumiorp5 wpa_supplicant[1105]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Feb 21 15:52:06 volumiorp5 ifplugd(eth0)[1015]: Program executed successfully. Feb 21 15:52:06 volumiorp5 wpa_supplicant[1105]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=NL Feb 21 15:52:06 volumiorp5 dhcpcd[1092]: wlan0: IAID 67:c8:c5:85 Feb 21 15:52:06 volumiorp5 dhcpcd[1092]: wlan0: adding address fe80::a984:3e26:dc94:8b32 Feb 21 15:52:06 volumiorp5 dhcpcd[1092]: ipv6_addaddr1: Permission denied Feb 21 15:52:06 volumiorp5 dhcpcd[1092]: wlan0: carrier lost Feb 21 15:52:06 volumiorp5 dhcpcd[1092]: wlan0: carrier acquired Feb 21 15:52:06 volumiorp5 dhcpcd[1092]: wlan0: IAID 67:c8:c5:85 Feb 21 15:52:06 volumiorp5 wireless.js[776]: trying... Feb 21 15:52:06 volumiorp5 sudo[1217]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 21 15:52:06 volumiorp5 sudo[1217]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:06 volumiorp5 sudo[1217]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:06 volumiorp5 nmbd[942]: [2025/02/21 15:52:06.842692, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 21 15:52:06 volumiorp5 nmbd[942]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Feb 21 15:52:06 volumiorp5 systemd[1]: Started Samba NMB Daemon. Feb 21 15:52:06 volumiorp5 systemd[1]: Starting Samba Winbind Daemon... Feb 21 15:52:06 volumiorp5 winbindd[1219]: [2025/02/21 15:52:06.934550, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Feb 21 15:52:06 volumiorp5 winbindd[1219]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Feb 21 15:52:06 volumiorp5 winbindd[1219]: [2025/02/21 15:52:06.938526, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 21 15:52:06 volumiorp5 winbindd[1219]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Feb 21 15:52:06 volumiorp5 systemd[1]: Started Samba Winbind Daemon. Feb 21 15:52:06 volumiorp5 systemd[1]: Starting Samba SMB Daemon... Feb 21 15:52:07 volumiorp5 smbd[1224]: [2025/02/21 15:52:07.076223, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 21 15:52:07 volumiorp5 systemd[1]: Started Samba SMB Daemon. Feb 21 15:52:07 volumiorp5 smbd[1224]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Feb 21 15:52:07 volumiorp5 dhcpcd[1092]: eth0: leased 192.168.0.102 for 86400 seconds Feb 21 15:52:07 volumiorp5 dhcpcd[1092]: eth0: adding route to 192.168.0.0/24 Feb 21 15:52:07 volumiorp5 dhcpcd[1092]: eth0: adding default route via 192.168.0.1 Feb 21 15:52:07 volumiorp5 dhcpcd[1092]: forked to background, child pid 1252 Feb 21 15:52:07 volumiorp5 sudo[1091]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:07 volumiorp5 dhcpcd[1252]: wlan0: soliciting an IPv6 router Feb 21 15:52:07 volumiorp5 dhcpcd[1252]: wlan0: rebinding lease of 192.168.0.103 Feb 21 15:52:07 volumiorp5 wireless.js[776]: trying... Feb 21 15:52:07 volumiorp5 sudo[1257]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 21 15:52:07 volumiorp5 sudo[1257]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:07 volumiorp5 sudo[1257]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:07 volumiorp5 dhcpcd[1252]: wlan0: probing address 192.168.0.103/24 Feb 21 15:52:08 volumiorp5 ntpd[982]: Listen normally on 3 eth0 192.168.0.102:123 Feb 21 15:52:08 volumiorp5 ntpd[982]: new interface(s) found: waking up resolver Feb 21 15:52:08 volumiorp5 wireless.js[776]: trying... Feb 21 15:52:08 volumiorp5 sudo[1260]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 21 15:52:08 volumiorp5 sudo[1260]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:08 volumiorp5 sudo[1260]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:08 volumiorp5 volumio-remote-updater[770]: [2025-02-21 15:52:08] [info] asio async_connect error: system:111 (Connection refused) Feb 21 15:52:08 volumiorp5 volumio-remote-updater[770]: [2025-02-21 15:52:08] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Feb 21 15:52:08 volumiorp5 volumio-remote-updater[770]: [2025-02-21 15:52:08] [error] handle_connect error: Underlying Transport Error Feb 21 15:52:09 volumiorp5 wireless.js[776]: trying... Feb 21 15:52:09 volumiorp5 sudo[1263]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 21 15:52:09 volumiorp5 sudo[1263]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:09 volumiorp5 sudo[1263]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:10 volumiorp5 wireless.js[776]: trying... Feb 21 15:52:10 volumiorp5 sudo[1266]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 21 15:52:10 volumiorp5 sudo[1266]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:10 volumiorp5 sudo[1266]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:11 volumiorp5 volumio-time-update[778]: volumio-time-update-util: Fetching time from Volumio... Feb 21 15:52:11 volumiorp5 volumio-time-update[778]: volumio-time-update-util: Setting system time to: 2025-02-21 15:52:11 Feb 21 15:52:11 volumiorp5 sudo[1273]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-02-21 15:52:11 Feb 21 15:52:11 volumiorp5 sudo[1273]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:11 volumiorp5 dbus-daemon[768]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.10' (uid=0 pid=1274 comm="timedatectl set-time 2025-02-21 15:52:11 ") Feb 21 15:52:11 volumiorp5 systemd[1]: Starting Time & Date Service... Feb 21 15:52:11 volumiorp5 dbus-daemon[768]: [system] Successfully activated service 'org.freedesktop.timedate1' Feb 21 15:52:11 volumiorp5 systemd[1]: Started Time & Date Service. Feb 21 15:52:11 volumiorp5 wireless.js[776]: trying... Feb 21 15:52:11 volumiorp5 sudo[1277]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 21 15:52:11 volumiorp5 sudo[1277]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:11 volumiorp5 sudo[1277]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:11 volumiorp5 systemd-timedated[1275]: Changed local time to Fri Feb 21 15:52:11 2025 Feb 21 15:52:11 volumiorp5 sudo[1273]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:11 volumiorp5 volumio-time-update[778]: volumio-time-update-util: System time updated successfully. Feb 21 15:52:11 volumiorp5 systemd[1]: Started Volumio Time Update Utility. Feb 21 15:52:12 volumiorp5 wireless.js[776]: trying... Feb 21 15:52:12 volumiorp5 sudo[1281]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 21 15:52:12 volumiorp5 sudo[1281]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:12 volumiorp5 sudo[1281]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:12 volumiorp5 dhcpcd[1252]: wlan0: leased 192.168.0.103 for 86400 seconds Feb 21 15:52:12 volumiorp5 avahi-daemon[767]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.103. Feb 21 15:52:12 volumiorp5 avahi-daemon[767]: New relevant interface wlan0.IPv4 for mDNS. Feb 21 15:52:12 volumiorp5 dhcpcd[1252]: wlan0: adding route to 192.168.0.0/24 Feb 21 15:52:12 volumiorp5 avahi-daemon[767]: Registering new address record for 192.168.0.103 on wlan0.IPv4. Feb 21 15:52:12 volumiorp5 dhcpcd[1252]: wlan0: adding default route via 192.168.0.1 Feb 21 15:52:12 volumiorp5 login[1017]: pam_unix(login:session): session opened for user volumio by LOGIN(uid=0) Feb 21 15:52:12 volumiorp5 systemd[1]: Created slice User Slice of UID 1000. Feb 21 15:52:12 volumiorp5 systemd[1]: Starting User Runtime Directory /run/user/1000... Feb 21 15:52:12 volumiorp5 systemd-logind[774]: New session 1 of user volumio. Feb 21 15:52:12 volumiorp5 systemd[1]: Started User Runtime Directory /run/user/1000. Feb 21 15:52:12 volumiorp5 systemd[1]: Starting User Manager for UID 1000... Feb 21 15:52:12 volumiorp5 systemd[1311]: pam_unix(systemd-user:session): session opened for user volumio by (uid=0) Feb 21 15:52:12 volumiorp5 systemd[1311]: Listening on GnuPG network certificate management daemon. Feb 21 15:52:12 volumiorp5 systemd[1311]: Starting D-Bus User Message Bus Socket. Feb 21 15:52:12 volumiorp5 systemd[1311]: Listening on GnuPG cryptographic agent and passphrase cache. Feb 21 15:52:12 volumiorp5 systemd[1311]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers). Feb 21 15:52:12 volumiorp5 systemd[1311]: Listening on GnuPG cryptographic agent (ssh-agent emulation). Feb 21 15:52:12 volumiorp5 systemd[1311]: Listening on Sound System. Feb 21 15:52:12 volumiorp5 systemd[1311]: Reached target Paths. Feb 21 15:52:12 volumiorp5 systemd[1311]: Reached target Timers. Feb 21 15:52:12 volumiorp5 systemd[1311]: Listening on GnuPG cryptographic agent and passphrase cache (restricted). Feb 21 15:52:13 volumiorp5 wireless.js[776]: trying... Feb 21 15:52:13 volumiorp5 systemd[1311]: Listening on D-Bus User Message Bus Socket. Feb 21 15:52:13 volumiorp5 systemd[1311]: Reached target Sockets. Feb 21 15:52:13 volumiorp5 systemd[1311]: Reached target Basic System. Feb 21 15:52:13 volumiorp5 systemd[1311]: Reached target Default. Feb 21 15:52:13 volumiorp5 systemd[1311]: Startup finished in 110ms. Feb 21 15:52:13 volumiorp5 systemd[1]: Started User Manager for UID 1000. Feb 21 15:52:13 volumiorp5 systemd[1]: Started Session 1 of user volumio. Feb 21 15:52:13 volumiorp5 sudo[1323]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 21 15:52:13 volumiorp5 sudo[1323]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:13 volumiorp5 sudo[1323]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:13 volumiorp5 wireless.js[776]: Connected to: ----UPC2711479 Feb 21 15:52:13 volumiorp5 wireless.js[776]: ---- Feb 21 15:52:13 volumiorp5 sudo[1327]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 15:52:13 volumiorp5 sudo[1327]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:13 volumiorp5 sudo[1327]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:13 volumiorp5 wireless.js[776]: ... joined AP, wlan0 IPv4 is 192.168.0.103, ipV6 is undefined Feb 21 15:52:13 volumiorp5 wireless.js[776]: It's done! AP Feb 21 15:52:13 volumiorp5 systemd[1]: Started Wireless Services. Feb 21 15:52:13 volumiorp5 systemd[1]: Started Volumio Backend Module. Feb 21 15:52:13 volumiorp5 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Feb 21 15:52:13 volumiorp5 systemd[1]: Started Volumio Cpu Tweaker. Feb 21 15:52:13 volumiorp5 systemd[1]: Reached target Multi-User System. Feb 21 15:52:13 volumiorp5 systemd[1]: Reached target Graphical Interface. Feb 21 15:52:13 volumiorp5 systemd[1]: Starting Update UTMP about System Runlevel Changes... Feb 21 15:52:13 volumiorp5 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Feb 21 15:52:13 volumiorp5 volumio-cpu-tweak[1335]: Setting RT Priority for mpd Feb 21 15:52:13 volumiorp5 systemd[1]: Started Update UTMP about System Runlevel Changes. Feb 21 15:52:13 volumiorp5 systemd[1]: Startup finished in 10.874s (kernel) + 18.709s (userspace) = 29.584s. Feb 21 15:52:13 volumiorp5 volumio-cpu-tweak[1335]: Setting MPD Affinity Feb 21 15:52:13 volumiorp5 volumio-cpu-tweak[1335]: pid 1019's current affinity mask: f Feb 21 15:52:13 volumiorp5 volumio-cpu-tweak[1335]: pid 1019's new affinity mask: 3 Feb 21 15:52:13 volumiorp5 volumio-cpu-tweak[1335]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Feb 21 15:52:13 volumiorp5 volumio-cpu-tweak[1335]: VOLUMIO CPU TWEAK: Setting CPU Governor: conservative Feb 21 15:52:13 volumiorp5 systemd[1]: volumio_cpu_tweak.service: Succeeded. Feb 21 15:52:13 volumiorp5 volumio[1334]: info: ------------------------------------------- Feb 21 15:52:13 volumiorp5 volumio[1334]: info: ----- Volumio3 ---- Feb 21 15:52:13 volumiorp5 volumio[1334]: info: ------------------------------------------- Feb 21 15:52:13 volumiorp5 volumio[1334]: info: ----- System startup ---- Feb 21 15:52:13 volumiorp5 volumio[1334]: info: ------------------------------------------- Feb 21 15:52:13 volumiorp5 volumio[1334]: info: MYVOLUMIO Environment detected Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Plugin folders cleanup Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Scanning into folder /volumio/app/plugins/ Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Scanning category audio_interface Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Scanning category miscellanea Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Scanning category music_service Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Scanning category plugins.json Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Scanning category system_controller Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Scanning category user_interface Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Scanning into folder /data/plugins/ Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Scanning category audio_interface Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Scanning category music_service Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Scanning category system_controller Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Scanning category system_hardware Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Scanning category user_interface Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Plugin folders cleanup completed Feb 21 15:52:13 volumiorp5 volumio[1334]: info: ------------------------------------------- Feb 21 15:52:13 volumiorp5 volumio[1334]: info: ----- Core plugins startup ---- Feb 21 15:52:13 volumiorp5 volumio[1334]: info: ------------------------------------------- Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Loading plugins from folder /volumio/app/plugins/ Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Adding plugin upnp to MyMusic Plugins Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Loading plugins from folder /data/plugins/ Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Loading plugin "system"... Feb 21 15:52:13 volumiorp5 volumio[1334]: info: Loading plugin "ampswitch"... Feb 21 15:52:13 volumiorp5 ntpd[982]: Listen normally on 4 wlan0 192.168.0.103:123 Feb 21 15:52:13 volumiorp5 ntpd[982]: new interface(s) found: waking up resolver Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Applying required configuration parameters for plugin ampswitch Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Loading plugin "appearance"... Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Loading plugin "network"... Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Refreshing Cached IP Addresses Feb 21 15:52:14 volumiorp5 sudo[1367]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 21 15:52:14 volumiorp5 sudo[1367]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:14 volumiorp5 sudo[1367]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:14 volumiorp5 sudo[1369]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 15:52:14 volumiorp5 sudo[1369]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:14 volumiorp5 sudo[1369]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Loading plugin "services"... Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Loading plugin "alsa_controller"... Feb 21 15:52:14 volumiorp5 sudo[1381]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 21 15:52:14 volumiorp5 sudo[1381]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:14 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Loading plugin "wizard"... Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Loading plugin "networkfs"... Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Starting Udev Watcher for removable devices Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Ignoring mount for partition: boot Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Ignoring mount for partition: volumio Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Ignoring mount for partition: volumio_data Feb 21 15:52:14 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Loading plugin "volumio_command_line_client"... Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Loading plugin "upnp"... Feb 21 15:52:14 volumiorp5 volumio[1334]: info: [1740149534464] Starting Upmpd Daemon Feb 21 15:52:14 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Loading plugin "my_music"... Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Loading plugin "mpd"... Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Loading plugin "upnp_browser"... Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Loading plugin "alarm-clock"... Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Loading plugin "airplay_emulation"... Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Starting Shairport Sync Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Loading plugin "last_100"... Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Loading plugin "webradio"... Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Loading plugin "i2s_dacs"... Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Loading plugin "volumiodiscovery"... Feb 21 15:52:14 volumiorp5 volumio[1334]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 21 15:52:14 volumiorp5 volumio[1334]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 15:52:14 volumiorp5 volumio[1334]: *** WARNING *** For more information see Feb 21 15:52:14 volumiorp5 volumio[1334]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 21 15:52:14 volumiorp5 volumio[1334]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 15:52:14 volumiorp5 volumio[1334]: *** WARNING *** For more information see Feb 21 15:52:14 volumiorp5 node[1334]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 21 15:52:14 volumiorp5 node[1334]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 15:52:14 volumiorp5 node[1334]: *** WARNING *** For more information see Feb 21 15:52:14 volumiorp5 node[1334]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 21 15:52:14 volumiorp5 node[1334]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 15:52:14 volumiorp5 node[1334]: *** WARNING *** For more information see Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Discovery: Started advertising with name: VolumioRp5 Feb 21 15:52:14 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 21 15:52:14 volumiorp5 volumio[1334]: info: Loading plugin "spop"... Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Loading plugin "autostart"... Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Applying required configuration parameters for plugin autostart Feb 21 15:52:15 volumiorp5 volumio[1334]: info: AutoStart - onVolumioStart - read config.json Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Loading plugin "outputs"... Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Loading plugin "albumart"... Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Plugin example_plugin is not enabled Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Loading plugin "inputs"... Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Loading plugin "updater_comm"... Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Plugin mpdemulation is not enabled Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Loading plugin "rest_api"... Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Loading plugin "websocket"... Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Starting Socket.io Server version 2.3.0 Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Loading plugin "fusiondsp"... Feb 21 15:52:15 volumiorp5 volumio[1334]: Forking 3 albumart workers Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Applying required configuration parameters for plugin fusiondsp Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Loading plugin "mpdoutput"... Feb 21 15:52:15 volumiorp5 volumio[1334]: Starting albumart workers Feb 21 15:52:15 volumiorp5 volumio[1334]: Starting albumart workers Feb 21 15:52:15 volumiorp5 volumio[1334]: Starting albumart workers Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Loading plugin "audiophonicsonoff"... Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Applying required configuration parameters for plugin audiophonicsonoff Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Audiophonics on/off initiated Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Loading plugin "ir_controller"... Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Applying required configuration parameters for plugin ir_controller Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Loading plugin "mpd_oled"... Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Applying required configuration parameters for plugin mpd_oled Feb 21 15:52:15 volumiorp5 volumio[1334]: info: [MPD_OLED Plugin] Reading configuration file at: /data/configuration/system_hardware/mpd_oled/config.json Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Loading plugin "Systeminfo"... Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Plugin touch_display is not enabled Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Loading i18n strings for locale sk Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored. Feb 21 15:52:15 volumiorp5 volumio[1334]: error: ir_controller: Fetching language file: Error: i18n file complementing the system language not found. Feb 21 15:52:15 volumiorp5 volumio[1334]: Updating browse sources language Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::initPlayerControls Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 15:52:15 volumiorp5 volumio[1334]: Express server listening on port 3000 Feb 21 15:52:15 volumiorp5 volumio[1334]: [Metrics] WebUI: 2s 466.23ms Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreStateMachine::resetVolumioState Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreStateMachine::getcurrentVolume Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioRetrievevolume Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Cannot read play queue from file Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Volumio Network Manager: Network status updated: 3 Feb 21 15:52:15 volumiorp5 volumio[1334]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:15 volumiorp5 volumio[1334]: info: VolumeController:: Volume=100 Mute =false Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreStateMachine::pushState Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushState Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreStateMachine::updateTrackBlock Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrackBlock Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioRetrievevolume Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreStateMachine::setRepeat null single undefined Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreStateMachine::pushState Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushState Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreStateMachine::setRandom null Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreStateMachine::pushState Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushState Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Setting Device type: Raspberry PI Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Completed loading Core Plugins Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Preparing to generate the ALSA configuration file Feb 21 15:52:15 volumiorp5 volumio[1334]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Feb 21 15:52:15 volumiorp5 volumio[1334]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf Feb 21 15:52:15 volumiorp5 volumio[1334]: info: Reading ALSA contributions from plugins. Feb 21 15:52:16 volumiorp5 volumio[1334]: info: VolumeController:: Volume=100 Mute =false Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreStateMachine::pushState Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushState Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Asound.conf file written Feb 21 15:52:16 volumiorp5 sudo[1465]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Feb 21 15:52:16 volumiorp5 sudo[1465]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 sudo[1465]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Output device has changed, restarting MPD Feb 21 15:52:16 volumiorp5 sudo[1470]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 21 15:52:16 volumiorp5 sudo[1470]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Output device has changed, restarting Shairport Sync Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:16 volumiorp5 sudo[1470]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 sudo[1473]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 21 15:52:16 volumiorp5 sudo[1473]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 systemd[1]: Stopping Music Player Daemon... Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 15:52:16 volumiorp5 volumio[1334]: info: ___________ START PLUGINS ___________ Feb 21 15:52:16 volumiorp5 volumio[1334]: info: ControllerMpd::onStart: Initializing MPD Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Creating MPD Configuration file Feb 21 15:52:16 volumiorp5 sudo[1491]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 21 15:52:16 volumiorp5 systemd[1]: mpd.service: Succeeded. Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 15:52:16 volumiorp5 volumio[1334]: info: [1740149536109] CoreMusicLibrary::Adding element Mediálne servery Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:16 volumiorp5 sudo[1491]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 systemd[1]: Stopped Music Player Daemon. Feb 21 15:52:16 volumiorp5 sudo[1491]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 systemd[1]: Starting Music Player Daemon... Feb 21 15:52:16 volumiorp5 sudo[1495]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 21 15:52:16 volumiorp5 sudo[1495]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Feb 21 15:52:16 volumiorp5 systemd[1]: mpd.service: Succeeded. Feb 21 15:52:16 volumiorp5 systemd[1]: Stopped Music Player Daemon. Feb 21 15:52:16 volumiorp5 systemd[1]: Starting Music Player Daemon... Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 15:52:16 volumiorp5 volumio[1334]: info: [1740149536144] CoreMusicLibrary::Adding element Last_100 Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 15:52:16 volumiorp5 volumio[1334]: info: [1740149536145] CoreMusicLibrary::Adding element Webradio Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Initializing BBC Radios Feb 21 15:52:16 volumiorp5 sudo[1500]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 21 15:52:16 volumiorp5 sudo[1500]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 sudo[1500]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Creating Spotify config file Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: AutoStart - onStart Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Loading i18n strings for locale sk Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored. Feb 21 15:52:16 volumiorp5 volumio[1334]: error: ir_controller: Fetching language file: Error: i18n file complementing the system language not found. Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: FusionDsp - mixtype--------------------- Hardware Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Configuring GPIO pins Feb 21 15:52:16 volumiorp5 volumio[1334]: error: Plugin audiophonicsonoff failed to start! Error: EBUSY: resource busy or locked, write Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Loading i18n strings for locale sk Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored. Feb 21 15:52:16 volumiorp5 volumio[1334]: error: ir_controller: Fetching language file: Error: i18n file complementing the system language not found. Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 21 15:52:16 volumiorp5 volumio[1334]: info: [MPD_OLED Plugin] Not starting mpd_oled service because oled type is not configured yet Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Volumio Calling Home Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Preparing to generate the ALSA configuration file Feb 21 15:52:16 volumiorp5 sudo[1529]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R a+rwX /etc/lirc/irexec.lircrc /etc/lirc/lirc_options.conf /etc/lirc/lircd.conf /etc/lirc/lircd.conf.d /etc/lirc/lircmd.conf /etc/lirc/lircrc Feb 21 15:52:16 volumiorp5 sudo[1529]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 sudo[1529]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Discovery: adding ea32ead4-0d28-406a-ac55-957107ecfeeb Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Discovery: Found device VolumioRp5 Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Discovery: this is already registered, ea32ead4-0d28-406a-ac55-957107ecfeeb Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Discovery: Found device VolumioRp5 Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:16 volumiorp5 volumio[1334]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Feb 21 15:52:16 volumiorp5 volumio[1334]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Reading ALSA contributions from plugins. Feb 21 15:52:16 volumiorp5 volumio[1334]: info: ir_controller: File permissions successfully set on /etc/lirc/*. Feb 21 15:52:16 volumiorp5 volumio[1334]: info: MPD Permissions set Feb 21 15:52:16 volumiorp5 volumio[1334]: info: MPD Permissions set Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Spotify config file written Feb 21 15:52:16 volumiorp5 volumio[1334]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 sudo[1532]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 sudo[1532]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: No need to fix Spotify hosts Feb 21 15:52:16 volumiorp5 volumio[1334]: info: [ASDebug] CurState: stop PrevState: na Feb 21 15:52:16 volumiorp5 volumio[1334]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Feb 21 15:52:16 volumiorp5 volumio[1334]: info: [ASDebug] CurState: stop PrevState: na Feb 21 15:52:16 volumiorp5 volumio[1334]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Volumio called home Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Starting Shairport Sync Feb 21 15:52:16 volumiorp5 systemd[1]: Started go-librespot Daemon. Feb 21 15:52:16 volumiorp5 go-librespot[1538]: go-librespot daemon starting... Feb 21 15:52:16 volumiorp5 sudo[1532]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Starting Shairport Sync Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Starting Shairport Sync Feb 21 15:52:16 volumiorp5 sudo[1545]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 15:52:16 volumiorp5 sudo[1545]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 volumio[1334]: info: [ASDebug] CurState: stop PrevState: na Feb 21 15:52:16 volumiorp5 volumio[1334]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Feb 21 15:52:16 volumiorp5 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 21 15:52:16 volumiorp5 sudo[1549]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 15:52:16 volumiorp5 sudo[1549]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:16 volumiorp5 sudo[1550]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 15:52:16 volumiorp5 sudo[1550]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 systemd[1]: shairport-sync.service: Succeeded. Feb 21 15:52:16 volumiorp5 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 21 15:52:16 volumiorp5 volumio[1334]: info: ir_controller: LIRC correctly updated. Feb 21 15:52:16 volumiorp5 volumio[1334]: info: ir_controller: HAT did not load /proc/device-tree/ir_receiver! Feb 21 15:52:16 volumiorp5 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 21 15:52:16 volumiorp5 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 21 15:52:16 volumiorp5 systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Feb 21 15:52:16 volumiorp5 sudo[1545]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 systemd[1]: shairport-sync.service: Succeeded. Feb 21 15:52:16 volumiorp5 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 21 15:52:16 volumiorp5 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 21 15:52:16 volumiorp5 mpd[1506]: Feb 21 15:52 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 21 15:52:16 volumiorp5 sudo[1550]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 sudo[1549]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 go-librespot[1538]: time="2025-02-21T15:52:16+01:00" level=info msg="running go-librespot 0.2.0" Feb 21 15:52:16 volumiorp5 go-librespot[1538]: time="2025-02-21T15:52:16+01:00" level=debug msg="app state loaded" Feb 21 15:52:16 volumiorp5 go-librespot[1538]: time="2025-02-21T15:52:16+01:00" level=debug msg="stored credentials not found" Feb 21 15:52:16 volumiorp5 go-librespot[1538]: time="2025-02-21T15:52:16+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 15:52:16 volumiorp5 systemd[1]: Started Music Player Daemon. Feb 21 15:52:16 volumiorp5 sudo[1495]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Asound.conf file unchanged, so no further update is needed Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Output device has changed, restarting MPD Feb 21 15:52:16 volumiorp5 sudo[1473]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 sudo[1567]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 21 15:52:16 volumiorp5 sudo[1567]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Output device has changed, restarting Shairport Sync Feb 21 15:52:16 volumiorp5 sudo[1567]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:16 volumiorp5 sudo[1570]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 21 15:52:16 volumiorp5 sudo[1570]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 systemd[1]: Stopping Music Player Daemon... Feb 21 15:52:16 volumiorp5 systemd[1]: mpd.service: Succeeded. Feb 21 15:52:16 volumiorp5 systemd[1]: Stopped Music Player Daemon. Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Preparing to generate the ALSA configuration file Feb 21 15:52:16 volumiorp5 volumio[1334]: info: ir_controller: Raspberry Pi revision code: d04171 Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Shairport-Sync Started Feb 21 15:52:16 volumiorp5 volumio[1334]: Error adding Membership: Error: addMembership EINVAL Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Shairport-Sync Started Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Shairport-Sync Started Feb 21 15:52:16 volumiorp5 volumio[1334]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Feb 21 15:52:16 volumiorp5 volumio[1334]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Reading ALSA contributions from plugins. Feb 21 15:52:16 volumiorp5 systemd[1]: Starting Music Player Daemon... Feb 21 15:52:16 volumiorp5 volumio[1334]: info: MPD Permissions set Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Completed starting Core Plugins Feb 21 15:52:16 volumiorp5 volumio[1334]: info: ------------------------------------------- Feb 21 15:52:16 volumiorp5 volumio[1334]: info: ----- MyVolumio plugins startup ---- Feb 21 15:52:16 volumiorp5 volumio[1334]: info: ------------------------------------------- Feb 21 15:52:16 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 21 15:52:16 volumiorp5 sudo[1575]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 21 15:52:16 volumiorp5 sudo[1575]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 sudo[1575]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 volumio[1334]: error: Cannot initialize MPD Connection: MPD is not running Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 sudo[1582]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r -1 Feb 21 15:52:16 volumiorp5 sudo[1582]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 sudo[1582]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Starting Shairport Sync Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPause Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreStateMachine::pause Feb 21 15:52:16 volumiorp5 volumio[1334]: info: mpdhttpout --- Volumio set on pause Feb 21 15:52:16 volumiorp5 volumio[1334]: info: mpdhttpout ---Configuration successfully added to mpd.conf. Feb 21 15:52:16 volumiorp5 sudo[1592]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 15:52:16 volumiorp5 sudo[1592]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 21 15:52:16 volumiorp5 systemd[1]: shairport-sync.service: Succeeded. Feb 21 15:52:16 volumiorp5 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Asound.conf file unchanged, so no further update is needed Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Output device has changed, restarting MPD Feb 21 15:52:16 volumiorp5 sudo[1598]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay gpio-ir gpio_pin=25 gpio_pull=up Feb 21 15:52:16 volumiorp5 sudo[1598]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 21 15:52:16 volumiorp5 sudo[1601]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 21 15:52:16 volumiorp5 sudo[1601]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 sudo[1592]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 sudo[1601]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Output device has changed, restarting Shairport Sync Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:16 volumiorp5 sudo[1607]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 21 15:52:16 volumiorp5 sudo[1607]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 kernel: Registered IR keymap rc-rc6-mce Feb 21 15:52:16 volumiorp5 kernel: IR RC6 protocol handler initialized Feb 21 15:52:16 volumiorp5 sudo[1598]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Feb 21 15:52:16 volumiorp5 systemd[1]: mpd.service: Succeeded. Feb 21 15:52:16 volumiorp5 systemd[1]: Stopped Music Player Daemon. Feb 21 15:52:16 volumiorp5 systemd[1]: Starting Music Player Daemon... Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 15:52:16 volumiorp5 volumio[1334]: info: MPD Permissions set Feb 21 15:52:16 volumiorp5 volumio[1334]: info: ir_controller: Overlay gpio-ir gpio_pin=25 gpio_pull=up loaded. Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Shairport-Sync Started Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 kernel: rc rc2: gpio_ir_recv as /devices/platform/ir-receiver@19/rc/rc2 Feb 21 15:52:16 volumiorp5 kernel: rc rc2: lirc_dev: driver gpio_ir_recv registered at minor = 0, raw IR receiver, no transmitter Feb 21 15:52:16 volumiorp5 kernel: input: gpio_ir_recv as /devices/platform/ir-receiver@19/rc/rc2/input9 Feb 21 15:52:16 volumiorp5 sudo[1621]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart lircd.service Feb 21 15:52:16 volumiorp5 sudo[1621]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 sudo[1619]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 21 15:52:16 volumiorp5 sudo[1619]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:16 volumiorp5 systemd[1]: Starting lircd(8) initialization helper tool... Feb 21 15:52:16 volumiorp5 sudo[1619]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Starting Shairport Sync Feb 21 15:52:16 volumiorp5 volumio[1334]: info: mpdhttpout ---Configuration successfully replaced in mpd.conf. Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPause Feb 21 15:52:16 volumiorp5 volumio[1334]: info: CoreStateMachine::pause Feb 21 15:52:16 volumiorp5 volumio[1334]: info: mpdhttpout --- Volumio set on pause Feb 21 15:52:16 volumiorp5 sudo[1634]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 15:52:16 volumiorp5 sudo[1634]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 21 15:52:16 volumiorp5 systemd[1]: shairport-sync.service: Succeeded. Feb 21 15:52:16 volumiorp5 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 21 15:52:16 volumiorp5 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 21 15:52:16 volumiorp5 sudo[1634]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 volumio[1334]: info: Shairport-Sync Started Feb 21 15:52:16 volumiorp5 systemd-udevd[1623]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Feb 21 15:52:16 volumiorp5 systemd-logind[774]: Watching system buttons on /dev/input/event9 (gpio_ir_recv) Feb 21 15:52:16 volumiorp5 lircd-setup[1631]: /usr/sbin/lircd-setup:37: DeprecationWarning: The SafeConfigParser class has been renamed to ConfigParser in Python 3.2. This alias will be removed in future versions. Use ConfigParser directly instead. Feb 21 15:52:16 volumiorp5 lircd-setup[1631]: parser = configparser.SafeConfigParser() Feb 21 15:52:16 volumiorp5 systemd[1]: lircd-setup.service: Succeeded. Feb 21 15:52:16 volumiorp5 systemd[1]: Started lircd(8) initialization helper tool. Feb 21 15:52:16 volumiorp5 systemd[1]: Starting Flexible IR remote input/output application support... Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Info: lircd: Opening log, level: Info Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Version: lircd 0.10.1 Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: System info: Linux volumiorp5 6.6.62-v8+ #1816 SMP PREEMPT Mon Nov 18 15:35:52 GMT 2024 aarch64 GNU/Linux Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Info: Initial device: /dev/lirc0 Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: 'lirc' written to protocols file /sys/class/rc/rc2/protocols Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Info: Initial device: /dev/lirc0 Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Info: [lirc] protocol is enabled Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Options: driver: default Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Options: output: /var/run/lirc/lircd Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Options: nodaemon: 1 Feb 21 15:52:16 volumiorp5 lircd[1643]: lircd-0.10.1[1643]: Info: lircd: Opening log, level: Info Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Options: plugindir: /usr/lib/arm-linux-gnueabihf/lirc/plugins Feb 21 15:52:16 volumiorp5 lircd[1643]: lircd-0.10.1[1643]: Notice: Using systemd fd Feb 21 15:52:16 volumiorp5 lircd[1643]: lircd-0.10.1[1643]: Warning: Running as root Feb 21 15:52:16 volumiorp5 lircd[1643]: lircd-0.10.1[1643]: Info: Using remote: lircd.conf. Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Options: logfile: syslog Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Options: immediate-init: 0 Feb 21 15:52:16 volumiorp5 lircd[1643]: lircd-0.10.1[1643]: Notice: lircd(default) ready, using /var/run/lirc/lircd Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Options: permission: 666 Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Options: driver-options: Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Options: pidfile: /var/run/lirc/lircd.pid Feb 21 15:52:16 volumiorp5 systemd[1]: Started Flexible IR remote input/output application support. Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Options: listen: 0 Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Options: connect: (null) Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Options: userelease: 0 Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Options: effective_user: (null) Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Options: release_suffix: _EVUP Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Options: allow_simulate: 0 Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Options: repeat_max: 600 Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Options: configfile: /etc/lirc/lircd.conf Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Options: dynamic_codes: (null) Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Current driver: default Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Driver API version: 3 Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Driver version: 0.10.0 Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Driver info: See file:///usr/share/doc/lirc/plugindocs/default.html Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Info: lircd: Opening log, level: Info Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: Using systemd fd Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Warning: Running as root Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Info: Using remote: lircd.conf. Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: lircd(default) ready, using /var/run/lirc/lircd Feb 21 15:52:16 volumiorp5 sudo[1621]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 volumio[1334]: info: ir_controller: systemctl restart lircd.service succeeded. Feb 21 15:52:16 volumiorp5 sudo[1647]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart irexec.service Feb 21 15:52:16 volumiorp5 sudo[1647]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:16 volumiorp5 systemd[1]: Started Handle events from IR remotes decoded by lircd(8). Feb 21 15:52:16 volumiorp5 sudo[1647]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 lircd[1643]: lircd-0.10.1[1643]: Notice: accepted new client on /var/run/lirc/lircd Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Notice: accepted new client on /var/run/lirc/lircd Feb 21 15:52:16 volumiorp5 lircd[1643]: lircd-0.10.1[1643]: Info: [lirc] protocol is enabled Feb 21 15:52:16 volumiorp5 lircd-0.10.1[1643]: Info: [lirc] protocol is enabled Feb 21 15:52:16 volumiorp5 volumio[1334]: info: ir_controller: systemctl restart irexec.service succeeded. Feb 21 15:52:16 volumiorp5 mpd[1632]: Feb 21 15:52 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 21 15:52:16 volumiorp5 systemd[1]: Started Music Player Daemon. Feb 21 15:52:16 volumiorp5 sudo[1607]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 sudo[1570]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:16 volumiorp5 volumio[1334]: error: MPD error: The expression evaluated to a falsy value: Feb 21 15:52:16 volumiorp5 volumio[1334]: assert.ok(self.idling) Feb 21 15:52:16 volumiorp5 volumio[1334]: error: The expression evaluated to a falsy value: Feb 21 15:52:16 volumiorp5 volumio[1334]: assert.ok(self.idling) Feb 21 15:52:16 volumiorp5 volumio[1334]: error: updateQueue error: null Feb 21 15:52:16 volumiorp5 volumio[1334]: error: MPD error: The expression evaluated to a falsy value: Feb 21 15:52:16 volumiorp5 volumio[1334]: assert.ok(self.idling) Feb 21 15:52:16 volumiorp5 volumio[1334]: error: The expression evaluated to a falsy value: Feb 21 15:52:16 volumiorp5 volumio[1334]: assert.ok(self.idling) Feb 21 15:52:16 volumiorp5 volumio[1334]: error: updateQueue error: null Feb 21 15:52:17 volumiorp5 volumio[1334]: info: [ASDebug] Togle GPIO: OFF Feb 21 15:52:17 volumiorp5 sudo[1656]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart lircd.service Feb 21 15:52:17 volumiorp5 sudo[1656]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:17 volumiorp5 lircd[1643]: lircd-0.10.1[1643]: Notice: caught signal Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1643]: Notice: caught signal Feb 21 15:52:17 volumiorp5 systemd[1]: Stopping Flexible IR remote input/output application support... Feb 21 15:52:17 volumiorp5 systemd[1]: lircd.service: Main process exited, code=killed, status=15/TERM Feb 21 15:52:17 volumiorp5 systemd[1]: lircd.service: Succeeded. Feb 21 15:52:17 volumiorp5 systemd[1]: Stopped Flexible IR remote input/output application support. Feb 21 15:52:17 volumiorp5 systemd[1]: irexec.service: Succeeded. Feb 21 15:52:17 volumiorp5 systemd[1]: Starting lircd(8) initialization helper tool... Feb 21 15:52:17 volumiorp5 lircd-setup[1658]: /usr/sbin/lircd-setup:37: DeprecationWarning: The SafeConfigParser class has been renamed to ConfigParser in Python 3.2. This alias will be removed in future versions. Use ConfigParser directly instead. Feb 21 15:52:17 volumiorp5 lircd-setup[1658]: parser = configparser.SafeConfigParser() Feb 21 15:52:17 volumiorp5 systemd[1]: lircd-setup.service: Succeeded. Feb 21 15:52:17 volumiorp5 systemd[1]: Started lircd(8) initialization helper tool. Feb 21 15:52:17 volumiorp5 systemd[1]: Starting Flexible IR remote input/output application support... Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Info: lircd: Opening log, level: Info Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Version: lircd 0.10.1 Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: System info: Linux volumiorp5 6.6.62-v8+ #1816 SMP PREEMPT Mon Nov 18 15:35:52 GMT 2024 aarch64 GNU/Linux Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Info: Initial device: /dev/lirc0 Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Info: [lirc] protocol is enabled Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Info: Initial device: /dev/lirc0 Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Info: [lirc] protocol is enabled Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Options: driver: default Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Options: output: /var/run/lirc/lircd Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Options: nodaemon: 1 Feb 21 15:52:17 volumiorp5 lircd[1659]: lircd-0.10.1[1659]: Info: lircd: Opening log, level: Info Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Options: plugindir: /usr/lib/arm-linux-gnueabihf/lirc/plugins Feb 21 15:52:17 volumiorp5 lircd[1659]: lircd-0.10.1[1659]: Notice: Using systemd fd Feb 21 15:52:17 volumiorp5 lircd[1659]: lircd-0.10.1[1659]: Warning: Running as root Feb 21 15:52:17 volumiorp5 lircd[1659]: lircd-0.10.1[1659]: Info: Using remote: lircd.conf. Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Options: logfile: syslog Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Options: immediate-init: 0 Feb 21 15:52:17 volumiorp5 lircd[1659]: lircd-0.10.1[1659]: Notice: lircd(default) ready, using /var/run/lirc/lircd Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Options: permission: 666 Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Options: driver-options: Feb 21 15:52:17 volumiorp5 systemd[1]: Started Flexible IR remote input/output application support. Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Options: pidfile: /var/run/lirc/lircd.pid Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Options: listen: 0 Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Options: connect: (null) Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Options: userelease: 0 Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Options: effective_user: (null) Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Options: release_suffix: _EVUP Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Options: allow_simulate: 0 Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Options: repeat_max: 600 Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Options: configfile: /etc/lirc/lircd.conf Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Options: dynamic_codes: (null) Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Current driver: default Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Driver API version: 3 Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Driver version: 0.10.0 Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Driver info: See file:///usr/share/doc/lirc/plugindocs/default.html Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Info: lircd: Opening log, level: Info Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: Using systemd fd Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Warning: Running as root Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Info: Using remote: lircd.conf. Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: lircd(default) ready, using /var/run/lirc/lircd Feb 21 15:52:17 volumiorp5 sudo[1656]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:17 volumiorp5 volumio[1334]: info: ir_controller: systemctl restart lircd.service succeeded. Feb 21 15:52:17 volumiorp5 sudo[1663]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart irexec.service Feb 21 15:52:17 volumiorp5 sudo[1663]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:17 volumiorp5 systemd[1]: Started Handle events from IR remotes decoded by lircd(8). Feb 21 15:52:17 volumiorp5 sudo[1663]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:17 volumiorp5 volumio[1334]: info: ir_controller: systemctl restart irexec.service succeeded. Feb 21 15:52:17 volumiorp5 lircd[1659]: lircd-0.10.1[1659]: Notice: accepted new client on /var/run/lirc/lircd Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Notice: accepted new client on /var/run/lirc/lircd Feb 21 15:52:17 volumiorp5 lircd[1659]: lircd-0.10.1[1659]: Info: [lirc] protocol is enabled Feb 21 15:52:17 volumiorp5 lircd-0.10.1[1659]: Info: [lirc] protocol is enabled Feb 21 15:52:18 volumiorp5 sudo[1381]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:18 volumiorp5 volumio[1334]: info: camilladsp spawned new process with pid 1672, instance 1, run: true Feb 21 15:52:18 volumiorp5 volumio[1334]: info: camilladsp service started and running in background, instance 1 Feb 21 15:52:18 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:18 volumiorp5 volumio[1334]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 384000 <-AAAAAAAAAAAAA Feb 21 15:52:18 volumiorp5 kernel: pcm512x 1-004c: No SCLK, using BCLK: -2 Feb 21 15:52:18 volumiorp5 kernel: pcm512x 1-004c: No SCLK, using BCLK: -2 Feb 21 15:52:18 volumiorp5 volumio[1334]: info: FusionDsp loaded Feb 21 15:52:18 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:52:18 volumiorp5 sudo[1682]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Feb 21 15:52:18 volumiorp5 sudo[1682]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:18 volumiorp5 volumio[1334]: info: FusionDsp - Reporting Fusion DSP Enabled Feb 21 15:52:18 volumiorp5 volumio[1334]: info: Adding Signal Path Element [object Object] Feb 21 15:52:18 volumiorp5 volumio[1334]: info: Adding fusiondspeq DSP Signal Path Element Feb 21 15:52:18 volumiorp5 volumio[1334]: info: FusionDsp - ---- installed callbackRead Feb 21 15:52:18 volumiorp5 volumio[1334]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 21 15:52:18 volumiorp5 volumio[1334]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 21 15:52:18 volumiorp5 volumio[1334]: info: FusionDsp - {"Reload":{"result":"Ok"}} Feb 21 15:52:18 volumiorp5 systemd[1]: Started FusionDsp Daemon. Feb 21 15:52:18 volumiorp5 sudo[1682]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:18 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Feb 21 15:52:18 volumiorp5 sudo[1687]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 21 15:52:18 volumiorp5 sudo[1687]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:18 volumiorp5 systemd[1]: Stopping Music Player Daemon... Feb 21 15:52:18 volumiorp5 systemd[1]: mpd.service: Succeeded. Feb 21 15:52:18 volumiorp5 systemd[1]: Stopped Music Player Daemon. Feb 21 15:52:18 volumiorp5 systemd[1]: Starting Music Player Daemon... Feb 21 15:52:18 volumiorp5 sudo[1689]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 21 15:52:18 volumiorp5 sudo[1689]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:18 volumiorp5 sudo[1689]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:18 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Feb 21 15:52:18 volumiorp5 sudo[1693]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 21 15:52:18 volumiorp5 sudo[1693]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:18 volumiorp5 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Feb 21 15:52:18 volumiorp5 systemd[1]: mpd.service: Succeeded. Feb 21 15:52:18 volumiorp5 systemd[1]: Stopped Music Player Daemon. Feb 21 15:52:18 volumiorp5 systemd[1]: Starting Music Player Daemon... Feb 21 15:52:18 volumiorp5 sudo[1695]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 21 15:52:18 volumiorp5 sudo[1695]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:18 volumiorp5 sudo[1695]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:18 volumiorp5 volumio-remote-updater[770]: [2025-02-21 15:52:18] [connect] Successful connection Feb 21 15:52:18 volumiorp5 volumio-remote-updater[770]: [2025-02-21 15:52:18] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1740149538 101 Feb 21 15:52:18 volumiorp5 volumio[1334]: 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 Feb 21 15:52:19 volumiorp5 mpd[1697]: Feb 21 15:52 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 21 15:52:19 volumiorp5 systemd[1]: Started Music Player Daemon. Feb 21 15:52:19 volumiorp5 sudo[1687]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:19 volumiorp5 sudo[1693]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:19 volumiorp5 volumio[1334]: error: MPD error: The expression evaluated to a falsy value: Feb 21 15:52:19 volumiorp5 volumio[1334]: assert.ok(self.idling) Feb 21 15:52:19 volumiorp5 volumio[1334]: error: The expression evaluated to a falsy value: Feb 21 15:52:19 volumiorp5 volumio[1334]: assert.ok(self.idling) Feb 21 15:52:19 volumiorp5 volumio[1334]: error: updateQueue error: null Feb 21 15:52:19 volumiorp5 volumio[1334]: info: go-librespot daemon successfully initialized Feb 21 15:52:21 volumiorp5 go-librespot[1538]: time="2025-02-21T15:52:21+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 21 15:52:21 volumiorp5 go-librespot[1538]: time="2025-02-21T15:52:21+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 21 15:52:21 volumiorp5 go-librespot[1538]: time="2025-02-21T15:52:21+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 21 15:52:21 volumiorp5 go-librespot[1538]: time="2025-02-21T15:52:21+01:00" level=info msg="zeroconf server listening on port 45795" Feb 21 15:52:21 volumiorp5 volumio[1334]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 21 15:52:22 volumiorp5 volumio[1334]: info: Initializing connection to go-librespot Websocket Feb 21 15:52:22 volumiorp5 go-librespot[1538]: time="2025-02-21T15:52:22+01:00" level=debug msg="new websocket client" Feb 21 15:52:22 volumiorp5 volumio[1334]: info: Connection to go-librespot Websocket established Feb 21 15:52:24 volumiorp5 sudo[1716]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 21 15:52:24 volumiorp5 sudo[1716]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:24 volumiorp5 sudo[1716]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:24 volumiorp5 sudo[1718]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 15:52:24 volumiorp5 sudo[1718]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:24 volumiorp5 sudo[1718]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:24 volumiorp5 sudo[1722]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 21 15:52:24 volumiorp5 sudo[1722]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:24 volumiorp5 systemd[1]: Started UPnP Renderer front-end to MPD. Feb 21 15:52:24 volumiorp5 sudo[1722]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:24 volumiorp5 volumio[1334]: info: Upmpdcli Daemon Started Feb 21 15:52:24 volumiorp5 volumio[1724]: Generating RSA private key, 4096 bit long modulus (2 primes) Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 21 15:52:24 volumiorp5 volumio[1334]: info: Adding plugin bluetooth to MyMusic Plugins Feb 21 15:52:24 volumiorp5 volumio[1334]: info: Adding plugin multiroom to MyMusic Plugins Feb 21 15:52:24 volumiorp5 volumio[1334]: info: Adding plugin metavolumio to MyMusic Plugins Feb 21 15:52:24 volumiorp5 volumio[1334]: info: Adding plugin cd_controller to MyMusic Plugins Feb 21 15:52:24 volumiorp5 volumio[1334]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 21 15:52:24 volumiorp5 volumio[1334]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 21 15:52:24 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 21 15:52:25 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 21 15:52:25 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 21 15:52:25 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:25 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:25 volumiorp5 volumio[1334]: info: Starting MyVolumio Remote Streaming Endpoints Feb 21 15:52:25 volumiorp5 volumio[1334]: info: MyVolumio login type: Token Feb 21 15:52:25 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 21 15:52:25 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 21 15:52:25 volumiorp5 systemd[1]: systemd-fsckd.service: Succeeded. Feb 21 15:52:25 volumiorp5 volumio[1334]: info: Starting Streaming Service Transparent Proxy Feb 21 15:52:25 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 21 15:52:25 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 21 15:52:25 volumiorp5 volumio[1334]: info: Streaming services startup Feb 21 15:52:25 volumiorp5 volumio[1334]: info: Starting Streaming Daemon Feb 21 15:52:25 volumiorp5 sudo[1747]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 21 15:52:25 volumiorp5 sudo[1747]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:25 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 21 15:52:25 volumiorp5 sudo[1747]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:25 volumiorp5 volumio[1334]: info: Getting Spotify volume Feb 21 15:52:25 volumiorp5 volumio[1334]: error: Cannot start Volumio Streaming Daemon Feb 21 15:52:25 volumiorp5 volumio[1334]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 21 15:52:25 volumiorp5 volumio[1334]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 21 15:52:25 volumiorp5 volumio[1334]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Feb 21 15:52:25 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:25 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:25 volumiorp5 volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 21 15:52:25 volumiorp5 volumio[1334]: SPOTIFY: SPOTIFY VOLUME undefined Feb 21 15:52:25 volumiorp5 volumio[1334]: SPOTIFY: VOLUMIO VOLUME 100 Feb 21 15:52:25 volumiorp5 volumio[1334]: info: Aligning Spotify Volume to Volumio Volume Feb 21 15:52:25 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:25 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:25 volumiorp5 volumio[1334]: info: Setting Spotify Volume from Volumio: 100 Feb 21 15:52:25 volumiorp5 volumio[1334]: STREAMING PROXY: Starting server on port 3245 Feb 21 15:52:25 volumiorp5 volumio[1334]: Node JS runtime: 14 Feb 21 15:52:25 volumiorp5 volumio[1334]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 21 15:52:26 volumiorp5 volumio[1334]: info: MyVolumio token set successfully Feb 21 15:52:26 volumiorp5 volumio[1334]: info: MYVOLUMIO: Adding device Feb 21 15:52:26 volumiorp5 volumio[1334]: info: MYVOLUMIO: Evaluating Server Feb 21 15:52:26 volumiorp5 volumio[1334]: info: MyVolumio Plan changed: premium Feb 21 15:52:26 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Feb 21 15:52:26 volumiorp5 systemd[1]: systemd-hostnamed.service: Succeeded. Feb 21 15:52:26 volumiorp5 volumio[1334]: info: Removing browser output: myVolumio user plan is not superstar Feb 21 15:52:26 volumiorp5 volumio[1334]: info: Removing audio output: Feb 21 15:52:26 volumiorp5 volumio[1334]: info: MYVOLUMIO: Adding device Feb 21 15:52:26 volumiorp5 volumio[1334]: info: MYVOLUMIO: Evaluating Server Feb 21 15:52:26 volumiorp5 volumio[1334]: info: Remote config written successfully Feb 21 15:52:26 volumiorp5 volumio[1334]: info: Starting Tunnel 1 Feb 21 15:52:26 volumiorp5 volumio[1334]: info: Starting Tunnel Connection Checker Feb 21 15:52:26 volumiorp5 volumio[1334]: info: Completed starting MyVolumio Plugin Feb 21 15:52:27 volumiorp5 volumio[1334]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Sending Spotify command with payload to local API: /player/volume Feb 21 15:52:27 volumiorp5 volumio[1334]: info: MYVolumio Device enabled Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Feb 21 15:52:27 volumiorp5 volumio[1334]: info: MyVolumio status changed Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Streaming services startup Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Starting Streaming Daemon Feb 21 15:52:27 volumiorp5 sudo[1793]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 21 15:52:27 volumiorp5 sudo[1793]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:27 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Feb 21 15:52:27 volumiorp5 sudo[1793]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Feb 21 15:52:27 volumiorp5 volumio[1724]: .....................................................++++ Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [1740149547265] Starting BluetoothController Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Feb 21 15:52:27 volumiorp5 sudo[1796]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Feb 21 15:52:27 volumiorp5 sudo[1796]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:27 volumiorp5 sudo[1796]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:27 volumiorp5 volumio[1334]: info: MRS: MultiRoom plugin initialized Feb 21 15:52:27 volumiorp5 volumio[1334]: info: MRS: STOPPING SNAPCLIENT Feb 21 15:52:27 volumiorp5 volumio[1334]: info: MRS: Snap server stop Feb 21 15:52:27 volumiorp5 sudo[1812]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Feb 21 15:52:27 volumiorp5 sudo[1812]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:27 volumiorp5 volumio[1334]: info: MRS: STOPPING volumioStreaming Feb 21 15:52:27 volumiorp5 sudo[1815]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Feb 21 15:52:27 volumiorp5 sudo[1815]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:27 volumiorp5 sudo[1818]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Feb 21 15:52:27 volumiorp5 sudo[1818]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:27 volumiorp5 sudo[1815]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:27 volumiorp5 sudo[1812]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Feb 21 15:52:27 volumiorp5 sudo[1821]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Feb 21 15:52:27 volumiorp5 sudo[1818]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:27 volumiorp5 sudo[1821]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:27 volumiorp5 sudo[1821]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Preparing to generate the ALSA configuration file Feb 21 15:52:27 volumiorp5 volumio[1334]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Feb 21 15:52:27 volumiorp5 volumio[1334]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Feb 21 15:52:27 volumiorp5 volumio[1334]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Reading ALSA contributions from plugins. Feb 21 15:52:27 volumiorp5 volumio[1334]: info: MRS: Removed streaming files Feb 21 15:52:27 volumiorp5 volumio[1334]: info: MRS: volumioStreaming STOPPED Feb 21 15:52:27 volumiorp5 volumio[1334]: info: MRS: SNAPSERVER STOPPED Feb 21 15:52:27 volumiorp5 volumio[1334]: info: MRS: SNAPCLIENT STOPPED Feb 21 15:52:27 volumiorp5 volumio[1334]: error: Cannot start Volumio Streaming Daemon Feb 21 15:52:27 volumiorp5 volumio[1334]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 21 15:52:27 volumiorp5 volumio[1334]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Asound.conf file written Feb 21 15:52:27 volumiorp5 sudo[1824]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Feb 21 15:52:27 volumiorp5 sudo[1824]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:27 volumiorp5 sudo[1824]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:27 volumiorp5 volumio[1334]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Max Overclock PLL:0' : Device or resource busy Feb 21 15:52:27 volumiorp5 volumio[1334]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Max Overclock DSP:0' : Device or resource busy Feb 21 15:52:27 volumiorp5 volumio[1334]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Max Overclock DAC:0' : Device or resource busy Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Output device has changed, restarting MPD Feb 21 15:52:27 volumiorp5 sudo[1829]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 21 15:52:27 volumiorp5 sudo[1829]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:27 volumiorp5 sudo[1829]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Output device has changed, restarting Shairport Sync Feb 21 15:52:27 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:27 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:27 volumiorp5 sudo[1832]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 21 15:52:27 volumiorp5 sudo[1832]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:27 volumiorp5 systemd[1]: Stopping Music Player Daemon... Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 15:52:27 volumiorp5 volumio[1334]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Feb 21 15:52:27 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:27 volumiorp5 systemd[1]: mpd.service: Succeeded. Feb 21 15:52:27 volumiorp5 systemd[1]: Stopped Music Player Daemon. Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Feb 21 15:52:27 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Feb 21 15:52:27 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Feb 21 15:52:27 volumiorp5 volumio[1334]: info: MRS: Pushing multiroomSync output for this device Feb 21 15:52:27 volumiorp5 volumio[1334]: info: MRS: Pushing multiroomSync output Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Adding audio output: Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Adding audio output: Feb 21 15:52:27 volumiorp5 sudo[1841]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name VolumioRp5 Feb 21 15:52:27 volumiorp5 sudo[1841]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:27 volumiorp5 systemd[1]: Starting Music Player Daemon... Feb 21 15:52:27 volumiorp5 volumio[1334]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Feb 21 15:52:27 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:27 volumiorp5 sudo[1841]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Adding METAVOLUMIO REST API Endpoints Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Preparing CD Folders Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Adding CD REST API Endpoints Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Starting UDEV Watcher for CD Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Detecting CD presence with UDEV Feb 21 15:52:27 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Adding inputs REST Endpoints Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Scanning Audio Inputs Feb 21 15:52:27 volumiorp5 sudo[1838]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 21 15:52:27 volumiorp5 sudo[1838]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:27 volumiorp5 sudo[1838]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Checking against Known Cards name Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Adding Server instance for streaming Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Feb 21 15:52:27 volumiorp5 volumio[1334]: error: Hi Res Audio Failed Login: Missing Login Data Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Adding HIGHRESAUDIO REST API Endpoints Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Refreshing TIDAL token Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Feb 21 15:52:27 volumiorp5 volumio[1334]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Stopping AccessToken refresher cron for QOBUZ Feb 21 15:52:27 volumiorp5 sudo[1851]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Feb 21 15:52:27 volumiorp5 sudo[1851]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:27 volumiorp5 volumio[1334]: info: AccessToken refresher cron started for QOBUZ Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Adding QOBUZ REST API Endpoints Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Feb 21 15:52:27 volumiorp5 sudo[1851]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:27 volumiorp5 volumio[1334]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Bluetooth name changed to VolumioRp5 Feb 21 15:52:27 volumiorp5 volumio[1334]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Feb 21 15:52:27 volumiorp5 volumio[1334]: info: MPD Permissions set Feb 21 15:52:27 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:27 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:27 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:27 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:27 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:27 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:27 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:27 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:27 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:27 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:27 volumiorp5 volumio[1334]: info: Starting Shairport Sync Feb 21 15:52:28 volumiorp5 volumio[1334]: info: mpdhttpout ---Configuration successfully replaced in mpd.conf. Feb 21 15:52:28 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:28 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:28 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPause Feb 21 15:52:28 volumiorp5 volumio[1334]: info: CoreStateMachine::pause Feb 21 15:52:28 volumiorp5 volumio[1334]: info: mpdhttpout --- Volumio set on pause Feb 21 15:52:28 volumiorp5 sudo[1859]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 15:52:28 volumiorp5 sudo[1859]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:28 volumiorp5 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 21 15:52:28 volumiorp5 systemd[1]: shairport-sync.service: Succeeded. Feb 21 15:52:28 volumiorp5 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 21 15:52:28 volumiorp5 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 21 15:52:28 volumiorp5 sudo[1859]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:28 volumiorp5 volumio[1334]: info: Shairport-Sync Started Feb 21 15:52:28 volumiorp5 mpd[1849]: Feb 21 15:52 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 21 15:52:28 volumiorp5 systemd[1]: Started Music Player Daemon. Feb 21 15:52:28 volumiorp5 sudo[1832]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:28 volumiorp5 volumio[1334]: error: updateQueue error: null Feb 21 15:52:28 volumiorp5 volumio[1724]: ..............................++++ Feb 21 15:52:28 volumiorp5 volumio[1724]: e is 65537 (0x010001) Feb 21 15:52:28 volumiorp5 volumio[1724]: writing RSA key Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:52:30 volumiorp5 volumio[1334]: info: Discovery: Getting this device information Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:52:30 volumiorp5 volumio[1334]: info: Discovery: Getting this device information Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Feb 21 15:52:30 volumiorp5 sudo[1882]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 21 15:52:30 volumiorp5 sudo[1882]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:30 volumiorp5 systemd[1]: Stopping Music Player Daemon... Feb 21 15:52:30 volumiorp5 systemd[1]: mpd.service: Succeeded. Feb 21 15:52:30 volumiorp5 systemd[1]: Stopped Music Player Daemon. Feb 21 15:52:30 volumiorp5 systemd[1]: Starting Music Player Daemon... Feb 21 15:52:30 volumiorp5 sudo[1884]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 21 15:52:30 volumiorp5 sudo[1884]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:30 volumiorp5 sudo[1884]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:30 volumiorp5 mpd[1886]: Feb 21 15:52 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 21 15:52:30 volumiorp5 systemd[1]: Started Music Player Daemon. Feb 21 15:52:30 volumiorp5 sudo[1882]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:30 volumiorp5 volumio[1334]: error: updateQueue error: null Feb 21 15:52:30 volumiorp5 volumio[1334]: verbose: New Socket.io Connection to 192.168.0.103 from 192.168.0.193 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 6 Feb 21 15:52:30 volumiorp5 volumio[1334]: info: Received Get System Info Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:52:30 volumiorp5 volumio[1334]: info: Discovery: Getting this device information Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetVisibleSources Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 21 15:52:30 volumiorp5 volumio[1334]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Feb 21 15:52:30 volumiorp5 volumio[1334]: info: Received Get System Info Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:52:30 volumiorp5 volumio[1334]: info: Discovery: Getting this device information Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:30 volumiorp5 volumio[1334]: info: Listing playlists Feb 21 15:52:30 volumiorp5 sudo[1890]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Feb 21 15:52:30 volumiorp5 sudo[1890]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 21 15:52:30 volumiorp5 volumio[1334]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 21 15:52:30 volumiorp5 systemd[1]: Started Volumio Bluetooth Module. Feb 21 15:52:30 volumiorp5 sudo[1890]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:30 volumiorp5 sudo[1893]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Feb 21 15:52:30 volumiorp5 sudo[1893]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:30 volumiorp5 volumiobt[1892]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Feb 21 15:52:30 volumiorp5 sudo[1893]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:31 volumiorp5 volumio[1334]: info: TidalConnect service stoped! Feb 21 15:52:31 volumiorp5 volumio[1334]: info: Volumio BT Module successfully started Feb 21 15:52:31 volumiorp5 volumio[1334]: verbose: New Socket.io Connection to 192.168.0.102:3000 from 192.168.0.193 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Feb 21 15:52:31 volumiorp5 volumio[1334]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Feb 21 15:52:31 volumiorp5 volumio[1334]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Feb 21 15:52:31 volumiorp5 sudo[1905]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Feb 21 15:52:31 volumiorp5 sudo[1905]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:31 volumiorp5 systemd[1]: Started Volumio Tidal Connect Service. Feb 21 15:52:31 volumiorp5 sudo[1905]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:31 volumiorp5 volumio[1334]: info: Executing endpoint tc_getconfig Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Feb 21 15:52:31 volumiorp5 vtcs[1907]: STARTING TidalConnect services, version: 1.4.0.34 Feb 21 15:52:31 volumiorp5 vtcs[1907]: STARTED TidalConnect services. Feb 21 15:52:31 volumiorp5 volumio[1334]: info: Executing endpoint tc_connect Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Feb 21 15:52:31 volumiorp5 volumio[1334]: info: Connecting to TidalConnect Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreCommandRouter::servicePushState Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreStateMachine::pushState Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushState Feb 21 15:52:31 volumiorp5 volumio[1334]: info: MRS: Pushing multiroomSync output update for this device Feb 21 15:52:31 volumiorp5 volumio[1334]: info: MRS: Pushing multiroomSync output Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:31 volumiorp5 volumio[1334]: 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} Feb 21 15:52:31 volumiorp5 volumio[1334]: verbose: CURRENT POSITION 0 Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreStateMachine::syncState stateService stop Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreStateMachine::syncState currentStatus stop Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreStateMachine::pushState Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushState Feb 21 15:52:31 volumiorp5 volumio[1334]: info: MRS: Pushing multiroomSync output update for this device Feb 21 15:52:31 volumiorp5 volumio[1334]: info: MRS: Pushing multiroomSync output Feb 21 15:52:31 volumiorp5 volumio[1334]: info: No code Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreStateMachine::pushState Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushState Feb 21 15:52:31 volumiorp5 volumio[1334]: info: MRS: Pushing multiroomSync output update for this device Feb 21 15:52:31 volumiorp5 volumio[1334]: info: MRS: Pushing multiroomSync output Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreCommandRouter::servicePushState Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreStateMachine::pushState Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushState Feb 21 15:52:31 volumiorp5 volumio[1334]: info: MRS: Pushing multiroomSync output update for this device Feb 21 15:52:31 volumiorp5 volumio[1334]: info: MRS: Pushing multiroomSync output Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:31 volumiorp5 volumio[1334]: 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} Feb 21 15:52:31 volumiorp5 volumio[1334]: verbose: CURRENT POSITION 0 Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreStateMachine::syncState stateService stop Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreStateMachine::syncState currentStatus stop Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreStateMachine::pushState Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushState Feb 21 15:52:31 volumiorp5 volumio[1334]: info: MRS: Pushing multiroomSync output update for this device Feb 21 15:52:31 volumiorp5 volumio[1334]: info: MRS: Pushing multiroomSync output Feb 21 15:52:31 volumiorp5 volumio[1334]: info: No code Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreStateMachine::pushState Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:31 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushState Feb 21 15:52:31 volumiorp5 volumio[1334]: info: MRS: Pushing multiroomSync output update for this device Feb 21 15:52:31 volumiorp5 volumio[1334]: info: MRS: Pushing multiroomSync output Feb 21 15:52:31 volumiorp5 volumio[1334]: info: [ASDebug] CurState: stop PrevState: stop Feb 21 15:52:31 volumiorp5 volumio[1334]: info: [ASDebug] CurState: stop PrevState: stop Feb 21 15:52:31 volumiorp5 volumio[1334]: info: [ASDebug] CurState: stop PrevState: stop Feb 21 15:52:31 volumiorp5 volumio[1334]: info: [ASDebug] CurState: stop PrevState: stop Feb 21 15:52:31 volumiorp5 volumio[1334]: info: [ASDebug] CurState: stop PrevState: stop Feb 21 15:52:31 volumiorp5 volumio[1334]: info: [ASDebug] CurState: stop PrevState: stop Feb 21 15:52:31 volumiorp5 volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 21 15:52:31 volumiorp5 volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 21 15:52:31 volumiorp5 volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 21 15:52:31 volumiorp5 volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 21 15:52:31 volumiorp5 volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 21 15:52:31 volumiorp5 volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 21 15:52:31 volumiorp5 sudo[1931]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Feb 21 15:52:31 volumiorp5 sudo[1931]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:31 volumiorp5 sudo[1934]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Feb 21 15:52:31 volumiorp5 sudo[1934]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:31 volumiorp5 volumiobt[1892]: pulseaudio: no process found Feb 21 15:52:31 volumiorp5 systemd[1]: Started MyVolumio SSH Tunnel. Feb 21 15:52:31 volumiorp5 sudo[1934]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:31 volumiorp5 sudo[1931]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:32 volumiorp5 volumio[1334]: info: Remote SSH Started Feb 21 15:52:32 volumiorp5 autossh[1937]: port set to 0, monitoring disabled Feb 21 15:52:32 volumiorp5 autossh[1937]: starting ssh (count 1) Feb 21 15:52:32 volumiorp5 autossh[1937]: ssh child pid is 1940 Feb 21 15:52:32 volumiorp5 dbus-daemon[768]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.27' (uid=1000 pid=1942 comm="/usr/bin/pulseaudio --high-priority=true ") Feb 21 15:52:32 volumiorp5 systemd[1]: Starting RealtimeKit Scheduling Policy Service... Feb 21 15:52:32 volumiorp5 dbus-daemon[768]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Feb 21 15:52:32 volumiorp5 rtkit-daemon[1943]: Successfully called chroot. Feb 21 15:52:32 volumiorp5 rtkit-daemon[1943]: Successfully dropped privileges. Feb 21 15:52:32 volumiorp5 systemd[1]: Started RealtimeKit Scheduling Policy Service. Feb 21 15:52:32 volumiorp5 rtkit-daemon[1943]: Successfully limited resources. Feb 21 15:52:32 volumiorp5 rtkit-daemon[1943]: Running. Feb 21 15:52:32 volumiorp5 rtkit-daemon[1943]: Canary thread running. Feb 21 15:52:32 volumiorp5 rtkit-daemon[1943]: Watchdog thread running. Feb 21 15:52:32 volumiorp5 dbus-daemon[768]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.28' (uid=0 pid=1943 comm="/usr/lib/rtkit/rtkit-daemon ") Feb 21 15:52:32 volumiorp5 systemd[1]: Starting Authorization Manager... Feb 21 15:52:32 volumiorp5 volumio[1334]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 21 15:52:32 volumiorp5 volumio[1334]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 21 15:52:32 volumiorp5 polkitd[1947]: started daemon version 0.105 using authority implementation `local' version `0.105' Feb 21 15:52:32 volumiorp5 dbus-daemon[768]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Feb 21 15:52:32 volumiorp5 systemd[1]: Started Authorization Manager. Feb 21 15:52:32 volumiorp5 volumiossh-tunnel[1933]: Warning: Permanently added '[eu1.myvolumio.org]:2222,[68.183.69.189]:2222' (RSA) to the list of known hosts. Feb 21 15:52:32 volumiorp5 pulseaudio[1942]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Feb 21 15:52:32 volumiorp5 pulseaudio[1942]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Feb 21 15:52:32 volumiorp5 pulseaudio[1942]: 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 Feb 21 15:52:32 volumiorp5 bluetoothd[1051]: Endpoint registered: sender=:1.48 path=/MediaEndpoint/A2DPSource Feb 21 15:52:32 volumiorp5 bluetoothd[1051]: Endpoint registered: sender=:1.48 path=/MediaEndpoint/A2DPSink Feb 21 15:52:32 volumiorp5 volumiobt[1892]: Applying permissions Feb 21 15:52:32 volumiorp5 volumiobt[1892]: Setting BT discoverable and pairable Feb 21 15:52:32 volumiorp5 kernel: Bluetooth: RFCOMM TTY layer initialized Feb 21 15:52:32 volumiorp5 kernel: Bluetooth: RFCOMM socket layer initialized Feb 21 15:52:32 volumiorp5 kernel: Bluetooth: RFCOMM ver 1.11 Feb 21 15:52:32 volumiorp5 volumiobt[1892]: [CHG] Controller 2C:CF:67:C8:C5:86 Class: 0x0008041c Feb 21 15:52:32 volumiorp5 volumiobt[1892]: [55B blob data] Feb 21 15:52:32 volumiorp5 volumiobt[1892]: [bluetooth]# -e power on Feb 21 15:52:32 volumiorp5 volumiobt[1892]: Invalid command in menu main: -e Feb 21 15:52:32 volumiorp5 volumiobt[1892]: Feb 21 15:52:32 volumiorp5 volumiobt[1892]: Use "help" for a list of available commands in a menu. Feb 21 15:52:32 volumiorp5 volumiobt[1892]: Use "menu " if you want to enter any submenu. Feb 21 15:52:32 volumiorp5 volumiobt[1892]: Use "back" if you want to return to menu main. Feb 21 15:52:32 volumiorp5 volumiobt[1892]: [bluetooth]# agent on Feb 21 15:52:32 volumiorp5 volumiobt[1892]: Agent is already registered Feb 21 15:52:32 volumiorp5 volumiobt[1892]: [bluetooth]# discoverable on Feb 21 15:52:32 volumiorp5 volumiobt[1892]: [bluetooth]# pairable on Feb 21 15:52:32 volumiorp5 volumiobt[1892]: [bluetooth]# agent NoInputNoOutput Feb 21 15:52:32 volumiorp5 volumiobt[1892]: Agent is already registered Feb 21 15:52:32 volumiorp5 volumiobt[1892]: [bluetooth]# default-agent Feb 21 15:52:32 volumiorp5 volumiobt[1892]: [bluetooth]# quit Feb 21 15:52:32 volumiorp5 volumiobt[1892]: [59B blob data] Feb 21 15:52:32 volumiorp5 volumio[1334]: info: Setting Geolocation for MyVolumio to eu4 Feb 21 15:52:32 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:32 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:32 volumiorp5 volumio[1334]: info: Setting Geolocation for MyVolumio to eu4 Feb 21 15:52:32 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:32 volumiorp5 volumio[1334]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Feb 21 15:52:32 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:32 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:32 volumiorp5 volumio[1334]: info: MRS: Getting audio outputs on start Feb 21 15:52:32 volumiorp5 volumio[1334]: info: MRS: Requesting all other devices output Feb 21 15:52:33 volumiorp5 volumio[1334]: info: Successfully Added MyVolumio device Feb 21 15:52:33 volumiorp5 volumio[1334]: info: Updating MyVolumio device info Feb 21 15:52:33 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:33 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:33 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:33 volumiorp5 volumio[1334]: info: Successfully Added MyVolumio device Feb 21 15:52:33 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Feb 21 15:52:33 volumiorp5 volumio[1334]: info: Updating MyVolumio device info Feb 21 15:52:33 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:33 volumiorp5 volumio[1334]: info: Access Token successfully retrieved Feb 21 15:52:33 volumiorp5 volumio[1334]: info: Successfully retrieved User Session From TIDAL Feb 21 15:52:34 volumiorp5 volumio[1334]: info: Successfully Updated MyVolumio device Feb 21 15:52:34 volumiorp5 volumio[1334]: info: Successfully retrieved User Subscription From TIDAL Feb 21 15:52:34 volumiorp5 volumio[1334]: info: Adding TIDAL to Browse Sources Feb 21 15:52:34 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 15:52:34 volumiorp5 volumio[1334]: info: [1740149554102] CoreMusicLibrary::Adding element TIDAL Feb 21 15:52:34 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:52:34 volumiorp5 volumio[1334]: Cannot find translation for source TIDAL Feb 21 15:52:34 volumiorp5 volumio[1334]: info: Stopping AccessToken refresher cron Feb 21 15:52:34 volumiorp5 volumio[1334]: info: AccessToken refresher cron started Feb 21 15:52:34 volumiorp5 volumio[1334]: info: Adding TIDAL REST API Endpoints Feb 21 15:52:34 volumiorp5 volumio[1334]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Feb 21 15:52:34 volumiorp5 volumio[1334]: info: Successfully Updated MyVolumio device Feb 21 15:52:34 volumiorp5 volumio[1334]: info: TidalConnect service started! Feb 21 15:52:34 volumiorp5 volumio[1334]: [Metrics] CommandRouter: 20s 978.87ms Feb 21 15:52:34 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumiosetStartupVolume Feb 21 15:52:34 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:34 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:34 volumiorp5 volumio[1334]: info: CoreCommandRouter::Close All Modals sent Feb 21 15:52:34 volumiorp5 volumio[1334]: info: CoreCommandRouter::Close All Modals sent Feb 21 15:52:34 volumiorp5 volumio[1334]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Feb 21 15:52:34 volumiorp5 volumio[1334]: info: FusionDsp - ---- read samplerate from file: 44100 Feb 21 15:52:34 volumiorp5 volumio[1334]: info: camilladsp stopping service pid 1672... Feb 21 15:52:34 volumiorp5 volumio[1334]: info: camilladsp service terminated, instance 1 Feb 21 15:52:34 volumiorp5 volumio[1334]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 21 15:52:34 volumiorp5 volumio[1334]: info: camilladsp service started and running in background, instance 1 Feb 21 15:52:34 volumiorp5 volumio[1334]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Feb 21 15:52:34 volumiorp5 volumio[1334]: info: FusionDsp - ---- read samplerate from file: 44100 Feb 21 15:52:34 volumiorp5 volumio[1334]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 21 15:52:34 volumiorp5 volumio[1334]: error: FusionDsp - WebSocket error: [object Object] Feb 21 15:52:34 volumiorp5 volumio[1334]: info: camilladsp spawned new process with pid 1976, instance 1, run: true Feb 21 15:52:34 volumiorp5 kernel: pcm512x 1-004c: No SCLK, using BCLK: -2 Feb 21 15:52:35 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Feb 21 15:52:35 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 21 15:52:35 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Feb 21 15:52:36 volumiorp5 volumio[1334]: info: AutoStart - Plugin is starting Feb 21 15:52:36 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetQueue Feb 21 15:52:36 volumiorp5 volumio[1334]: info: CoreStateMachine::getQueue Feb 21 15:52:36 volumiorp5 volumio[1334]: info: CorePlayQueue::getQueue Feb 21 15:52:37 volumiorp5 volumio[1334]: info: camilladsp spawned new process with pid 1986, instance 1, run: true Feb 21 15:52:37 volumiorp5 kernel: pcm512x 1-004c: No SCLK, using BCLK: -2 Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 21 15:52:38 volumiorp5 volumio[1334]: info: Retrieving Cloud Streaming UI Feb 21 15:52:38 volumiorp5 volumio[1334]: info: Getting Tidal Cloud Configuration Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 21 15:52:38 volumiorp5 volumio[1334]: info: Getting Qobuz Cloud Configuration Feb 21 15:52:38 volumiorp5 volumio[1334]: info: Asking plugin for UI Config Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 21 15:52:38 volumiorp5 volumio[1334]: info: Getting Spotify Cloud Configuration Feb 21 15:52:38 volumiorp5 volumio[1334]: info: Asking plugin for UI Config Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 21 15:52:38 volumiorp5 volumio[1334]: info: Saving Spotify Acccount Feb 21 15:52:38 volumiorp5 volumio[1334]: info: Got it Feb 21 15:52:38 volumiorp5 volumio[1334]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Feb 21 15:52:38 volumiorp5 volumio[1334]: info: Got Tidal Cloud Configuration Feb 21 15:52:38 volumiorp5 volumio[1334]: info: Got it Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetBrowseSources Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetBrowseSources Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetBrowseSources Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 15:52:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Feb 21 15:52:40 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 21 15:52:40 volumiorp5 volumio[1334]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Feb 21 15:52:40 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:40 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:41 volumiorp5 systemd[1]: systemd-timedated.service: Succeeded. Feb 21 15:52:41 volumiorp5 volumio[1334]: info: BOOT COMPLETED Feb 21 15:52:42 volumiorp5 volumio[1334]: info: mpdhttpout ---Boot completed detected! Patching mpd now! Feb 21 15:52:42 volumiorp5 volumio[1334]: info: mpdhttpout ---Configuration successfully replaced in mpd.conf. Feb 21 15:52:42 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:42 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:42 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPause Feb 21 15:52:42 volumiorp5 volumio[1334]: info: CoreStateMachine::pause Feb 21 15:52:42 volumiorp5 volumio[1334]: info: mpdhttpout --- Volumio set on pause Feb 21 15:52:42 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 15:52:43 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:52:43 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:52:43 volumiorp5 volumio[1334]: info: Discovery: Getting this device information Feb 21 15:52:43 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:52:43 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:52:43 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:52:44 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Feb 21 15:52:44 volumiorp5 sudo[1996]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 21 15:52:44 volumiorp5 sudo[1996]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:44 volumiorp5 systemd[1]: Stopping Music Player Daemon... Feb 21 15:52:44 volumiorp5 volumio[1334]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 21 15:52:44 volumiorp5 systemd[1]: mpd.service: Succeeded. Feb 21 15:52:44 volumiorp5 systemd[1]: Stopped Music Player Daemon. Feb 21 15:52:44 volumiorp5 volumio[1334]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Feb 21 15:52:44 volumiorp5 systemd[1]: Starting Music Player Daemon... Feb 21 15:52:44 volumiorp5 volumio[1334]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 21 15:52:44 volumiorp5 sudo[1998]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 21 15:52:44 volumiorp5 sudo[1998]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 15:52:44 volumiorp5 sudo[1998]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:44 volumiorp5 mpd[2000]: Feb 21 15:52 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 21 15:52:44 volumiorp5 systemd[1]: Started Music Player Daemon. Feb 21 15:52:44 volumiorp5 sudo[1996]: pam_unix(sudo:session): session closed for user root Feb 21 15:52:44 volumiorp5 volumio[1334]: error: updateQueue error: null Feb 21 15:52:45 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:52:45 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 21 15:52:45 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 21 15:52:45 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 21 15:52:45 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetBrowseSources Feb 21 15:52:45 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 15:52:46 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 15:52:46 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 15:52:46 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 21 15:52:46 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 15:52:46 volumiorp5 volumio-remote-updater[770]: No test mode Feb 21 15:52:46 volumiorp5 volumio-remote-updater[770]: No alpha test mode Feb 21 15:52:46 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 21 15:52:46 volumiorp5 volumio[1334]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 21 15:52:46 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 21 15:52:50 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 15:52:54 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 15:52:58 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 15:52:59 volumiorp5 volumio[1334]: info: CALLMETHOD: miscellanea albumart saveAlbumartOptions [object Object] Feb 21 15:52:59 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: albumart , saveAlbumartOptions Feb 21 15:53:02 volumiorp5 ntpd[982]: Soliciting pool server 195.35.113.80 Feb 21 15:53:02 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 15:53:02 volumiorp5 ntpd[982]: Soliciting pool server 178.239.19.60 Feb 21 15:53:03 volumiorp5 ntpd[982]: Soliciting pool server 193.87.160.18 Feb 21 15:53:03 volumiorp5 ntpd[982]: Soliciting pool server 185.242.56.5 Feb 21 15:53:03 volumiorp5 ntpd[982]: Soliciting pool server 213.81.129.99 Feb 21 15:53:03 volumiorp5 ntpd[982]: Soliciting pool server 91.237.170.89 Feb 21 15:53:04 volumiorp5 ntpd[982]: Soliciting pool server 90.176.21.0 Feb 21 15:53:04 volumiorp5 ntpd[982]: Soliciting pool server 62.168.94.161 Feb 21 15:53:05 volumiorp5 ntpd[982]: Soliciting pool server 2001:470:6f:483::1 Feb 21 15:53:05 volumiorp5 ntpd[982]: Soliciting pool server 92.240.244.202 Feb 21 15:53:06 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 15:53:06 volumiorp5 ntpd[982]: Soliciting pool server 87.197.160.189 Feb 21 15:53:07 volumiorp5 ntpd[982]: Soliciting pool server 84.245.104.80 Feb 21 15:53:10 volumiorp5 ntpd[982]: receive: Unexpected origin timestamp 0xeb6311d5.f5a8de44 does not match aorg 0000000000.00000000 from server@213.81.129.99 xmt 0xeb6311d6.2c06dfd9 Feb 21 15:53:10 volumiorp5 ntpd[982]: receive: Unexpected origin timestamp 0xeb6311d5.f5a828c8 does not match aorg 0000000000.00000000 from server@90.176.21.0 xmt 0xeb6311d6.2be1c0d2 Feb 21 15:53:10 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetQueue Feb 21 15:53:10 volumiorp5 volumio[1334]: info: CoreStateMachine::getQueue Feb 21 15:53:10 volumiorp5 volumio[1334]: info: CorePlayQueue::getQueue Feb 21 15:53:13 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:53:13 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:53:13 volumiorp5 volumio[1334]: info: Discovery: Getting this device information Feb 21 15:53:13 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:53:13 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:53:13 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:53:14 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Feb 21 15:53:14 volumiorp5 volumio[1334]: info: browseTIDALUri took 403 milliseconds Feb 21 15:53:14 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:14 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:15 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Feb 21 15:53:16 volumiorp5 volumio[1334]: info: browseTIDALUri took 455 milliseconds Feb 21 15:53:16 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:16 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:19 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Feb 21 15:53:19 volumiorp5 volumio[1334]: info: browseTIDALUri took 358 milliseconds Feb 21 15:53:19 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:19 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:21 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Feb 21 15:53:23 volumiorp5 volumio[1334]: info: browseTIDALUri took 1373 milliseconds Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/35748020 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/35748027 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/405033668 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/400405208 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/274168241 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/35748026 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/35748023 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/405033661 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/405033654 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/396588958 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/35748022 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/405033666 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/405033665 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/41099493 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/274168239 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/405033664 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/405033672 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/405033667 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/405033670 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/405033671 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/35748018 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/274168238 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/35748019 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/5577753 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/215213468 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/274168243 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/35748021 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/35748037 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/215213462 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/274168242 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/405893501 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/274168252 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/4990500 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/35748029 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/215214768 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/35748028 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/35748038 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/274168240 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/274168237 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/274168250 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/274168244 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/50257828 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/50257822 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/35748025 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/280729222 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/570315 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/274168247 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/35748031 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/35748033 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Preloading song: tidal://song/274168245 Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748020 in service tidal Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748027 in service tidal Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/405033668 in service tidal Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/400405208 in service tidal Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168241 in service tidal Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748026 in service tidal Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748023 in service tidal Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/405033661 in service tidal Feb 21 15:53:23 volumiorp5 volumio[1334]: info: explodeTIDALUri took 351 milliseconds Feb 21 15:53:23 volumiorp5 volumio[1334]: info: explodeTIDALUri took 344 milliseconds Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/405033654 in service tidal Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/396588958 in service tidal Feb 21 15:53:23 volumiorp5 volumio[1334]: info: explodeTIDALUri took 357 milliseconds Feb 21 15:53:23 volumiorp5 volumio[1334]: info: explodeTIDALUri took 348 milliseconds Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748022 in service tidal Feb 21 15:53:23 volumiorp5 volumio[1334]: info: explodeTIDALUri took 345 milliseconds Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/405033666 in service tidal Feb 21 15:53:23 volumiorp5 volumio[1334]: info: explodeTIDALUri took 346 milliseconds Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/405033665 in service tidal Feb 21 15:53:23 volumiorp5 volumio[1334]: info: explodeTIDALUri took 341 milliseconds Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/41099493 in service tidal Feb 21 15:53:23 volumiorp5 volumio[1334]: info: explodeTIDALUri took 334 milliseconds Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168239 in service tidal Feb 21 15:53:23 volumiorp5 volumio[1334]: info: explodeTIDALUri took 339 milliseconds Feb 21 15:53:23 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/405033664 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/405033672 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: explodeTIDALUri took 337 milliseconds Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/405033667 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/405033670 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: explodeTIDALUri took 354 milliseconds Feb 21 15:53:24 volumiorp5 volumio[1334]: info: explodeTIDALUri took 348 milliseconds Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/405033671 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: explodeTIDALUri took 534 milliseconds Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748018 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: explodeTIDALUri took 362 milliseconds Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168238 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748019 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/5577753 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/215213468 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168243 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748021 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748037 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/215213462 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168242 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/405893501 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168252 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/4990500 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748029 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/215214768 in service tidal Feb 21 15:53:24 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748028 in service tidal Feb 21 15:53:25 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748038 in service tidal Feb 21 15:53:25 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168240 in service tidal Feb 21 15:53:25 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168237 in service tidal Feb 21 15:53:25 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168250 in service tidal Feb 21 15:53:25 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168244 in service tidal Feb 21 15:53:25 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/50257828 in service tidal Feb 21 15:53:25 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/50257822 in service tidal Feb 21 15:53:25 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748025 in service tidal Feb 21 15:53:25 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/280729222 in service tidal Feb 21 15:53:25 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/570315 in service tidal Feb 21 15:53:25 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168247 in service tidal Feb 21 15:53:25 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748031 in service tidal Feb 21 15:53:25 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748033 in service tidal Feb 21 15:53:25 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168245 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreStateMachine::ClearQueue Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreStateMachine::stop Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CorePlayQueue::clearPlayQueue Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CorePlayQueue::saveQueue Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushQueue Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreStateMachine::addQueueItems Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CorePlayQueue::addQueueItems Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748020 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748020 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748027 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748027 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033668 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033668 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/400405208 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/400405208 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168241 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168241 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushQueue Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CorePlayQueue::saveQueue Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreStateMachine::updateTrackBlock Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrackBlock Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPlay Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreStateMachine::play index 4 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreStateMachine::addQueueItems Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CorePlayQueue::addQueueItems Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748026 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748026 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748023 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748023 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033661 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033661 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033654 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033654 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/396588958 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/396588958 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748022 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748022 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033666 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033666 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033665 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033665 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/41099493 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/41099493 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168239 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168239 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033664 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/405033664 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033672 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/405033672 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033667 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/405033667 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033670 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/405033670 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033671 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/405033671 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748018 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748018 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168238 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168238 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748019 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748019 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/5577753 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/5577753 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/215213468 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/215213468 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168243 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168243 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748021 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748021 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748037 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748037 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/215213462 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/215213462 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168242 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168242 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405893501 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/405893501 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168252 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168252 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/4990500 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/4990500 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748029 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748029 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/215214768 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/215214768 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748028 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748028 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748038 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748038 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168240 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168240 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168237 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168237 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168250 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168250 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168244 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168244 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/50257828 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/50257828 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/50257822 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/50257822 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748025 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748025 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/280729222 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/280729222 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/570315 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/570315 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168247 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168247 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748031 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748031 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748033 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748033 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168245 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168245 in service tidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreStateMachine::stop Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreStateMachine::play index undefined Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 4 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreStateMachine::startPlaybackTimer Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 4 Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetVisibleSources Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 21 15:53:28 volumiorp5 volumio[1334]: info: [1740149608798] ControllerTidal::clearAddPlayTrack Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Getting stream with soundQuality HIGH Feb 21 15:53:28 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand stop Feb 21 15:53:28 volumiorp5 volumio[1334]: info: sendMpdCommand stop took 35 milliseconds Feb 21 15:53:28 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand clear Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Feb 21 15:53:28 volumiorp5 volumio[1334]: ---------------------------- MPD announces system playlist update Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Ignoring MPD Status Update Feb 21 15:53:28 volumiorp5 volumio[1334]: info: sendMpdCommand clear took 0 milliseconds Feb 21 15:53:28 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/274168241&soundQuality=HIGH" Feb 21 15:53:28 volumiorp5 volumio[1334]: error: updateQueue error: null Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Feb 21 15:53:28 volumiorp5 volumio[1334]: ---------------------------- MPD announces system playlist update Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Ignoring MPD Status Update Feb 21 15:53:28 volumiorp5 volumio[1334]: info: ------------------------------ 1ms Feb 21 15:53:28 volumiorp5 volumio[1334]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/274168241&soundQuality=HIGH" took 0 milliseconds Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 21 15:53:28 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand play Feb 21 15:53:28 volumiorp5 volumio[1334]: info: ------------------------------ 1ms Feb 21 15:53:28 volumiorp5 volumio[1334]: info: sendMpdCommand play took 1 milliseconds Feb 21 15:53:28 volumiorp5 volumio[1334]: STREAMING PROXY: Handling url /?data=tidal://song/274168241&soundQuality=HIGH Feb 21 15:53:28 volumiorp5 volumio[1334]: info: Executing endpoint getStreamUrltidal Feb 21 15:53:28 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 21 15:53:29 volumiorp5 volumio[1334]: info: explodeTIDALUri took 5235 milliseconds Feb 21 15:53:29 volumiorp5 volumio[1334]: info: explodeTIDALUri took 5399 milliseconds Feb 21 15:53:29 volumiorp5 volumio[1334]: info: explodeTIDALUri took 5151 milliseconds Feb 21 15:53:29 volumiorp5 volumio[1334]: info: explodeTIDALUri took 4956 milliseconds Feb 21 15:53:29 volumiorp5 volumio[1334]: info: explodeTIDALUri took 4820 milliseconds Feb 21 15:53:29 volumiorp5 volumio[1334]: info: explodeTIDALUri took 4922 milliseconds Feb 21 15:53:29 volumiorp5 volumio[1334]: info: explodeTIDALUri took 5137 milliseconds Feb 21 15:53:29 volumiorp5 volumio[1334]: info: explodeTIDALUri took 5340 milliseconds Feb 21 15:53:29 volumiorp5 volumio[1334]: info: explodeTIDALUri took 4799 milliseconds Feb 21 15:53:29 volumiorp5 volumio[1334]: info: explodeTIDALUri took 5261 milliseconds Feb 21 15:53:29 volumiorp5 volumio[1334]: info: explodeTIDALUri took 5067 milliseconds Feb 21 15:53:29 volumiorp5 volumio[1334]: info: explodeTIDALUri took 4923 milliseconds Feb 21 15:53:29 volumiorp5 volumio[1334]: info: explodeTIDALUri took 5432 milliseconds Feb 21 15:53:29 volumiorp5 volumio[1334]: info: explodeTIDALUri took 5135 milliseconds Feb 21 15:53:32 volumiorp5 volumio[1334]: info: VolumeController::SetAlsaVolume61 Feb 21 15:53:32 volumiorp5 volumio[1334]: info: CoreStateMachine::pushState Feb 21 15:53:32 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 21 15:53:32 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushState Feb 21 15:53:32 volumiorp5 volumio[1334]: info: MRS: Pushing multiroomSync output update for this device Feb 21 15:53:32 volumiorp5 volumio[1334]: info: MRS: Pushing multiroomSync output Feb 21 15:53:32 volumiorp5 volumio[1334]: info: [ASDebug] CurState: PrevState: stop Feb 21 15:53:32 volumiorp5 volumio[1334]: info: [ASDebug] Togle GPIO: ON Feb 21 15:53:32 volumiorp5 volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 61 Feb 21 15:53:32 volumiorp5 volumio[1334]: SPOTIFY: SPOTIFY VOLUME 100 Feb 21 15:53:32 volumiorp5 volumio[1334]: SPOTIFY: VOLUMIO VOLUME 61 Feb 21 15:53:32 volumiorp5 volumio[1334]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 21 15:53:32 volumiorp5 volumio[1334]: info: Setting Spotify Volume from Volumio: 61 Feb 21 15:53:33 volumiorp5 volumio[1334]: SPOTIFY: SETTING SPOTIFY VOLUME 61 Feb 21 15:53:33 volumiorp5 volumio[1334]: info: Sending Spotify command with payload to local API: /player/volume Feb 21 15:53:34 volumiorp5 volumio[1334]: info: explodeTIDALUri took 9628 milliseconds Feb 21 15:53:34 volumiorp5 volumio[1334]: info: explodeTIDALUri took 9739 milliseconds Feb 21 15:53:34 volumiorp5 volumio[1334]: info: explodeTIDALUri took 9346 milliseconds Feb 21 15:53:34 volumiorp5 volumio[1334]: info: explodeTIDALUri took 9472 milliseconds Feb 21 15:53:34 volumiorp5 volumio[1334]: info: explodeTIDALUri took 9424 milliseconds Feb 21 15:53:34 volumiorp5 volumio[1334]: info: explodeTIDALUri took 9582 milliseconds Feb 21 15:53:34 volumiorp5 volumio[1334]: info: explodeTIDALUri took 9637 milliseconds Feb 21 15:53:34 volumiorp5 volumio[1334]: info: explodeTIDALUri took 9543 milliseconds Feb 21 15:53:34 volumiorp5 volumio[1334]: info: explodeTIDALUri took 9097 milliseconds Feb 21 15:53:34 volumiorp5 volumio[1334]: info: explodeTIDALUri took 9352 milliseconds Feb 21 15:53:34 volumiorp5 volumio[1334]: info: explodeTIDALUri took 9061 milliseconds Feb 21 15:53:34 volumiorp5 volumio[1334]: info: explodeTIDALUri took 9263 milliseconds Feb 21 15:53:34 volumiorp5 volumio[1334]: info: explodeTIDALUri took 9226 milliseconds Feb 21 15:53:34 volumiorp5 volumio[1334]: info: explodeTIDALUri took 9332 milliseconds Feb 21 15:53:34 volumiorp5 volumio[1334]: info: explodeTIDALUri took 9786 milliseconds Feb 21 15:53:34 volumiorp5 volumio[1334]: info: explodeTIDALUri took 9190 milliseconds Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreStateMachine::ClearQueue Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreStateMachine::stop Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CorePlayQueue::clearPlayQueue Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CorePlayQueue::saveQueue Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushQueue Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreStateMachine::addQueueItems Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CorePlayQueue::addQueueItems Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748020 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748020 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748027 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748027 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033668 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033668 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/400405208 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/400405208 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168241 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168241 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushQueue Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CorePlayQueue::saveQueue Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreStateMachine::updateTrackBlock Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrackBlock Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPlay Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreStateMachine::play index 4 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreStateMachine::addQueueItems Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CorePlayQueue::addQueueItems Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748026 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748026 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748023 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748023 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033661 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033661 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033654 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033654 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/396588958 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/396588958 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748022 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748022 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033666 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033666 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033665 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033665 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/41099493 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/41099493 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168239 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168239 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033664 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033664 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033672 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033672 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033667 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033667 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033670 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033670 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033671 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033671 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748018 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748018 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168238 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168238 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748019 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748019 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/5577753 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/5577753 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/215213468 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/215213468 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168243 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168243 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748021 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748021 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748037 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748037 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/215213462 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/215213462 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168242 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168242 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405893501 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405893501 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168252 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168252 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/4990500 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/4990500 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748029 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748029 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/215214768 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/215214768 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748028 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748028 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748038 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748038 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168240 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168240 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168237 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168237 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168250 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168250 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168244 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168244 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/50257828 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/50257828 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/50257822 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/50257822 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748025 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748025 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/280729222 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/280729222 in service tidal Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/570315 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/570315 in service tidal Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168247 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168247 in service tidal Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748031 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748031 in service tidal Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748033 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748033 in service tidal Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168245 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168245 in service tidal Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreStateMachine::stop Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreStateMachine::play index undefined Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 4 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreStateMachine::startPlaybackTimer Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 4 Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetVisibleSources Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 21 15:53:35 volumiorp5 volumio[1334]: info: [1740149615799] ControllerTidal::clearAddPlayTrack Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Getting stream with soundQuality HIGH Feb 21 15:53:35 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand stop Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Feb 21 15:53:35 volumiorp5 volumio[1334]: ---------------------------- MPD announces state update: player Feb 21 15:53:35 volumiorp5 volumio[1334]: info: sendMpdCommand stop took 10 milliseconds Feb 21 15:53:35 volumiorp5 volumio[1334]: info: ControllerMpd::getState Feb 21 15:53:35 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Feb 21 15:53:35 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand clear Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Feb 21 15:53:35 volumiorp5 volumio[1334]: ---------------------------- MPD announces system playlist update Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Ignoring MPD Status Update Feb 21 15:53:35 volumiorp5 volumio[1334]: info: sendMpdCommand status took 0 milliseconds Feb 21 15:53:35 volumiorp5 volumio[1334]: info: sendMpdCommand clear took 0 milliseconds Feb 21 15:53:35 volumiorp5 volumio[1334]: verbose: ControllerMpd::parseState Feb 21 15:53:35 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 21 15:53:35 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/274168241&soundQuality=HIGH" Feb 21 15:53:35 volumiorp5 volumio[1334]: error: updateQueue error: null Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Feb 21 15:53:35 volumiorp5 volumio[1334]: ---------------------------- MPD announces system playlist update Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Ignoring MPD Status Update Feb 21 15:53:35 volumiorp5 volumio[1334]: info: ------------------------------ 2ms Feb 21 15:53:35 volumiorp5 volumio[1334]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 21 15:53:35 volumiorp5 volumio[1334]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/274168241&soundQuality=HIGH" took 1 milliseconds Feb 21 15:53:35 volumiorp5 volumio[1334]: verbose: ControllerMpd::parseTrackInfo Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 21 15:53:35 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand play Feb 21 15:53:35 volumiorp5 volumio[1334]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Feb 21 15:53:35 volumiorp5 volumio[1334]: info: ------------------------------ 4ms Feb 21 15:53:35 volumiorp5 volumio[1334]: info: ------------------------------ 1ms Feb 21 15:53:35 volumiorp5 volumio[1334]: info: sendMpdCommand play took 0 milliseconds Feb 21 15:53:35 volumiorp5 volumio[1334]: STREAMING PROXY: Handling url /?data=tidal://song/274168241&soundQuality=HIGH Feb 21 15:53:35 volumiorp5 volumio[1334]: info: Executing endpoint getStreamUrltidal Feb 21 15:53:35 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreStateMachine::ClearQueue Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreStateMachine::stop Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CorePlayQueue::clearPlayQueue Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CorePlayQueue::saveQueue Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushQueue Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreStateMachine::addQueueItems Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CorePlayQueue::addQueueItems Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748020 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748020 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748027 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748027 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033668 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033668 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/400405208 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/400405208 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168241 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168241 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushQueue Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CorePlayQueue::saveQueue Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreStateMachine::updateTrackBlock Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrackBlock Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPlay Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreStateMachine::play index 4 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreStateMachine::addQueueItems Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CorePlayQueue::addQueueItems Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748026 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748026 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748023 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748023 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033661 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033661 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033654 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033654 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/396588958 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/396588958 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748022 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748022 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033666 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033666 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033665 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033665 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/41099493 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/41099493 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168239 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168239 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033664 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033664 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033672 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033672 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033667 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033667 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033670 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033670 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405033671 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405033671 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748018 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748018 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168238 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168238 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748019 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748019 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/5577753 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/5577753 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/215213468 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/215213468 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168243 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168243 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748021 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748021 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748037 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748037 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/215213462 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/215213462 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168242 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168242 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/405893501 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/405893501 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168252 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168252 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/4990500 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/4990500 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748029 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748029 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/215214768 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/215214768 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748028 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748028 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748038 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748038 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168240 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168240 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168237 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168237 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168250 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168250 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168244 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168244 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/50257828 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/50257828 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/50257822 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/50257822 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748025 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/35748025 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/280729222 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/280729222 in service tidal Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/570315 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/570315 in service tidal Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168247 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168247 in service tidal Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748031 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748031 in service tidal Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/35748033 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/35748033 in service tidal Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168245 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Exploding uri tidal://song/274168245 in service tidal Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreStateMachine::stop Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreStateMachine::play index undefined Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 4 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreStateMachine::startPlaybackTimer Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 4 Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetVisibleSources Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 21 15:53:38 volumiorp5 volumio[1334]: info: [1740149618175] ControllerTidal::clearAddPlayTrack Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Getting stream with soundQuality HIGH Feb 21 15:53:38 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand stop Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Feb 21 15:53:38 volumiorp5 volumio[1334]: ---------------------------- MPD announces state update: player Feb 21 15:53:38 volumiorp5 volumio[1334]: info: sendMpdCommand stop took 8 milliseconds Feb 21 15:53:38 volumiorp5 volumio[1334]: info: ControllerMpd::getState Feb 21 15:53:38 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Feb 21 15:53:38 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand clear Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Feb 21 15:53:38 volumiorp5 volumio[1334]: ---------------------------- MPD announces system playlist update Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Ignoring MPD Status Update Feb 21 15:53:38 volumiorp5 volumio[1334]: info: sendMpdCommand status took 1 milliseconds Feb 21 15:53:38 volumiorp5 volumio[1334]: info: sendMpdCommand clear took 1 milliseconds Feb 21 15:53:38 volumiorp5 volumio[1334]: verbose: ControllerMpd::parseState Feb 21 15:53:38 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 21 15:53:38 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/274168241&soundQuality=HIGH" Feb 21 15:53:38 volumiorp5 volumio[1334]: error: updateQueue error: null Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Feb 21 15:53:38 volumiorp5 volumio[1334]: ---------------------------- MPD announces system playlist update Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Ignoring MPD Status Update Feb 21 15:53:38 volumiorp5 volumio[1334]: info: ------------------------------ 1ms Feb 21 15:53:38 volumiorp5 volumio[1334]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 21 15:53:38 volumiorp5 volumio[1334]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/274168241&soundQuality=HIGH" took 1 milliseconds Feb 21 15:53:38 volumiorp5 volumio[1334]: verbose: ControllerMpd::parseTrackInfo Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 21 15:53:38 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand play Feb 21 15:53:38 volumiorp5 volumio[1334]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Feb 21 15:53:38 volumiorp5 volumio[1334]: info: ------------------------------ 2ms Feb 21 15:53:38 volumiorp5 volumio[1334]: info: ------------------------------ 1ms Feb 21 15:53:38 volumiorp5 volumio[1334]: info: sendMpdCommand play took 1 milliseconds Feb 21 15:53:38 volumiorp5 volumio[1334]: STREAMING PROXY: Handling url /?data=tidal://song/274168241&soundQuality=HIGH Feb 21 15:53:38 volumiorp5 volumio[1334]: info: Executing endpoint getStreamUrltidal Feb 21 15:53:38 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 21 15:53:39 volumiorp5 volumio[1334]: info: explodeTIDALUri took 10550 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: info: explodeTIDALUri took 10552 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: info: explodeTIDALUri took 10562 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: info: explodeTIDALUri took 10580 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: info: explodeTIDALUri took 10583 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: info: explodeTIDALUri took 10593 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: info: explodeTIDALUri took 13812 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: info: explodeTIDALUri took 10604 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: info: explodeTIDALUri took 13773 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: info: explodeTIDALUri took 13985 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: info: explodeTIDALUri took 13759 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: info: explodeTIDALUri took 13931 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: info: explodeTIDALUri took 14044 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreStateMachine::ClearQueue Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreStateMachine::stop Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CorePlayQueue::clearPlayQueue Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CorePlayQueue::saveQueue Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushQueue Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreStateMachine::addQueueItems Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CorePlayQueue::addQueueItems Feb 21 15:53:39 volumiorp5 volumio[1334]: info: Preload queue cleared Feb 21 15:53:39 volumiorp5 volumio[1334]: info: Adding Item to queue: tidal://song/274168241 Feb 21 15:53:39 volumiorp5 volumio[1334]: info: Using cached record of: tidal://song/274168241 Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushQueue Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CorePlayQueue::saveQueue Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreStateMachine::updateTrackBlock Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrackBlock Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPlay Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreStateMachine::play index 0 Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreStateMachine::stop Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreStateMachine::play index undefined Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreStateMachine::startPlaybackTimer Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrack 0 Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetVisibleSources Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 21 15:53:39 volumiorp5 volumio[1334]: info: [1740149619949] ControllerTidal::clearAddPlayTrack Feb 21 15:53:39 volumiorp5 volumio[1334]: info: Getting stream with soundQuality HIGH Feb 21 15:53:39 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand stop Feb 21 15:53:39 volumiorp5 volumio[1334]: info: Feb 21 15:53:39 volumiorp5 volumio[1334]: ---------------------------- MPD announces state update: player Feb 21 15:53:39 volumiorp5 volumio[1334]: info: sendMpdCommand stop took 2 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: info: ControllerMpd::getState Feb 21 15:53:39 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Feb 21 15:53:39 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand clear Feb 21 15:53:39 volumiorp5 volumio[1334]: info: Feb 21 15:53:39 volumiorp5 volumio[1334]: ---------------------------- MPD announces system playlist update Feb 21 15:53:39 volumiorp5 volumio[1334]: info: Ignoring MPD Status Update Feb 21 15:53:39 volumiorp5 volumio[1334]: info: sendMpdCommand status took 1 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: info: sendMpdCommand clear took 1 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: verbose: ControllerMpd::parseState Feb 21 15:53:39 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 21 15:53:39 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/274168241&soundQuality=HIGH" Feb 21 15:53:39 volumiorp5 volumio[1334]: error: updateQueue error: null Feb 21 15:53:39 volumiorp5 volumio[1334]: info: Feb 21 15:53:39 volumiorp5 volumio[1334]: ---------------------------- MPD announces system playlist update Feb 21 15:53:39 volumiorp5 volumio[1334]: info: Ignoring MPD Status Update Feb 21 15:53:39 volumiorp5 volumio[1334]: info: ------------------------------ 1ms Feb 21 15:53:39 volumiorp5 volumio[1334]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/274168241&soundQuality=HIGH" took 1 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: verbose: ControllerMpd::parseTrackInfo Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 21 15:53:39 volumiorp5 volumio[1334]: verbose: ControllerMpd::sendMpdCommand play Feb 21 15:53:39 volumiorp5 volumio[1334]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Feb 21 15:53:39 volumiorp5 volumio[1334]: info: ------------------------------ 2ms Feb 21 15:53:39 volumiorp5 volumio[1334]: info: ------------------------------ 1ms Feb 21 15:53:39 volumiorp5 volumio[1334]: info: sendMpdCommand play took 1 milliseconds Feb 21 15:53:39 volumiorp5 volumio[1334]: STREAMING PROXY: Handling url /?data=tidal://song/274168241&soundQuality=HIGH Feb 21 15:53:39 volumiorp5 volumio[1334]: info: Executing endpoint getStreamUrltidal Feb 21 15:53:39 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 21 15:53:43 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 15:53:43 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 15:53:43 volumiorp5 volumio[1334]: info: Discovery: Getting this device information Feb 21 15:53:43 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioGetState Feb 21 15:53:43 volumiorp5 volumio[1334]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 15:53:44 volumiorp5 volumio[1334]: info: explodeTIDALUri took 15553 milliseconds Feb 21 15:53:44 volumiorp5 volumio[1334]: info: explodeTIDALUri took 15561 milliseconds Feb 21 15:53:44 volumiorp5 volumio[1334]: info: explodeTIDALUri took 15570 milliseconds Feb 21 15:53:44 volumiorp5 volumio[1334]: info: explodeTIDALUri took 15590 milliseconds Feb 21 15:53:44 volumiorp5 volumio[1334]: info: explodeTIDALUri took 15596 milliseconds Feb 21 15:53:44 volumiorp5 volumio[1334]: info: explodeTIDALUri took 15605 milliseconds Feb 21 15:53:44 volumiorp5 volumio[1334]: info: explodeTIDALUri took 15605 milliseconds Feb 21 15:53:44 volumiorp5 volumio[1334]: info: explodeTIDALUri took 15618 milliseconds Feb 21 15:53:44 volumiorp5 volumio[1334]: info: explodeTIDALUri took 15623 milliseconds Feb 21 15:53:44 volumiorp5 volumio[1334]: info: explodeTIDALUri took 15624 milliseconds Feb 21 15:53:44 volumiorp5 volumio[1334]: info: explodeTIDALUri took 15624 milliseconds Feb 21 15:53:44 volumiorp5 volumio[1334]: info: explodeTIDALUri took 15636 milliseconds Feb 21 15:53:44 volumiorp5 volumio[1334]: info: explodeTIDALUri took 15640 milliseconds Feb 21 15:53:44 volumiorp5 volumio[1334]: info: explodeTIDALUri took 15657 milliseconds Feb 21 15:53:44 volumiorp5 volumio[1334]: info: explodeTIDALUri took 15657 milliseconds Feb 21 15:53:44 volumiorp5 volumio[1334]: info: explodeTIDALUri took 15665 milliseconds Feb 21 15:53:49 volumiorp5 volumio[1334]: info: explodeTIDALUri took 20600 milliseconds Feb 21 15:53:49 volumiorp5 volumio[1334]: info: explodeTIDALUri took 20604 milliseconds Feb 21 15:53:49 volumiorp5 volumio[1334]: info: explodeTIDALUri took 20611 milliseconds Feb 21 15:53:49 volumiorp5 volumio[1334]: info: explodeTIDALUri took 20629 milliseconds Feb 21 15:53:49 volumiorp5 volumio[1334]: info: explodeTIDALUri took 20632 milliseconds Feb 21 15:53:49 volumiorp5 volumio[1334]: info: explodeTIDALUri took 20643 milliseconds Feb 21 15:53:49 volumiorp5 volumio[1334]: info: explodeTIDALUri took 20642 milliseconds Feb 21 15:53:49 volumiorp5 volumio[1334]: info: explodeTIDALUri took 20659 milliseconds Feb 21 15:53:49 volumiorp5 volumio[1334]: info: explodeTIDALUri took 20673 milliseconds Feb 21 15:53:49 volumiorp5 volumio[1334]: info: explodeTIDALUri took 20677 milliseconds Feb 21 15:53:49 volumiorp5 volumio[1334]: info: explodeTIDALUri took 20690 milliseconds Feb 21 15:53:49 volumiorp5 volumio[1334]: info: explodeTIDALUri took 20694 milliseconds Feb 21 15:53:49 volumiorp5 volumio[1334]: info: explodeTIDALUri took 20707 milliseconds Feb 21 15:53:49 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushQueue Feb 21 15:53:49 volumiorp5 volumio[1334]: info: CorePlayQueue::saveQueue Feb 21 15:53:49 volumiorp5 volumio[1334]: info: CoreStateMachine::updateTrackBlock Feb 21 15:53:49 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrackBlock Feb 21 15:53:49 volumiorp5 volumio[1334]: info: getStreamUrl took 20712 milliseconds Feb 21 15:53:49 volumiorp5 volumio[1334]: STREAMING PROXY: Got real url: http://amz-pr-cf.audio.tidal.com/03d0fe828446529e2a8447a245972edc_37.mp4?Expires=1740153229&Signature=cVjttndUO5UUfqBExsTeeNVJTyRNdUlA2JT1SP83r96XC70RaPkvt7Aycrfox4UJIv~IfftBuDoX7wzM3VUZGCZDHV2Nws~1cW4zCwWxw9YnuQ8Qx4VXrvBxKWc0FwSyHUHj1ixsRaD3UTVDtOXfPGkTD7WTmVsc0mGCLKPBhgfQqAqiuypPI0upzbzdzU7NBujccMaMxGaEocBL4D~mIu7k5gxyXEjwe3GrmDD-HUtykCBJSlFg4D6fOZwHqexuAFSqmdqJ60DUuOgHNTZmDswxp~93b95Kfe4TEnOsF63-gSkIg7ooeeu1C01iG7jry0h7kMwodU9hK0vgM~FfhA__&Key-Pair-Id=K14LZCZ9QUI4JL Feb 21 15:53:54 volumiorp5 volumio[1334]: info: explodeTIDALUri took 18663 milliseconds Feb 21 15:53:54 volumiorp5 volumio[1334]: info: explodeTIDALUri took 18670 milliseconds Feb 21 15:53:54 volumiorp5 volumio[1334]: info: explodeTIDALUri took 18671 milliseconds Feb 21 15:53:54 volumiorp5 volumio[1334]: info: explodeTIDALUri took 16298 milliseconds Feb 21 15:53:54 volumiorp5 volumio[1334]: info: explodeTIDALUri took 18673 milliseconds Feb 21 15:53:54 volumiorp5 volumio[1334]: info: explodeTIDALUri took 16309 milliseconds Feb 21 15:53:54 volumiorp5 volumio[1334]: info: explodeTIDALUri took 16320 milliseconds Feb 21 15:53:54 volumiorp5 volumio[1334]: info: explodeTIDALUri took 16331 milliseconds Feb 21 15:53:54 volumiorp5 volumio[1334]: info: explodeTIDALUri took 18720 milliseconds Feb 21 15:53:54 volumiorp5 volumio[1334]: info: explodeTIDALUri took 16349 milliseconds Feb 21 15:53:54 volumiorp5 volumio[1334]: info: explodeTIDALUri took 18727 milliseconds Feb 21 15:53:54 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushQueue Feb 21 15:53:54 volumiorp5 volumio[1334]: info: CorePlayQueue::saveQueue Feb 21 15:53:54 volumiorp5 volumio[1334]: info: CoreStateMachine::updateTrackBlock Feb 21 15:53:54 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrackBlock Feb 21 15:53:54 volumiorp5 volumio[1334]: info: explodeTIDALUri took 16363 milliseconds Feb 21 15:53:54 volumiorp5 volumio[1334]: info: CoreCommandRouter::volumioPushQueue Feb 21 15:53:54 volumiorp5 volumio[1334]: info: CorePlayQueue::saveQueue Feb 21 15:53:54 volumiorp5 volumio[1334]: info: CoreStateMachine::updateTrackBlock Feb 21 15:53:54 volumiorp5 volumio[1334]: info: CorePlayQueue::getTrackBlock Feb 21 15:53:54 volumiorp5 volumio[1334]: info: getStreamUrl took 18785 milliseconds Feb 21 15:53:54 volumiorp5 volumio[1334]: STREAMING PROXY: Got real url: http://amz-pr-cf.audio.tidal.com/03d0fe828446529e2a8447a245972edc_37.mp4?Expires=1740153229&Signature=cVjttndUO5UUfqBExsTeeNVJTyRNdUlA2JT1SP83r96XC70RaPkvt7Aycrfox4UJIv~IfftBuDoX7wzM3VUZGCZDHV2Nws~1cW4zCwWxw9YnuQ8Qx4VXrvBxKWc0FwSyHUHj1ixsRaD3UTVDtOXfPGkTD7WTmVsc0mGCLKPBhgfQqAqiuypPI0upzbzdzU7NBujccMaMxGaEocBL4D~mIu7k5gxyXEjwe3GrmDD-HUtykCBJSlFg4D6fOZwHqexuAFSqmdqJ60DUuOgHNTZmDswxp~93b95Kfe4TEnOsF63-gSkIg7ooeeu1C01iG7jry0h7kMwodU9hK0vgM~FfhA__&Key-Pair-Id=K14LZCZ9QUI4JL Feb 21 15:53:54 volumiorp5 volumio[1334]: info: getStreamUrl took 14757 milliseconds Feb 21 15:53:54 volumiorp5 volumio[1334]: STREAMING PROXY: Got real url: http://amz-pr-cf.audio.tidal.com/03d0fe828446529e2a8447a245972edc_37.mp4?Expires=1740153229&Signature=cVjttndUO5UUfqBExsTeeNVJTyRNdUlA2JT1SP83r96XC70RaPkvt7Aycrfox4UJIv~IfftBuDoX7wzM3VUZGCZDHV2Nws~1cW4zCwWxw9YnuQ8Qx4VXrvBxKWc0FwSyHUHj1ixsRaD3UTVDtOXfPGkTD7WTmVsc0mGCLKPBhgfQqAqiuypPI0upzbzdzU7NBujccMaMxGaEocBL4D~mIu7k5gxyXEjwe3GrmDD-HUtykCBJSlFg4D6fOZwHqexuAFSqmdqJ60DUuOgHNTZmDswxp~93b95Kfe4TEnOsF63-gSkIg7ooeeu1C01iG7jry0h7kMwodU9hK0vgM~FfhA__&Key-Pair-Id=K14LZCZ9QUI4JL Feb 21 15:53:54 volumiorp5 volumio[1334]: info: getStreamUrl took 16577 milliseconds Feb 21 15:53:54 volumiorp5 volumio[1334]: STREAMING PROXY: Got real url: http://amz-pr-cf.audio.tidal.com/03d0fe828446529e2a8447a245972edc_37.mp4?Expires=1740153229&Signature=cVjttndUO5UUfqBExsTeeNVJTyRNdUlA2JT1SP83r96XC70RaPkvt7Aycrfox4UJIv~IfftBuDoX7wzM3VUZGCZDHV2Nws~1cW4zCwWxw9YnuQ8Qx4VXrvBxKWc0FwSyHUHj1ixsRaD3UTVDtOXfPGkTD7WTmVsc0mGCLKPBhgfQqAqiuypPI0upzbzdzU7NBujccMaMxGaEocBL4D~mIu7k5gxyXEjwe3GrmDD-HUtykCBJSlFg4D6fOZwHqexuAFSqmdqJ60DUuOgHNTZmDswxp~93b95Kfe4TEnOsF63-gSkIg7ooeeu1C01iG7jry0h7kMwodU9hK0vgM~FfhA__&Key-Pair-Id=K14LZCZ9QUI4JL Feb 21 15:53:55 volumiorp5 volumio[1334]: STREAMING PROXY: Response: 200, length: 9547145 Feb 21 15:53:55 volumiorp5 volumio[1334]: STREAMING PROXY: Response: 200, length: 9547145 Feb 21 15:53:55 volumiorp5 volumio[1334]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________ Feb 21 15:53:55 volumiorp5 volumio[1334]: info: PLUGIN onReboot : networkfs Feb 21 15:53:55 volumiorp5 volumio[1334]: info: PLUGIN onReboot : audiophonicsonoff Feb 21 15:53:55 volumiorp5 volumio[1334]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 15:53:55 volumiorp5 volumio[1334]: TypeError: Cannot read property 'writeSync' of undefined Feb 21 15:53:55 volumiorp5 volumio[1334]: at ControllerAudiophonicsOnOff.onVolumioReboot (/data/plugins/system_hardware/audiophonicsonoff/index.js:40:25) Feb 21 15:53:55 volumiorp5 volumio[1334]: at PluginManager.onVolumioRebootPlugin (/volumio/app/pluginmanager.js:684:30) Feb 21 15:53:55 volumiorp5 volumio[1334]: at HashMap. (/volumio/app/pluginmanager.js:668:31) Feb 21 15:53:55 volumiorp5 volumio[1334]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Feb 21 15:53:55 volumiorp5 volumio[1334]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Feb 21 15:53:55 volumiorp5 volumio[1334]: at PluginManager.onVolumioReboot (/volumio/app/pluginmanager.js:666:20) Feb 21 15:53:55 volumiorp5 volumio[1334]: at CoreCommandRouter.reboot (/volumio/app/index.js:1344:22) Feb 21 15:53:55 volumiorp5 volumio[1334]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:864:33) Feb 21 15:53:55 volumiorp5 volumio[1334]: at Socket.emit (events.js:315:20) Feb 21 15:53:55 volumiorp5 volumio[1334]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Feb 21 15:53:55 volumiorp5 volumio[1334]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Feb 21 15:53:55 volumiorp5 volumio[1334]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 15:53:55 volumiorp5 sudo[2193]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-21 15:52 Feb 21 15:53:55 volumiorp5 sudo[2193]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"