-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Tue 2024-08-27 08:21:04 CEST. -- Aug 27 08:20:00 volumio-4b sudo[697]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:00 volumio-4b wireless.js[541]: Stopped aP Aug 27 08:20:00 volumio-4b sudo[704]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 27 08:20:00 volumio-4b sudo[704]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:00 volumio-4b kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 27 08:20:00 volumio-4b sudo[704]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:00 volumio-4b sudo[706]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Aug 27 08:20:00 volumio-4b sudo[706]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:00 volumio-4b sudo[706]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:00 volumio-4b sudo[713]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 27 08:20:00 volumio-4b sudo[713]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:00 volumio-4b sudo[713]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:00 volumio-4b sudo[715]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Aug 27 08:20:00 volumio-4b sudo[715]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:00 volumio-4b ntpd[666]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Aug 27 08:20:00 volumio-4b systemd[1]: systemd-rfkill.service: Succeeded. Aug 27 08:20:01 volumio-4b ntpd[666]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Aug 27 08:20:02 volumio-4b bthelper[587]: Changing power off succeeded Aug 27 08:20:02 volumio-4b ntpd[666]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Aug 27 08:20:02 volumio-4b bthelper[587]: [CHG] Controller D8:3A:DD:96:09:73 Class: 0x0000041c Aug 27 08:20:02 volumio-4b bthelper[587]: Changing power on succeeded Aug 27 08:20:02 volumio-4b sudo[715]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:02 volumio-4b wireless.js[541]: SETTING APPROPRIATE REG DOMAIN: FR Aug 27 08:20:02 volumio-4b sudo[727]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 27 08:20:02 volumio-4b sudo[727]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:02 volumio-4b sudo[727]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:02 volumio-4b sudo[729]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set FR Aug 27 08:20:02 volumio-4b sudo[729]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:02 volumio-4b sudo[729]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:02 volumio-4b wireless.js[541]: SUCCESSFULLY SET NEW REGDOMAIN: FR Aug 27 08:20:02 volumio-4b volumio-remote-updater[540]: [2024-08-27 08:20:02] [info] asio async_connect error: system:111 (Connection refused) Aug 27 08:20:02 volumio-4b volumio-remote-updater[540]: [2024-08-27 08:20:02] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Aug 27 08:20:02 volumio-4b volumio-remote-updater[540]: [2024-08-27 08:20:02] [error] handle_connect error: Underlying Transport Error Aug 27 08:20:02 volumio-4b wireless.js[541]: Start wireless flow Aug 27 08:20:02 volumio-4b wireless.js[541]: Stopped hotspot (if there).. Aug 27 08:20:02 volumio-4b sudo[734]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 27 08:20:03 volumio-4b sudo[734]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:03 volumio-4b sudo[734]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:03 volumio-4b sudo[736]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 27 08:20:03 volumio-4b sudo[736]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:03 volumio-4b sudo[736]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:03 volumio-4b wireless.js[541]: DHCP IP Aug 27 08:20:03 volumio-4b wireless.js[541]: Start ap Aug 27 08:20:03 volumio-4b wpa_supplicant[738]: Successfully initialized wpa_supplicant Aug 27 08:20:03 volumio-4b sudo[739]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Aug 27 08:20:03 volumio-4b sudo[739]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:03 volumio-4b kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 27 08:20:03 volumio-4b dhcpcd[740]: dev: loaded udev Aug 27 08:20:03 volumio-4b dhcpcd-run-hooks[758]: wlan0: starting wpa_supplicant Aug 27 08:20:03 volumio-4b dhcpcd-run-hooks[763]: wlan0: failed to start wpa_supplicant Aug 27 08:20:03 volumio-4b dhcpcd-run-hooks[764]: 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 Aug 27 08:20:03 volumio-4b dhcpcd[740]: wlan0: connected to Access Point `' Aug 27 08:20:04 volumio-4b dhcpcd[740]: no interfaces have a carrier Aug 27 08:20:04 volumio-4b dhcpcd[740]: forked to background, child pid 774 Aug 27 08:20:04 volumio-4b dhcpcd[774]: eth0: waiting for carrier Aug 27 08:20:04 volumio-4b dhcpcd[774]: wlan0: waiting for carrier Aug 27 08:20:04 volumio-4b sudo[739]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:04 volumio-4b wireless.js[541]: trying... Aug 27 08:20:04 volumio-4b sudo[776]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 08:20:04 volumio-4b sudo[776]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:04 volumio-4b sudo[776]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:05 volumio-4b wireless.js[541]: trying... Aug 27 08:20:05 volumio-4b sudo[779]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 08:20:05 volumio-4b sudo[779]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:05 volumio-4b sudo[779]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:06 volumio-4b wpa_supplicant[762]: wlan0: Trying to associate with SSID 'TP-LINK_87AF' Aug 27 08:20:06 volumio-4b wireless.js[541]: trying... Aug 27 08:20:06 volumio-4b sudo[782]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 08:20:06 volumio-4b sudo[782]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:06 volumio-4b sudo[782]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:07 volumio-4b wireless.js[541]: trying... Aug 27 08:20:07 volumio-4b sudo[785]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 08:20:07 volumio-4b sudo[785]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:07 volumio-4b sudo[785]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:08 volumio-4b wireless.js[541]: trying... Aug 27 08:20:08 volumio-4b sudo[788]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 08:20:08 volumio-4b sudo[788]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:08 volumio-4b sudo[788]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:09 volumio-4b dhcpcd[774]: wlan0: carrier acquired Aug 27 08:20:09 volumio-4b dhcpcd[774]: wlan0: connected to Access Point `TP-LINK_87AF' Aug 27 08:20:09 volumio-4b wpa_supplicant[762]: wlan0: Associated with d4:6e:0e:7e:87:ae Aug 27 08:20:09 volumio-4b wpa_supplicant[762]: wlan0: CTRL-EVENT-CONNECTED - Connection to d4:6e:0e:7e:87:ae completed [id=0 id_str=] Aug 27 08:20:09 volumio-4b wpa_supplicant[762]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Aug 27 08:20:09 volumio-4b dhcpcd[774]: DUID 00:01:00:01:2d:5e:64:94:d8:3a:dd:96:09:6f Aug 27 08:20:09 volumio-4b dhcpcd[774]: wlan0: IAID dd:96:09:71 Aug 27 08:20:09 volumio-4b dhcpcd[774]: wlan0: adding address fe80::205d:90af:434a:61c4 Aug 27 08:20:09 volumio-4b dhcpcd[774]: ipv6_addaddr1: Permission denied Aug 27 08:20:09 volumio-4b dhcpcd[774]: wlan0: carrier lost Aug 27 08:20:09 volumio-4b dhcpcd[774]: wlan0: carrier acquired Aug 27 08:20:09 volumio-4b dhcpcd[774]: wlan0: IAID dd:96:09:71 Aug 27 08:20:09 volumio-4b wireless.js[541]: trying... Aug 27 08:20:09 volumio-4b sudo[803]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 08:20:09 volumio-4b sudo[803]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:09 volumio-4b sudo[803]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:10 volumio-4b dhcpcd[774]: wlan0: soliciting an IPv6 router Aug 27 08:20:10 volumio-4b dhcpcd[774]: wlan0: rebinding lease of 192.168.0.111 Aug 27 08:20:10 volumio-4b dhcpcd[774]: wlan0: probing address 192.168.0.111/24 Aug 27 08:20:10 volumio-4b volumio-remote-updater[540]: [2024-08-27 08:20:10] [info] asio async_connect error: system:111 (Connection refused) Aug 27 08:20:10 volumio-4b volumio-remote-updater[540]: [2024-08-27 08:20:10] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Aug 27 08:20:10 volumio-4b volumio-remote-updater[540]: [2024-08-27 08:20:10] [error] handle_connect error: Underlying Transport Error Aug 27 08:20:10 volumio-4b wireless.js[541]: trying... Aug 27 08:20:10 volumio-4b sudo[806]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 08:20:10 volumio-4b sudo[806]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:10 volumio-4b sudo[806]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:11 volumio-4b wireless.js[541]: trying... Aug 27 08:20:11 volumio-4b sudo[809]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 08:20:11 volumio-4b sudo[809]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:11 volumio-4b sudo[809]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:12 volumio-4b wireless.js[541]: trying... Aug 27 08:20:12 volumio-4b sudo[812]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 08:20:12 volumio-4b sudo[812]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:12 volumio-4b sudo[812]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:13 volumio-4b wireless.js[541]: trying... Aug 27 08:20:13 volumio-4b sudo[815]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 08:20:13 volumio-4b sudo[815]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:13 volumio-4b sudo[815]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:14 volumio-4b wireless.js[541]: trying... Aug 27 08:20:14 volumio-4b sudo[818]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 08:20:14 volumio-4b sudo[818]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:14 volumio-4b sudo[818]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:15 volumio-4b wireless.js[541]: trying... Aug 27 08:20:15 volumio-4b sudo[821]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 08:20:15 volumio-4b sudo[821]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:15 volumio-4b sudo[821]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:15 volumio-4b dhcpcd[774]: wlan0: leased 192.168.0.111 for 7200 seconds Aug 27 08:20:15 volumio-4b avahi-daemon[539]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.111. Aug 27 08:20:15 volumio-4b dhcpcd[774]: wlan0: adding route to 192.168.0.0/24 Aug 27 08:20:15 volumio-4b avahi-daemon[539]: New relevant interface wlan0.IPv4 for mDNS. Aug 27 08:20:15 volumio-4b dhcpcd[774]: wlan0: adding default route via 192.168.0.1 Aug 27 08:20:15 volumio-4b avahi-daemon[539]: Registering new address record for 192.168.0.111 on wlan0.IPv4. Aug 27 08:20:16 volumio-4b wireless.js[541]: trying... Aug 27 08:20:16 volumio-4b sudo[844]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 27 08:20:16 volumio-4b sudo[844]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:16 volumio-4b sudo[844]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:16 volumio-4b wireless.js[541]: Connected to: ----TP-LINK_87AF Aug 27 08:20:16 volumio-4b wireless.js[541]: ---- Aug 27 08:20:16 volumio-4b sudo[847]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 08:20:16 volumio-4b sudo[847]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:16 volumio-4b sudo[847]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:16 volumio-4b wireless.js[541]: ... joined AP, wlan0 IPv4 is 192.168.0.111, ipV6 is undefined Aug 27 08:20:16 volumio-4b wireless.js[541]: It's done! AP Aug 27 08:20:16 volumio-4b systemd[1]: Started Wireless Services. Aug 27 08:20:16 volumio-4b kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 27 08:20:16 volumio-4b systemd[1]: Started Volumio Backend Module. Aug 27 08:20:16 volumio-4b systemd[1]: Started Volumio Cpu Tweaker. Aug 27 08:20:16 volumio-4b volumio-cpu-tweak[853]: Setting RT Priority for mpd Aug 27 08:20:16 volumio-4b volumio-cpu-tweak[853]: pid 35's current scheduling policy: SCHED_OTHER Aug 27 08:20:16 volumio-4b volumio-cpu-tweak[853]: pid 35's current scheduling priority: 0 Aug 27 08:20:16 volumio-4b volumio-cpu-tweak[853]: Setting MPD Affinity Aug 27 08:20:16 volumio-4b volumio-cpu-tweak[853]: pid 3's current affinity mask: f Aug 27 08:20:16 volumio-4b volumio-cpu-tweak[853]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Aug 27 08:20:16 volumio-4b volumio-cpu-tweak[853]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Aug 27 08:20:16 volumio-4b systemd[1]: volumio_cpu_tweak.service: Succeeded. Aug 27 08:20:17 volumio-4b ntpd[666]: Listen normally on 3 wlan0 192.168.0.111:123 Aug 27 08:20:17 volumio-4b ntpd[666]: new interface(s) found: waking up resolver Aug 27 08:20:18 volumio-4b volumio[852]: info: ------------------------------------------- Aug 27 08:20:18 volumio-4b volumio[852]: info: ----- Volumio3 ---- Aug 27 08:20:18 volumio-4b volumio[852]: info: ------------------------------------------- Aug 27 08:20:18 volumio-4b volumio[852]: info: ----- System startup ---- Aug 27 08:20:18 volumio-4b volumio[852]: info: ------------------------------------------- Aug 27 08:20:19 volumio-4b volumio[852]: info: MYVOLUMIO Environment detected Aug 27 08:20:19 volumio-4b volumio[852]: info: Plugin folders cleanup Aug 27 08:20:19 volumio-4b volumio[852]: info: Scanning into folder /volumio/app/plugins/ Aug 27 08:20:19 volumio-4b volumio[852]: info: Scanning category audio_interface Aug 27 08:20:19 volumio-4b volumio[852]: info: Scanning category miscellanea Aug 27 08:20:19 volumio-4b volumio[852]: info: Scanning category music_service Aug 27 08:20:19 volumio-4b volumio[852]: info: Scanning category plugins.json Aug 27 08:20:19 volumio-4b volumio[852]: info: Scanning category system_controller Aug 27 08:20:19 volumio-4b volumio[852]: info: Scanning category user_interface Aug 27 08:20:19 volumio-4b volumio[852]: info: Scanning into folder /data/plugins/ Aug 27 08:20:19 volumio-4b volumio[852]: info: Scanning category audio_interface Aug 27 08:20:19 volumio-4b volumio[852]: info: Scanning category music_service Aug 27 08:20:19 volumio-4b volumio[852]: info: Scanning category system_controller Aug 27 08:20:19 volumio-4b volumio[852]: info: Scanning category user_interface Aug 27 08:20:19 volumio-4b volumio[852]: info: Plugin folders cleanup completed Aug 27 08:20:19 volumio-4b volumio[852]: info: ------------------------------------------- Aug 27 08:20:19 volumio-4b volumio[852]: info: ----- Core plugins startup ---- Aug 27 08:20:19 volumio-4b volumio[852]: info: ------------------------------------------- Aug 27 08:20:19 volumio-4b volumio[852]: info: Loading plugins from folder /volumio/app/plugins/ Aug 27 08:20:19 volumio-4b volumio[852]: info: Adding plugin upnp to MyMusic Plugins Aug 27 08:20:19 volumio-4b nmbd[626]: [2024/08/27 08:20:19.189700, 0] ../lib/util/become_daemon.c:138(daemon_ready) Aug 27 08:20:19 volumio-4b nmbd[626]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Aug 27 08:20:19 volumio-4b systemd[1]: Started Samba NMB Daemon. Aug 27 08:20:19 volumio-4b volumio[852]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 27 08:20:19 volumio-4b volumio[852]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 27 08:20:19 volumio-4b volumio[852]: info: Loading plugins from folder /data/plugins/ Aug 27 08:20:19 volumio-4b volumio[852]: info: Loading plugin "system"... Aug 27 08:20:19 volumio-4b volumio[852]: info: Loading plugin "appearance"... Aug 27 08:20:19 volumio-4b systemd[1]: Starting Samba Winbind Daemon... Aug 27 08:20:19 volumio-4b winbindd[879]: [2024/08/27 08:20:19.464347, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Aug 27 08:20:19 volumio-4b winbindd[879]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Aug 27 08:20:19 volumio-4b winbindd[879]: [2024/08/27 08:20:19.485763, 0] ../lib/util/become_daemon.c:138(daemon_ready) Aug 27 08:20:19 volumio-4b winbindd[879]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Aug 27 08:20:19 volumio-4b systemd[1]: Started Samba Winbind Daemon. Aug 27 08:20:19 volumio-4b systemd[1]: Starting Samba SMB Daemon... Aug 27 08:20:19 volumio-4b winbindd[879]: [2024/08/27 08:20:19.889720, 0] ../source3/winbindd/wb_lookupsids.c:659(wb_lookupsids_recv) Aug 27 08:20:19 volumio-4b winbindd[879]: res_names->count = 3, expected 4 Aug 27 08:20:19 volumio-4b smbd[887]: [2024/08/27 08:20:19.909670, 0] ../lib/util/become_daemon.c:138(daemon_ready) Aug 27 08:20:19 volumio-4b systemd[1]: Started Samba SMB Daemon. Aug 27 08:20:19 volumio-4b smbd[887]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Aug 27 08:20:19 volumio-4b systemd[1]: Reached target Multi-User System. Aug 27 08:20:19 volumio-4b systemd[1]: Reached target Graphical Interface. Aug 27 08:20:19 volumio-4b systemd[1]: Starting Update UTMP about System Runlevel Changes... Aug 27 08:20:19 volumio-4b systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Aug 27 08:20:19 volumio-4b systemd[1]: Started Update UTMP about System Runlevel Changes. Aug 27 08:20:19 volumio-4b systemd[1]: Startup finished in 9.265s (kernel) + 29.655s (userspace) = 38.921s. Aug 27 08:20:20 volumio-4b volumio[852]: info: Loading plugin "network"... Aug 27 08:20:20 volumio-4b volumio[852]: info: Refreshing Cached IP Addresses Aug 27 08:20:20 volumio-4b sudo[897]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 08:20:20 volumio-4b sudo[897]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:20 volumio-4b sudo[897]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:20 volumio-4b volumio[852]: info: Loading plugin "services"... Aug 27 08:20:20 volumio-4b sudo[899]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 08:20:20 volumio-4b sudo[899]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:20 volumio-4b volumio[852]: info: Loading plugin "alsa_controller"... Aug 27 08:20:20 volumio-4b sudo[899]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:20 volumio-4b sudo[902]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 27 08:20:20 volumio-4b sudo[902]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:20 volumio-4b volumio-remote-updater[540]: [2024-08-27 08:20:20] [connect] Successful connection Aug 27 08:20:20 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 08:20:20 volumio-4b volumio[852]: info: Loading plugin "wizard"... Aug 27 08:20:20 volumio-4b volumio[852]: info: Loading plugin "networkfs"... Aug 27 08:20:20 volumio-4b volumio[852]: info: Starting Udev Watcher for removable devices Aug 27 08:20:20 volumio-4b volumio[852]: info: Ignoring mount for partition: boot Aug 27 08:20:20 volumio-4b volumio[852]: info: Ignoring mount for partition: volumio Aug 27 08:20:20 volumio-4b volumio[852]: info: Ignoring mount for partition: volumio_data Aug 27 08:20:20 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 27 08:20:20 volumio-4b volumio[852]: info: Loading plugin "volumio_command_line_client"... Aug 27 08:20:20 volumio-4b volumio[852]: info: Loading plugin "upnp"... Aug 27 08:20:20 volumio-4b volumio[852]: info: [1724739620578] Starting Upmpd Daemon Aug 27 08:20:20 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 27 08:20:20 volumio-4b volumio[852]: info: Loading plugin "my_music"... Aug 27 08:20:20 volumio-4b volumio[852]: info: Loading plugin "mpd"... Aug 27 08:20:20 volumio-4b volumio[852]: info: Loading plugin "upnp_browser"... Aug 27 08:20:21 volumio-4b volumio[852]: info: Loading plugin "alarm-clock"... Aug 27 08:20:21 volumio-4b volumio[852]: info: Plugin airplay_emulation is not enabled Aug 27 08:20:21 volumio-4b volumio[852]: info: Loading plugin "last_100"... Aug 27 08:20:21 volumio-4b volumio[852]: info: Loading plugin "webradio"... Aug 27 08:20:21 volumio-4b volumio[852]: info: Loading plugin "i2s_dacs"... Aug 27 08:20:21 volumio-4b volumio[852]: info: Loading plugin "volumiodiscovery"... Aug 27 08:20:21 volumio-4b volumio[852]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 27 08:20:21 volumio-4b node[852]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 27 08:20:21 volumio-4b node[852]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 08:20:21 volumio-4b volumio[852]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 08:20:21 volumio-4b volumio[852]: *** WARNING *** For more information see Aug 27 08:20:21 volumio-4b volumio[852]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 27 08:20:21 volumio-4b volumio[852]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 08:20:21 volumio-4b volumio[852]: *** WARNING *** For more information see Aug 27 08:20:21 volumio-4b node[852]: *** WARNING *** For more information see Aug 27 08:20:21 volumio-4b node[852]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 27 08:20:21 volumio-4b node[852]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 08:20:21 volumio-4b node[852]: *** WARNING *** For more information see Aug 27 08:20:21 volumio-4b volumio[852]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 27 08:20:21 volumio-4b volumio[852]: info: Discovery: Started advertising with name: Volumio 4B Aug 27 08:20:21 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 27 08:20:21 volumio-4b volumio[852]: info: Loading plugin "calmradio"... Aug 27 08:20:22 volumio-4b volumio[852]: info: Loading plugin "mixcloud"... Aug 27 08:20:22 volumio-4b volumio[852]: info: Loading plugin "soundcloud"... Aug 27 08:20:22 volumio-4b volumio[852]: info: Loading plugin "spop"... Aug 27 08:20:23 volumio-4b volumio[852]: info: Loading plugin "outputs"... Aug 27 08:20:23 volumio-4b volumio[852]: info: Loading plugin "albumart"... Aug 27 08:20:23 volumio-4b volumio[852]: info: Plugin example_plugin is not enabled Aug 27 08:20:23 volumio-4b volumio[852]: info: Loading plugin "inputs"... Aug 27 08:20:23 volumio-4b volumio[852]: info: Loading plugin "updater_comm"... Aug 27 08:20:24 volumio-4b volumio[852]: info: Plugin mpdemulation is not enabled Aug 27 08:20:24 volumio-4b volumio[852]: info: Loading plugin "rest_api"... Aug 27 08:20:24 volumio-4b volumio[852]: info: Loading plugin "websocket"... Aug 27 08:20:24 volumio-4b volumio[852]: info: Loading plugin "fusiondsp"... Aug 27 08:20:24 volumio-4b volumio[852]: Forking 3 albumart workers Aug 27 08:20:24 volumio-4b sudo[902]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:24 volumio-4b volumio[852]: info: Applying required configuration parameters for plugin fusiondsp Aug 27 08:20:24 volumio-4b volumio[852]: info: Loading plugin "80s80s"... Aug 27 08:20:24 volumio-4b volumio[852]: Starting albumart workers Aug 27 08:20:24 volumio-4b volumio[852]: info: Applying required configuration parameters for plugin 80s80s Aug 27 08:20:24 volumio-4b volumio[852]: info: [1724739624756] [80s80s] API delay: 30 Aug 27 08:20:24 volumio-4b volumio[852]: info: Loading plugin "rad357pl"... Aug 27 08:20:24 volumio-4b volumio[852]: Starting albumart workers Aug 27 08:20:24 volumio-4b volumio[852]: Starting albumart workers Aug 27 08:20:25 volumio-4b volumio[852]: info: Applying required configuration parameters for plugin rad357pl Aug 27 08:20:25 volumio-4b volumio[852]: info: [1724739625089] [rad357pl] API delay: 5 Aug 27 08:20:25 volumio-4b volumio[852]: info: Loading plugin "radio_paradise"... Aug 27 08:20:25 volumio-4b volumio[852]: info: Applying required configuration parameters for plugin radio_paradise Aug 27 08:20:25 volumio-4b volumio[852]: info: [1724739625302] [RadioParadise] API delay: 5 Aug 27 08:20:25 volumio-4b volumio[852]: info: Plugin backup_restore is not enabled Aug 27 08:20:25 volumio-4b volumio[852]: info: Loading plugin "Systeminfo"... Aug 27 08:20:25 volumio-4b volumio[852]: info: Loading plugin "lastfm"... Aug 27 08:20:25 volumio-4b systemd[1]: systemd-fsckd.service: Succeeded. Aug 27 08:20:25 volumio-4b volumio[852]: info: Loading plugin "randomizer"... Aug 27 08:20:26 volumio-4b volumio[852]: info: Applying required configuration parameters for plugin randomizer Aug 27 08:20:26 volumio-4b volumio[852]: info: Loading plugin "touch_display"... Aug 27 08:20:26 volumio-4b volumio[852]: info: Applying required configuration parameters for plugin touch_display Aug 27 08:20:26 volumio-4b sh[417]: timed out Aug 27 08:20:26 volumio-4b dhcpcd[465]: timed out Aug 27 08:20:26 volumio-4b sh[417]: dhcpcd exited Aug 27 08:20:26 volumio-4b dhcpcd[465]: dhcpcd exited Aug 27 08:20:26 volumio-4b sh[417]: ifup: failed to bring up eth0 Aug 27 08:20:26 volumio-4b systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Aug 27 08:20:26 volumio-4b systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Aug 27 08:20:26 volumio-4b volumio[852]: info: Loading i18n strings for locale pl Aug 27 08:20:26 volumio-4b volumio[852]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Aug 27 08:20:26 volumio-4b volumio[852]: Updating browse sources language Aug 27 08:20:26 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 08:20:26 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 08:20:26 volumio-4b volumio[852]: info: CoreCommandRouter::initPlayerControls Aug 27 08:20:26 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:26 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:26 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:26 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:26 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:26 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:26 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:26 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:26 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 08:20:26 volumio-4b volumio[852]: Express server listening on port 3000 Aug 27 08:20:26 volumio-4b volumio[852]: [Metrics] WebUI: 8s 969.14ms Aug 27 08:20:26 volumio-4b volumio[852]: info: CoreStateMachine::resetVolumioState Aug 27 08:20:26 volumio-4b volumio[852]: info: CoreStateMachine::getcurrentVolume Aug 27 08:20:26 volumio-4b volumio[852]: info: CoreCommandRouter::volumioRetrievevolume Aug 27 08:20:26 volumio-4b volumio[852]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 1 Aug 27 08:20:26 volumio-4b volumio[852]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Aug 27 08:20:26 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 08:20:26 volumio-4b volumio[852]: info: Reloading queue from file Aug 27 08:20:27 volumio-4b volumio[852]: info: VolumeController:: Volume=100 Mute =false Aug 27 08:20:27 volumio-4b volumio[852]: info: CoreStateMachine::pushState Aug 27 08:20:27 volumio-4b volumio[852]: info: CorePlayQueue::getTrack 0 Aug 27 08:20:27 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 08:20:27 volumio-4b volumio[852]: info: CoreCommandRouter::volumioPushState Aug 27 08:20:27 volumio-4b volumio[852]: info: CoreStateMachine::updateTrackBlock Aug 27 08:20:27 volumio-4b volumio[852]: info: CorePlayQueue::getTrackBlock Aug 27 08:20:27 volumio-4b volumio[852]: info: CoreCommandRouter::volumioRetrievevolume Aug 27 08:20:27 volumio-4b volumio[852]: info: CoreStateMachine::setRepeat null single undefined Aug 27 08:20:27 volumio-4b volumio[852]: info: CoreStateMachine::pushState Aug 27 08:20:27 volumio-4b volumio[852]: info: CorePlayQueue::getTrack 0 Aug 27 08:20:27 volumio-4b volumio[852]: info: CoreCommandRouter::volumioPushState Aug 27 08:20:27 volumio-4b volumio[852]: info: CoreStateMachine::setRandom null Aug 27 08:20:27 volumio-4b volumio[852]: info: CoreStateMachine::pushState Aug 27 08:20:27 volumio-4b volumio[852]: info: CorePlayQueue::getTrack 0 Aug 27 08:20:27 volumio-4b volumio[852]: info: CoreCommandRouter::volumioPushState Aug 27 08:20:27 volumio-4b volumio[852]: info: Setting Device type: Raspberry PI Aug 27 08:20:27 volumio-4b volumio[852]: info: Discovery: adding b3ba5bc9-9d10-4f9e-8f60-d77341359dbb Aug 27 08:20:27 volumio-4b volumio[852]: info: Discovery: Found device Volumio 4B Aug 27 08:20:27 volumio-4b volumio[852]: info: CoreCommandRouter::volumioGetState Aug 27 08:20:27 volumio-4b volumio[852]: info: CorePlayQueue::getTrack 0 Aug 27 08:20:27 volumio-4b volumio[852]: info: VolumeController:: Volume=100 Mute =false Aug 27 08:20:27 volumio-4b volumio[852]: info: CoreStateMachine::pushState Aug 27 08:20:27 volumio-4b volumio[852]: info: CorePlayQueue::getTrack 0 Aug 27 08:20:27 volumio-4b volumio[852]: info: CoreCommandRouter::volumioPushState Aug 27 08:20:29 volumio-4b systemd[1]: systemd-hostnamed.service: Succeeded. Aug 27 08:20:30 volumio-4b sudo[979]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 08:20:30 volumio-4b sudo[979]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:30 volumio-4b sudo[979]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:30 volumio-4b sudo[982]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 08:20:30 volumio-4b sudo[982]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:30 volumio-4b sudo[982]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:30 volumio-4b sudo[985]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 27 08:20:30 volumio-4b sudo[985]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:30 volumio-4b systemd[1]: Started UPnP Renderer front-end to MPD. Aug 27 08:20:30 volumio-4b sudo[985]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:30 volumio-4b volumio[852]: info: Upmpdcli Daemon Started Aug 27 08:20:30 volumio-4b volumio[852]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Aug 27 08:20:34 volumio-4b volumio[852]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Aug 27 08:20:35 volumio-4b volumio-remote-updater[540]: [2024-08-27 08:20:35] [connect] Successful connection Aug 27 08:20:35 volumio-4b volumio-remote-updater[540]: [2024-08-27 08:20:35] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1724739635 101 Aug 27 08:20:35 volumio-4b volumio[852]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 3 Aug 27 08:20:40 volumio-4b volumio[852]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Aug 27 08:20:50 volumio-4b volumio[852]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Aug 27 08:20:56 volumio-4b volumio[852]: error: Plugin system_controller system failed to complete 'onVolumioStart' in a timely fashion Aug 27 08:20:56 volumio-4b volumio[852]: info: Preparing to generate the ALSA configuration file Aug 27 08:20:56 volumio-4b volumio[852]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Aug 27 08:20:56 volumio-4b volumio[852]: info: Reading ALSA contributions from plugins. Aug 27 08:20:56 volumio-4b volumio[852]: info: Asound.conf file unchanged, so no further update is needed Aug 27 08:20:56 volumio-4b volumio[852]: info: Output device has changed, restarting MPD Aug 27 08:20:56 volumio-4b sudo[989]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 27 08:20:56 volumio-4b sudo[989]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:56 volumio-4b volumio[852]: info: ___________ START PLUGINS ___________ Aug 27 08:20:56 volumio-4b sudo[989]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:56 volumio-4b volumio[852]: info: ControllerMpd::onStart: Initializing MPD Aug 27 08:20:56 volumio-4b volumio[852]: info: Creating MPD Configuration file Aug 27 08:20:56 volumio-4b sudo[991]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 27 08:20:56 volumio-4b sudo[991]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:56 volumio-4b sudo[995]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 27 08:20:56 volumio-4b sudo[995]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:56 volumio-4b sudo[995]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 08:20:56 volumio-4b volumio[852]: info: [1724739656677] CoreMusicLibrary::Adding element Serwery Mediów Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 08:20:56 volumio-4b sudo[999]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 27 08:20:56 volumio-4b sudo[999]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 08:20:56 volumio-4b volumio[852]: info: [1724739656695] CoreMusicLibrary::Adding element Last_100 Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 08:20:56 volumio-4b volumio[852]: info: [1724739656697] CoreMusicLibrary::Adding element Webradio Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 08:20:56 volumio-4b volumio[852]: info: Adding Calm Radio to Browse Sources Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 08:20:56 volumio-4b volumio[852]: info: [1724739656704] CoreMusicLibrary::Adding element Calm Radio Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Calm Radio Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 08:20:56 volumio-4b volumio[852]: info: [1724739656711] CoreMusicLibrary::Adding element Mixcloud Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Calm Radio Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Mixcloud Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 08:20:56 volumio-4b volumio[852]: info: [1724739656717] CoreMusicLibrary::Adding element SoundCloud Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Calm Radio Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Mixcloud Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source SoundCloud Aug 27 08:20:56 volumio-4b volumio[852]: info: Creating Spotify config file Aug 27 08:20:56 volumio-4b systemd[1]: Listening on mpd.socket. Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:56 volumio-4b systemd[1]: Starting Music Player Daemon... Aug 27 08:20:56 volumio-4b volumio[852]: info: Loading i18n strings for locale pl Aug 27 08:20:56 volumio-4b volumio[852]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:56 volumio-4b systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Aug 27 08:20:56 volumio-4b systemd[1]: mpd.service: Succeeded. Aug 27 08:20:56 volumio-4b volumio[852]: info: FusionDsp - mixtype--------------------- Hardware Aug 27 08:20:56 volumio-4b systemd[1]: Stopped Music Player Daemon. Aug 27 08:20:56 volumio-4b systemd[1]: Starting Music Player Daemon... Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 08:20:56 volumio-4b volumio[852]: info: [1724739656756] CoreMusicLibrary::Adding element 80s80s Radio Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Calm Radio Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Mixcloud Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source SoundCloud Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source 80s80s Radio Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 08:20:56 volumio-4b volumio[852]: info: [1724739656763] CoreMusicLibrary::Adding element RADIO 357 Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Calm Radio Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Mixcloud Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source SoundCloud Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source 80s80s Radio Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source RADIO 357 Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 08:20:56 volumio-4b volumio[852]: info: [1724739656770] CoreMusicLibrary::Adding element Radio Paradise Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Calm Radio Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Mixcloud Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source SoundCloud Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source 80s80s Radio Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source RADIO 357 Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Radio Paradise Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 08:20:56 volumio-4b volumio[852]: info: [1724739656774] CoreMusicLibrary::Adding element LastFM Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Calm Radio Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Mixcloud Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source SoundCloud Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source 80s80s Radio Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source RADIO 357 Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Radio Paradise Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source LastFM Aug 27 08:20:56 volumio-4b volumio[852]: info: [LastFM] scrobbler initiated! Aug 27 08:20:56 volumio-4b volumio[852]: info: [LastFM] extended logging: false Aug 27 08:20:56 volumio-4b volumio[852]: info: [LastFM] try scrobble stream/radio plays: true Aug 27 08:20:56 volumio-4b volumio[852]: info: [LastFM] Configuration parameters missing: "API_KEY" "API_SECRET" "username" "authToken" Aug 27 08:20:56 volumio-4b volumio[852]: info: [LastFM] Left init routine Aug 27 08:20:56 volumio-4b volumio[852]: info: [LastFM] Socket already connected: true Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 08:20:56 volumio-4b volumio[852]: info: [1724739656798] CoreMusicLibrary::Adding element Randomizer Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Calm Radio Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Mixcloud Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source SoundCloud Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source 80s80s Radio Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source RADIO 357 Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Radio Paradise Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source LastFM Aug 27 08:20:56 volumio-4b volumio[852]: Cannot find translation for source Randomizer Aug 27 08:20:56 volumio-4b volumio[852]: info: Loading i18n strings for locale pl Aug 27 08:20:56 volumio-4b volumio[852]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Aug 27 08:20:56 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 08:20:56 volumio-4b volumio[852]: info: Volumio Calling Home Aug 27 08:20:56 volumio-4b volumio[852]: info: Preparing to generate the ALSA configuration file Aug 27 08:20:56 volumio-4b volumio[852]: info: [LastFM] finished init with error: Configuration parameters missing: "API_KEY" "API_SECRET" "username" "authToken" Aug 27 08:20:56 volumio-4b sudo[1007]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Aug 27 08:20:56 volumio-4b sudo[1007]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:56 volumio-4b systemd[1]: Reloading. Aug 27 08:20:57 volumio-4b volumiologrotate[521]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Aug 27 08:20:57 volumio-4b volumiologrotate[521]: ls: cannot access '4B': No such file or directory Aug 27 08:20:57 volumio-4b volumio[852]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Aug 27 08:20:57 volumio-4b volumio[852]: info: Reading ALSA contributions from plugins. Aug 27 08:20:57 volumio-4b volumio[852]: info: MPD Permissions set Aug 27 08:20:57 volumio-4b volumio[852]: info: MPD Permissions set Aug 27 08:20:57 volumio-4b volumio[852]: info: Volumio called home Aug 27 08:20:57 volumio-4b volumio[852]: info: Spotify config file written Aug 27 08:20:57 volumio-4b volumio[852]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 4 Aug 27 08:20:57 volumio-4b volumio[852]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b sudo[1057]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 27 08:20:57 volumio-4b sudo[1057]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Aug 27 08:20:57 volumio-4b volumio[852]: info: Asound.conf file unchanged, so no further update is needed Aug 27 08:20:57 volumio-4b volumio[852]: info: Output device has changed, restarting MPD Aug 27 08:20:57 volumio-4b sudo[1072]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 27 08:20:57 volumio-4b sudo[1072]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:57 volumio-4b sudo[1072]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:57 volumio-4b sudo[1075]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 27 08:20:57 volumio-4b sudo[1075]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:57 volumio-4b volumio[852]: info: MPD Permissions set Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::volumioGetState Aug 27 08:20:57 volumio-4b volumio[852]: info: CorePlayQueue::getTrack 0 Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:57 volumio-4b sudo[1007]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:57 volumio-4b systemd[1]: Started go-librespot Daemon. Aug 27 08:20:57 volumio-4b sudo[1057]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:57 volumio-4b systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Aug 27 08:20:57 volumio-4b systemd[1]: mpd.service: Succeeded. Aug 27 08:20:57 volumio-4b go-librespot[1081]: Librespot-go daemon starting... Aug 27 08:20:57 volumio-4b systemd[1]: Stopped Music Player Daemon. Aug 27 08:20:57 volumio-4b systemd[1]: Starting Music Player Daemon... Aug 27 08:20:57 volumio-4b volumio[852]: info: touch_display: systemctl daemon-reload succeeded. Aug 27 08:20:57 volumio-4b sudo[1085]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Aug 27 08:20:57 volumio-4b sudo[1085]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:57 volumio-4b systemd[1]: Started Volumio Kiosk. Aug 27 08:20:57 volumio-4b sudo[1085]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:57 volumio-4b volumio[852]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Aug 27 08:20:57 volumio-4b volumio[852]: info: touch_display: Volumio Kiosk started Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::volumioGetState Aug 27 08:20:57 volumio-4b volumio[852]: info: CorePlayQueue::getTrack 0 Aug 27 08:20:57 volumio-4b volumio[852]: info: CoreCommandRouter::volumioGetState Aug 27 08:20:57 volumio-4b volumio[852]: info: CorePlayQueue::getTrack 0 Aug 27 08:20:57 volumio-4b volumio[852]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X Aug 27 08:20:57 volumio-4b go-librespot[1081]: time="2024-08-27T08:20:57+02:00" level=info msg="generated new device id: 9c41dfe47c6772ee4d70e97da30617117c7ee3c6" Aug 27 08:20:57 volumio-4b volumio[852]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Aug 27 08:20:57 volumio-4b startx[1091]: X.Org X Server 1.20.4 Aug 27 08:20:57 volumio-4b startx[1091]: X Protocol Version 11, Revision 0 Aug 27 08:20:57 volumio-4b startx[1091]: Build Operating System: Linux 5.4.0-109-generic armv8l Raspbian Aug 27 08:20:57 volumio-4b startx[1091]: Current Operating System: Linux volumio-4b 6.1.69-v7l+ #1710 SMP Thu Dec 21 13:17:38 GMT 2023 armv7l Aug 27 08:20:57 volumio-4b startx[1091]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 snd_bcm2835.enable_headphones=1 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=640 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 smsc95xx.macaddr=D8:3A:DD:96:09:6F vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=/dev/mmcblk0p2 imgfile=/volumio_current.sqsh rootwait bootdelay=5 elevator=noop logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 Aug 27 08:20:57 volumio-4b startx[1091]: Build Date: 04 April 2023 07:50:56AM Aug 27 08:20:57 volumio-4b startx[1091]: xorg-server 2:1.20.4-1+rpt4+deb10u9 (https://www.debian.org/support) Aug 27 08:20:57 volumio-4b startx[1091]: Current version of pixman: 0.36.0 Aug 27 08:20:57 volumio-4b startx[1091]: Before reporting problems, check http://wiki.x.org Aug 27 08:20:57 volumio-4b startx[1091]: to make sure that you have the latest version. Aug 27 08:20:57 volumio-4b startx[1091]: Markers: (--) probed, (**) from config file, (==) default setting, Aug 27 08:20:57 volumio-4b startx[1091]: (++) from command line, (!!) notice, (II) informational, Aug 27 08:20:57 volumio-4b startx[1091]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Aug 27 08:20:57 volumio-4b startx[1091]: (==) Log file: "/var/log/Xorg.0.log", Time: Tue Aug 27 08:20:57 2024 Aug 27 08:20:57 volumio-4b startx[1091]: (==) Using config directory: "/etc/X11/xorg.conf.d" Aug 27 08:20:57 volumio-4b startx[1091]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Aug 27 08:20:58 volumio-4b volumio[852]: info: CoreCommandRouter::volumioGetState Aug 27 08:20:58 volumio-4b volumio[852]: info: CorePlayQueue::getTrack 0 Aug 27 08:20:58 volumio-4b volumio[852]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Aug 27 08:20:58 volumio-4b go-librespot[1081]: time="2024-08-27T08:20:58+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 27 08:20:58 volumio-4b go-librespot[1081]: time="2024-08-27T08:20:58+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 27 08:20:58 volumio-4b go-librespot[1081]: time="2024-08-27T08:20:58+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 27 08:20:58 volumio-4b go-librespot[1081]: time="2024-08-27T08:20:58+02:00" level=debug msg="zeroconf server listening on port 37723" Aug 27 08:20:58 volumio-4b mpd[1083]: Aug 27 08:20 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 27 08:20:58 volumio-4b systemd[1]: Started Music Player Daemon. Aug 27 08:20:58 volumio-4b sudo[991]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:58 volumio-4b sudo[1075]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:58 volumio-4b sudo[999]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:58 volumio-4b volumio[852]: info: Completed starting Core Plugins Aug 27 08:20:58 volumio-4b volumio[852]: info: ------------------------------------------- Aug 27 08:20:58 volumio-4b volumio[852]: info: ----- MyVolumio plugins startup ---- Aug 27 08:20:58 volumio-4b volumio[852]: info: ------------------------------------------- Aug 27 08:20:58 volumio-4b volumio[852]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 27 08:20:58 volumio-4b volumio[852]: error: MPD error: The expression evaluated to a falsy value: Aug 27 08:20:58 volumio-4b volumio[852]: assert.ok(self.idling) Aug 27 08:20:58 volumio-4b volumio[852]: error: The expression evaluated to a falsy value: Aug 27 08:20:58 volumio-4b volumio[852]: assert.ok(self.idling) Aug 27 08:20:58 volumio-4b volumio[852]: error: MPD error: The expression evaluated to a falsy value: Aug 27 08:20:58 volumio-4b volumio[852]: assert.ok(self.idling) Aug 27 08:20:58 volumio-4b volumio[852]: error: The expression evaluated to a falsy value: Aug 27 08:20:58 volumio-4b volumio[852]: assert.ok(self.idling) Aug 27 08:20:58 volumio-4b volumio[852]: info: MPD running with PID1083 Aug 27 08:20:58 volumio-4b volumio[852]: ,establishing connection Aug 27 08:20:58 volumio-4b volumio[852]: error: MPD error: The expression evaluated to a falsy value: Aug 27 08:20:58 volumio-4b volumio[852]: assert.ok(self.idling) Aug 27 08:20:58 volumio-4b volumio[852]: error: The expression evaluated to a falsy value: Aug 27 08:20:58 volumio-4b volumio[852]: assert.ok(self.idling) Aug 27 08:20:58 volumio-4b volumio[852]: error: updateQueue error: null Aug 27 08:20:58 volumio-4b volumio[852]: info: camilladsp spawned new process with pid 1132, instance 1, run: true Aug 27 08:20:58 volumio-4b volumio[852]: info: camilladsp service started and running in background, instance 1 Aug 27 08:20:58 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 08:20:58 volumio-4b kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Aug 27 08:20:58 volumio-4b volumio[852]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 384000 <-AAAAAAAAAAAAA Aug 27 08:20:58 volumio-4b volumio[852]: info: FusionDsp loaded Aug 27 08:20:58 volumio-4b volumio[852]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 08:20:58 volumio-4b sudo[1146]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Aug 27 08:20:58 volumio-4b sudo[1146]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 08:20:58 volumio-4b volumio[852]: info: FusionDsp - Reporting Fusion DSP Enabled Aug 27 08:20:58 volumio-4b volumio[852]: info: Adding Signal Path Element [object Object] Aug 27 08:20:58 volumio-4b volumio[852]: info: Adding fusiondspeq DSP Signal Path Element Aug 27 08:20:58 volumio-4b volumio[852]: info: FusionDsp - ---- installed callbackRead Aug 27 08:20:58 volumio-4b volumio[852]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 27 08:20:58 volumio-4b volumio[852]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6 Aug 27 08:20:58 volumio-4b kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Aug 27 08:20:58 volumio-4b volumio[852]: info: FusionDsp - {"Reload":{"result":"Ok"}} Aug 27 08:20:58 volumio-4b systemd[1]: Started FusionDsp Daemon. Aug 27 08:20:59 volumio-4b sudo[1146]: pam_unix(sudo:session): session closed for user root Aug 27 08:20:59 volumio-4b volumio[852]: info: touch_display: Setting screensaver timeout to 120 seconds. Aug 27 08:21:00 volumio-4b volumio[852]: info: go-librespot daemon successfully initialized Aug 27 08:21:00 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:00+02:00" level=debug msg="obtained new client token: AAAnd150kN3jZBoRdWsfGW/VxGDXaQsBaJuh+c/4jhLgHFwVIo8/F9FHhqjTouxGeI8CIF2fxnNVfLJ/PQkYwqsoU42yQ6veXdCVICIvbfnKgScd4i2sJv+8lEn36H2xYwJv+8tke3DHPXOjKIQpdZ/5qDEi14LSoWTUyCL0gk7oWreogSC2UHgip8eQ78JpCPWbJc9GbAFw2onEdG66gNlFHJbFTGJ/Czx2foA3IN5HsQrti59X0Bi7ci6N" Aug 27 08:21:01 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:01+02:00" level=debug msg="completed keyexchange" Aug 27 08:21:01 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:01+02:00" level=debug msg="completed challenge" Aug 27 08:21:02 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:02+02:00" level=debug msg="authenticated as arturro12" Aug 27 08:21:02 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:02+02:00" level=debug msg="authenticated as arturro12" Aug 27 08:21:02 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:02+02:00" level=debug msg="dealer connection opened" Aug 27 08:21:02 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:02+02:00" level=info msg="accepted zeroconf user arturro12 from SM-G991B" Aug 27 08:21:02 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:02+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Aug 27 08:21:02 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:02+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Aug 27 08:21:02 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:02+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Aug 27 08:21:02 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:02+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Aug 27 08:21:02 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:02+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Aug 27 08:21:02 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:02+02:00" level=debug msg="received connection id: NmQ1NDhhYTItMTMwNS00ZTA5LWI3NWMtMDVkNzc3NzgyZmU4K2RlYWxlcit0Y3A6Ly8wYWNhNTg0OS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArOUJBNDZCMjI5N0RGMjk3NUQ0RTNENDg0NzlCM0RGNTI2NjE0MDdFRTk4REFBMjk5NjlERjc3QTFEQjREQzUzNQ==" Aug 27 08:21:02 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:02+02:00" level=debug msg="put connect state because NEW_DEVICE" Aug 27 08:21:02 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:02+02:00" level=debug msg="handling transfer player command from 1b12bf58bfd69707eb3c63dae4c97b63e68d8244" Aug 27 08:21:02 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:02+02:00" level=trace msg="fetched new page 0 with 25 items (list: 25)" Aug 27 08:21:02 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:02+02:00" level=debug msg="loading track spotify:track:1ILzp5O3eCNWXDtMozdoGh (paused: false, position: -105076220ms)" Aug 27 08:21:02 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:02+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 27 08:21:02 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:02+02:00" level=trace msg="emitting websocket event: will_play" Aug 27 08:21:02 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:02+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:1ILzp5O3eCNWXDtMozdoGh" Aug 27 08:21:02 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:02+02:00" level=debug msg="requested aes key for file 484430b56eadc60da5e92c4af490f6c2cc4b5ba9, gid: 1ILzp5O3eCNWXDtMozdoGh" Aug 27 08:21:03 volumio-4b volumio[852]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 27 08:21:03 volumio-4b volumio[852]: info: Initializing connection to go-librespot Websocket Aug 27 08:21:03 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:03+02:00" level=debug msg="new websocket client" Aug 27 08:21:03 volumio-4b volumio[852]: info: Connection to go-librespot Websocket established Aug 27 08:21:03 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:03+02:00" level=debug msg="fetched first chunk of 23, total size is 11972416 bytes" Aug 27 08:21:03 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:03+02:00" level=trace msg="seek to -105076220ms (diff: -105076220ms, samples: -4633861302, bytes: 0)" Aug 27 08:21:03 volumio-4b volumio[852]: info: FusionDsp - ---- read samplerate, raw: Aug 27 08:21:03 volumio-4b volumio[852]: error: FusionDsp - invalid sample rate Aug 27 08:21:03 volumio-4b volumio[852]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Aug 27 08:21:03 volumio-4b volumio[852]: info: FusionDsp - ---- read samplerate from file: 44100 Aug 27 08:21:03 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:03+02:00" level=info msg="loaded track \"Liberty\" (uri: spotify:track:1ILzp5O3eCNWXDtMozdoGh, paused: false, position: -105076220ms, duration: 344640ms)" Aug 27 08:21:03 volumio-4b volumio[852]: info: camilladsp stopping service pid 1132... Aug 27 08:21:03 volumio-4b volumio[852]: info: camilladsp service terminated, instance 1 Aug 27 08:21:03 volumio-4b volumio[852]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 27 08:21:03 volumio-4b volumio[852]: info: camilladsp service started and running in background, instance 1 Aug 27 08:21:03 volumio-4b volumio[852]: info: camilladsp spawned new process with pid 1299, instance 1, run: true Aug 27 08:21:03 volumio-4b kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Aug 27 08:21:03 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:03+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 27 08:21:03 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:03+02:00" level=trace msg="emitting websocket event: metadata" Aug 27 08:21:03 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:03+02:00" level=trace msg="emitting websocket event: active" Aug 27 08:21:03 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:03+02:00" level=debug msg="sending successful reply for delaer request" Aug 27 08:21:03 volumio-4b volumio[852]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1ILzp5O3eCNWXDtMozdoGh","name":"Liberty","artist_names":["Anette Askvik"],"album_name":"Liberty","album_cover_url":"https://i.scdn.co/image/ab67616d00001e021e393c08ddd4c0854c758400","position":-105076220,"duration":344640,"release_date":"year:2011 month:3 day:7","track_number":1,"disc_number":1}} Aug 27 08:21:03 volumio-4b volumio[852]: SPOTIFY: received: {"type":"active","data":null} Aug 27 08:21:03 volumio-4b volumio[852]: info: Aligning Spotify Volume to Volumio Volume Aug 27 08:21:03 volumio-4b volumio[852]: info: CoreCommandRouter::volumioGetState Aug 27 08:21:03 volumio-4b volumio[852]: info: CorePlayQueue::getTrack 0 Aug 27 08:21:03 volumio-4b volumio[852]: info: Setting Spotify Volume from Volumio: 100 Aug 27 08:21:04 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:04+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Aug 27 08:21:04 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:04+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Aug 27 08:21:04 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:04+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Aug 27 08:21:04 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:04+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 27 08:21:04 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:04+02:00" level=trace msg="emitting websocket event: playing" Aug 27 08:21:04 volumio-4b volumio[852]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1ILzp5O3eCNWXDtMozdoGh","play_origin":"playlist"}} Aug 27 08:21:04 volumio-4b volumio[852]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 08:21:04 volumio-4b volumio[852]: TypeError: Cannot read property 'service' of undefined Aug 27 08:21:04 volumio-4b volumio[852]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Aug 27 08:21:04 volumio-4b volumio[852]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:262:18) Aug 27 08:21:04 volumio-4b volumio[852]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Aug 27 08:21:04 volumio-4b volumio[852]: at WebSocket.emit (events.js:315:20) Aug 27 08:21:04 volumio-4b volumio[852]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1203:20) Aug 27 08:21:04 volumio-4b volumio[852]: at Receiver.emit (events.js:315:20) Aug 27 08:21:04 volumio-4b volumio[852]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:608:16 Aug 27 08:21:04 volumio-4b volumio[852]: at internal/process/task_queues.js:149:7 Aug 27 08:21:04 volumio-4b volumio[852]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) Aug 27 08:21:04 volumio-4b volumio[852]: at AsyncResource.runMicrotask (internal/process/task_queues.js:146:8) Aug 27 08:21:04 volumio-4b volumio[852]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Aug 27 08:21:04 volumio-4b volumio[852]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 08:21:04 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:04+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1359" Aug 27 08:21:04 volumio-4b go-librespot[1081]: time="2024-08-27T08:21:04+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Aug 27 08:21:04 volumio-4b sudo[1352]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-27 08:20 Aug 27 08:21:04 volumio-4b sudo[1352]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"