-- Logs begin at Fri 2024-04-05 18:10:53 -02, end at Fri 2024-04-05 18:12:03 -02. -- Apr 05 18:11:00 volumio-pi4 bluetoothd[607]: Failed to set privacy: Rejected (0x0b) Apr 05 18:11:00 volumio-pi4 systemd[1]: Started LSB: set CPUFreq kernel parameters. Apr 05 18:11:00 volumio-pi4 systemd[1]: Starting Hostname Service... Apr 05 18:11:00 volumio-pi4 dbus-daemon[465]: [system] Successfully activated service 'org.freedesktop.hostname1' Apr 05 18:11:00 volumio-pi4 systemd[1]: Started Hostname Service. Apr 05 18:11:00 volumio-pi4 nmbd[613]: [2024/04/05 18:11:00.443423, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Apr 05 18:11:00 volumio-pi4 nmbd[613]: started asyncdns process 679 Apr 05 18:11:00 volumio-pi4 nmbd[613]: [2024/04/05 18:11:00.445540, 0] ../lib/util/become_daemon.c:149(daemon_status) Apr 05 18:11:00 volumio-pi4 nmbd[613]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Apr 05 18:11:00 volumio-pi4 nmbd[613]: [2024/04/05 18:11:00.445712, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Apr 05 18:11:00 volumio-pi4 nmbd[613]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Apr 05 18:11:00 volumio-pi4 haveged[445]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Apr 05 18:11:00 volumio-pi4 haveged[445]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Apr 05 18:11:00 volumio-pi4 haveged[445]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99864 Apr 05 18:11:00 volumio-pi4 haveged[445]: haveged: fills: 0, generated: 0 Apr 05 18:11:00 volumio-pi4 ntpd[652]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Apr 05 18:11:00 volumio-pi4 wireless.js[480]: Cleaning previous... Apr 05 18:11:00 volumio-pi4 sudo[687]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 05 18:11:00 volumio-pi4 sudo[687]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:00 volumio-pi4 sudo[687]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:00 volumio-pi4 sudo[689]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 05 18:11:00 volumio-pi4 sudo[689]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:01 volumio-pi4 sudo[689]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:01 volumio-pi4 wireless.js[480]: Stopped aP Apr 05 18:11:01 volumio-pi4 sudo[696]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 05 18:11:01 volumio-pi4 sudo[696]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:01 volumio-pi4 sudo[696]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:01 volumio-pi4 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 05 18:11:01 volumio-pi4 sudo[698]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Apr 05 18:11:01 volumio-pi4 sudo[698]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:01 volumio-pi4 sudo[698]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:01 volumio-pi4 ntpd[652]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Apr 05 18:11:01 volumio-pi4 sudo[705]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 05 18:11:01 volumio-pi4 sudo[705]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:01 volumio-pi4 sudo[705]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:01 volumio-pi4 sudo[707]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Apr 05 18:11:01 volumio-pi4 sudo[707]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:01 volumio-pi4 systemd[1]: systemd-rfkill.service: Succeeded. Apr 05 18:11:02 volumio-pi4 ntpd[652]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Apr 05 18:11:03 volumio-pi4 ntpd[652]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Apr 05 18:11:03 volumio-pi4 bthelper[537]: Changing power off succeeded Apr 05 18:11:03 volumio-pi4 bthelper[537]: [CHG] Controller E4:5F:01:D5:85:BA Class: 0x0000041c Apr 05 18:11:03 volumio-pi4 bthelper[537]: Changing power on succeeded Apr 05 18:11:04 volumio-pi4 volumio-remote-updater[509]: [2024-04-05 18:11:04] [info] asio async_connect error: system:111 (Connection refused) Apr 05 18:11:04 volumio-pi4 volumio-remote-updater[509]: [2024-04-05 18:11:04] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 05 18:11:04 volumio-pi4 volumio-remote-updater[509]: [2024-04-05 18:11:04] [error] handle_connect error: Underlying Transport Error Apr 05 18:11:04 volumio-pi4 sudo[707]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:04 volumio-pi4 wireless.js[480]: SETTING APPROPRIATE REG DOMAIN: DE Apr 05 18:11:04 volumio-pi4 sudo[718]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 05 18:11:04 volumio-pi4 sudo[718]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:04 volumio-pi4 sudo[718]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:04 volumio-pi4 sudo[720]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set DE Apr 05 18:11:04 volumio-pi4 sudo[720]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:04 volumio-pi4 sudo[720]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:04 volumio-pi4 wireless.js[480]: SUCCESSFULLY SET NEW REGDOMAIN: DE Apr 05 18:11:04 volumio-pi4 wireless.js[480]: Start wireless flow Apr 05 18:11:04 volumio-pi4 wireless.js[480]: Stopped hotspot (if there).. Apr 05 18:11:04 volumio-pi4 sudo[725]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 05 18:11:04 volumio-pi4 sudo[725]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:04 volumio-pi4 sudo[725]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:04 volumio-pi4 sudo[727]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 05 18:11:04 volumio-pi4 sudo[727]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:04 volumio-pi4 sudo[727]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:04 volumio-pi4 wireless.js[480]: DHCP IP Apr 05 18:11:04 volumio-pi4 wireless.js[480]: Start ap Apr 05 18:11:04 volumio-pi4 wpa_supplicant[729]: Successfully initialized wpa_supplicant Apr 05 18:11:04 volumio-pi4 sudo[730]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Apr 05 18:11:04 volumio-pi4 sudo[730]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:04 volumio-pi4 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 05 18:11:04 volumio-pi4 dhcpcd[731]: dev: loaded udev Apr 05 18:11:05 volumio-pi4 dhcpcd-run-hooks[749]: wlan0: starting wpa_supplicant Apr 05 18:11:05 volumio-pi4 dhcpcd-run-hooks[754]: wlan0: failed to start wpa_supplicant Apr 05 18:11:05 volumio-pi4 dhcpcd-run-hooks[755]: 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 Apr 05 18:11:05 volumio-pi4 dhcpcd[731]: wlan0: connected to Access Point `' Apr 05 18:11:05 volumio-pi4 dhcpcd[731]: no interfaces have a carrier Apr 05 18:11:05 volumio-pi4 dhcpcd[731]: forked to background, child pid 765 Apr 05 18:11:05 volumio-pi4 dhcpcd[765]: eth0: waiting for carrier Apr 05 18:11:05 volumio-pi4 dhcpcd[765]: wlan0: waiting for carrier Apr 05 18:11:05 volumio-pi4 sudo[730]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:05 volumio-pi4 wireless.js[480]: trying... Apr 05 18:11:05 volumio-pi4 sudo[767]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 05 18:11:05 volumio-pi4 sudo[767]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:05 volumio-pi4 sudo[767]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:06 volumio-pi4 wireless.js[480]: trying... Apr 05 18:11:06 volumio-pi4 sudo[770]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 05 18:11:06 volumio-pi4 sudo[770]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:06 volumio-pi4 sudo[770]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:07 volumio-pi4 wpa_supplicant[753]: wlan0: Trying to associate with SSID 'FRITZ!Box RD' Apr 05 18:11:07 volumio-pi4 wireless.js[480]: trying... Apr 05 18:11:07 volumio-pi4 sudo[773]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 05 18:11:07 volumio-pi4 sudo[773]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:07 volumio-pi4 sudo[773]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:08 volumio-pi4 wireless.js[480]: trying... Apr 05 18:11:08 volumio-pi4 sudo[776]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 05 18:11:08 volumio-pi4 sudo[776]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:08 volumio-pi4 sudo[776]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:09 volumio-pi4 wireless.js[480]: trying... Apr 05 18:11:09 volumio-pi4 sudo[779]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 05 18:11:09 volumio-pi4 sudo[779]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:09 volumio-pi4 sudo[779]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: wlan0: carrier acquired Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: wlan0: connected to Access Point `FRITZ!Box RD' Apr 05 18:11:10 volumio-pi4 wpa_supplicant[753]: wlan0: Associated with 5c:49:79:dc:da:b5 Apr 05 18:11:10 volumio-pi4 wpa_supplicant[753]: wlan0: CTRL-EVENT-CONNECTED - Connection to 5c:49:79:dc:da:b5 completed [id=0 id_str=] Apr 05 18:11:10 volumio-pi4 wpa_supplicant[753]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Apr 05 18:11:10 volumio-pi4 wpa_supplicant[753]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: DUID 00:01:00:01:29:d8:62:59:b8:27:eb:ec:94:ba Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: wlan0: IAID 01:d5:85:b9 Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: wlan0: adding address fe80::5607:7467:a774:304d Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: ipv6_addaddr1: Permission denied Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: wlan0: carrier lost Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: wlan0: carrier acquired Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: wlan0: IAID 01:d5:85:b9 Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: wlan0: soliciting an IPv6 router Apr 05 18:11:10 volumio-pi4 wireless.js[480]: trying... Apr 05 18:11:10 volumio-pi4 dhcpcd[765]: wlan0: rebinding lease of 192.168.111.78 Apr 05 18:11:10 volumio-pi4 sudo[794]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 05 18:11:10 volumio-pi4 sudo[794]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:10 volumio-pi4 sudo[794]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:11 volumio-pi4 dhcpcd[765]: wlan0: probing address 192.168.111.78/24 Apr 05 18:11:11 volumio-pi4 volumio-remote-updater[509]: [2024-04-05 18:11:11] [info] asio async_connect error: system:111 (Connection refused) Apr 05 18:11:11 volumio-pi4 volumio-remote-updater[509]: [2024-04-05 18:11:11] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 05 18:11:11 volumio-pi4 volumio-remote-updater[509]: [2024-04-05 18:11:11] [error] handle_connect error: Underlying Transport Error Apr 05 18:11:11 volumio-pi4 wireless.js[480]: trying... Apr 05 18:11:11 volumio-pi4 sudo[797]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 05 18:11:11 volumio-pi4 sudo[797]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:11 volumio-pi4 sudo[797]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:12 volumio-pi4 wireless.js[480]: trying... Apr 05 18:11:12 volumio-pi4 sudo[800]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 05 18:11:12 volumio-pi4 sudo[800]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:12 volumio-pi4 sudo[800]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:13 volumio-pi4 wireless.js[480]: trying... Apr 05 18:11:13 volumio-pi4 sudo[803]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 05 18:11:13 volumio-pi4 sudo[803]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:13 volumio-pi4 sudo[803]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:14 volumio-pi4 wireless.js[480]: trying... Apr 05 18:11:14 volumio-pi4 sudo[806]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 05 18:11:14 volumio-pi4 sudo[806]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:14 volumio-pi4 sudo[806]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:15 volumio-pi4 wireless.js[480]: trying... Apr 05 18:11:15 volumio-pi4 sudo[809]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 05 18:11:15 volumio-pi4 sudo[809]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:15 volumio-pi4 sudo[809]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:16 volumio-pi4 dhcpcd[765]: wlan0: leased 192.168.111.78 for 864000 seconds Apr 05 18:11:16 volumio-pi4 avahi-daemon[490]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.111.78. Apr 05 18:11:16 volumio-pi4 avahi-daemon[490]: New relevant interface wlan0.IPv4 for mDNS. Apr 05 18:11:16 volumio-pi4 dhcpcd[765]: wlan0: adding route to 192.168.111.0/24 Apr 05 18:11:16 volumio-pi4 avahi-daemon[490]: Registering new address record for 192.168.111.78 on wlan0.IPv4. Apr 05 18:11:16 volumio-pi4 dhcpcd[765]: wlan0: adding default route via 192.168.111.1 Apr 05 18:11:16 volumio-pi4 wireless.js[480]: trying... Apr 05 18:11:16 volumio-pi4 sudo[833]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 05 18:11:16 volumio-pi4 sudo[833]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:16 volumio-pi4 sudo[833]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:16 volumio-pi4 wireless.js[480]: Connected to: ----FRITZ!Box RD Apr 05 18:11:16 volumio-pi4 wireless.js[480]: ---- Apr 05 18:11:16 volumio-pi4 sudo[836]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 05 18:11:16 volumio-pi4 sudo[836]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:16 volumio-pi4 sudo[836]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:16 volumio-pi4 wireless.js[480]: ... joined AP, wlan0 IPv4 is 192.168.111.78, ipV6 is undefined Apr 05 18:11:16 volumio-pi4 wireless.js[480]: It's done! AP Apr 05 18:11:17 volumio-pi4 systemd[1]: Started Wireless Services. Apr 05 18:11:17 volumio-pi4 systemd[1]: Started Volumio Backend Module. Apr 05 18:11:17 volumio-pi4 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 05 18:11:17 volumio-pi4 systemd[1]: Started Volumio Cpu Tweaker. Apr 05 18:11:17 volumio-pi4 volumio-cpu-tweak[842]: Setting RT Priority for mpd Apr 05 18:11:17 volumio-pi4 volumio-cpu-tweak[842]: pid 35's current scheduling policy: SCHED_OTHER Apr 05 18:11:17 volumio-pi4 volumio-cpu-tweak[842]: pid 35's current scheduling priority: 0 Apr 05 18:11:17 volumio-pi4 volumio-cpu-tweak[842]: Setting MPD Affinity Apr 05 18:11:17 volumio-pi4 volumio-cpu-tweak[842]: pid 3's current affinity mask: f Apr 05 18:11:17 volumio-pi4 volumio-cpu-tweak[842]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Apr 05 18:11:17 volumio-pi4 volumio-cpu-tweak[842]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Apr 05 18:11:17 volumio-pi4 systemd[1]: volumio_cpu_tweak.service: Succeeded. Apr 05 18:11:17 volumio-pi4 ntpd[652]: Listen normally on 3 wlan0 192.168.111.78:123 Apr 05 18:11:17 volumio-pi4 ntpd[652]: new interface(s) found: waking up resolver Apr 05 18:11:18 volumio-pi4 volumio[841]: info: ------------------------------------------- Apr 05 18:11:18 volumio-pi4 volumio[841]: info: ----- Volumio3 ---- Apr 05 18:11:18 volumio-pi4 volumio[841]: info: ------------------------------------------- Apr 05 18:11:18 volumio-pi4 volumio[841]: info: ----- System startup ---- Apr 05 18:11:18 volumio-pi4 volumio[841]: info: ------------------------------------------- Apr 05 18:11:19 volumio-pi4 volumio[841]: info: MYVOLUMIO Environment detected Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Plugin folders cleanup Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning into folder /volumio/app/plugins/ Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning category audio_interface Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning category miscellanea Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning category music_service Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning category plugins.json Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning category system_controller Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning category user_interface Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning into folder /data/plugins/ Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning category audio_interface Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Scanning category music_service Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Plugin folders cleanup completed Apr 05 18:11:19 volumio-pi4 volumio[841]: info: ------------------------------------------- Apr 05 18:11:19 volumio-pi4 volumio[841]: info: ----- Core plugins startup ---- Apr 05 18:11:19 volumio-pi4 volumio[841]: info: ------------------------------------------- Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Loading plugins from folder /volumio/app/plugins/ Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Adding plugin upnp to MyMusic Plugins Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Loading plugins from folder /data/plugins/ Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Loading plugin "system"... Apr 05 18:11:19 volumio-pi4 volumio[841]: info: Loading plugin "appearance"... Apr 05 18:11:20 volumio-pi4 nmbd[613]: [2024/04/05 18:11:20.450719, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 05 18:11:20 volumio-pi4 systemd[1]: Started Samba NMB Daemon. Apr 05 18:11:20 volumio-pi4 nmbd[613]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Apr 05 18:11:20 volumio-pi4 systemd[1]: Starting Samba Winbind Daemon... Apr 05 18:11:20 volumio-pi4 winbindd[871]: [2024/04/05 18:11:20.753353, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Apr 05 18:11:20 volumio-pi4 winbindd[871]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Apr 05 18:11:20 volumio-pi4 volumio[841]: info: Loading plugin "network"... Apr 05 18:11:20 volumio-pi4 winbindd[871]: [2024/04/05 18:11:20.785129, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 05 18:11:20 volumio-pi4 systemd[1]: Started Samba Winbind Daemon. Apr 05 18:11:20 volumio-pi4 winbindd[871]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Apr 05 18:11:20 volumio-pi4 volumio[841]: info: Refreshing Cached IP Addresses Apr 05 18:11:20 volumio-pi4 sudo[877]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 05 18:11:20 volumio-pi4 sudo[877]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:20 volumio-pi4 volumio[841]: info: Loading plugin "services"... Apr 05 18:11:20 volumio-pi4 volumio[841]: info: Loading plugin "alsa_controller"... Apr 05 18:11:20 volumio-pi4 sudo[877]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:20 volumio-pi4 sudo[879]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 05 18:11:20 volumio-pi4 sudo[879]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:20 volumio-pi4 systemd[1]: Starting Samba SMB Daemon... Apr 05 18:11:20 volumio-pi4 sudo[879]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:20 volumio-pi4 sudo[882]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 05 18:11:20 volumio-pi4 sudo[882]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:20 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 05 18:11:20 volumio-pi4 volumio[841]: info: Loading plugin "wizard"... Apr 05 18:11:20 volumio-pi4 volumio[841]: info: Loading plugin "networkfs"... Apr 05 18:11:20 volumio-pi4 volumio[841]: info: Starting Udev Watcher for removable devices Apr 05 18:11:20 volumio-pi4 sudo[889]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.111.55/Media /mnt/NAS/Media Apr 05 18:11:20 volumio-pi4 sudo[889]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Ignoring mount for partition: boot Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Ignoring mount for partition: volumio Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Ignoring mount for partition: volumio_data Apr 05 18:11:21 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "volumio_command_line_client"... Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "upnp"... Apr 05 18:11:21 volumio-pi4 volumio[841]: info: [1712347881042] Starting Upmpd Daemon Apr 05 18:11:21 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "my_music"... Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "mpd"... Apr 05 18:11:21 volumio-pi4 kernel: Key type cifs.spnego registered Apr 05 18:11:21 volumio-pi4 kernel: Key type cifs.idmap registered Apr 05 18:11:21 volumio-pi4 kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Apr 05 18:11:21 volumio-pi4 kernel: CIFS: Attempting to mount \\192.168.111.55\Media Apr 05 18:11:21 volumio-pi4 systemd[1]: Started Samba SMB Daemon. Apr 05 18:11:21 volumio-pi4 systemd[1]: Reached target Multi-User System. Apr 05 18:11:21 volumio-pi4 smbd[884]: [2024/04/05 18:11:21.218737, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 05 18:11:21 volumio-pi4 systemd[1]: Reached target Graphical Interface. Apr 05 18:11:21 volumio-pi4 smbd[884]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Apr 05 18:11:21 volumio-pi4 systemd[1]: Starting Update UTMP about System Runlevel Changes... Apr 05 18:11:21 volumio-pi4 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Apr 05 18:11:21 volumio-pi4 systemd[1]: Started Update UTMP about System Runlevel Changes. Apr 05 18:11:21 volumio-pi4 systemd[1]: Startup finished in 9.735s (kernel) + 30.111s (userspace) = 39.846s. Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "upnp_browser"... Apr 05 18:11:21 volumio-pi4 sudo[889]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:21 volumio-pi4 volumio-remote-updater[509]: [2024-04-05 18:11:21] [connect] Successful connection Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "alarm-clock"... Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Plugin airplay_emulation is not enabled Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "last_100"... Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "webradio"... Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "i2s_dacs"... Apr 05 18:11:21 volumio-pi4 volumio[841]: info: Loading plugin "volumiodiscovery"... Apr 05 18:11:22 volumio-pi4 volumio[841]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 05 18:11:22 volumio-pi4 volumio[841]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 05 18:11:22 volumio-pi4 node[841]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 05 18:11:22 volumio-pi4 volumio[841]: *** WARNING *** For more information see Apr 05 18:11:22 volumio-pi4 volumio[841]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 05 18:11:22 volumio-pi4 volumio[841]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 05 18:11:22 volumio-pi4 volumio[841]: *** WARNING *** For more information see Apr 05 18:11:22 volumio-pi4 node[841]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 05 18:11:22 volumio-pi4 node[841]: *** WARNING *** For more information see Apr 05 18:11:22 volumio-pi4 node[841]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 05 18:11:22 volumio-pi4 node[841]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 05 18:11:22 volumio-pi4 node[841]: *** WARNING *** For more information see Apr 05 18:11:22 volumio-pi4 volumio[841]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 05 18:11:22 volumio-pi4 volumio[841]: info: Discovery: Started advertising with name: Volumio PI4 Apr 05 18:11:22 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 05 18:11:22 volumio-pi4 volumio[841]: info: Loading plugin "mixcloud"... Apr 05 18:11:22 volumio-pi4 volumio[841]: info: Loading plugin "spop"... Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Loading plugin "outputs"... Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Loading plugin "albumart"... Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Plugin example_plugin is not enabled Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Loading plugin "inputs"... Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Loading plugin "updater_comm"... Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Plugin mpdemulation is not enabled Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Loading plugin "rest_api"... Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Loading plugin "websocket"... Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Loading plugin "fusiondsp"... Apr 05 18:11:23 volumio-pi4 volumio[841]: Forking 3 albumart workers Apr 05 18:11:23 volumio-pi4 volumio[841]: info: Applying required configuration parameters for plugin fusiondsp Apr 05 18:11:24 volumio-pi4 volumio[841]: info: Plugin minidlna is not enabled Apr 05 18:11:24 volumio-pi4 volumio[841]: info: Loading plugin "podcast"... Apr 05 18:11:24 volumio-pi4 volumio[841]: Starting albumart workers Apr 05 18:11:24 volumio-pi4 volumio[841]: Starting albumart workers Apr 05 18:11:24 volumio-pi4 volumio[841]: Starting albumart workers Apr 05 18:11:24 volumio-pi4 volumio[841]: info: ControllerPodcast::constructor Apr 05 18:11:24 volumio-pi4 volumio[841]: info: Loading i18n strings for locale de Apr 05 18:11:24 volumio-pi4 sudo[882]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:24 volumio-pi4 volumio[841]: Updating browse sources language Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::initPlayerControls Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 05 18:11:24 volumio-pi4 volumio[841]: Express server listening on port 3000 Apr 05 18:11:24 volumio-pi4 volumio[841]: [Metrics] WebUI: 6s 545.66ms Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreStateMachine::resetVolumioState Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreStateMachine::getcurrentVolume Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioRetrievevolume Apr 05 18:11:24 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 1 Apr 05 18:11:24 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 2 Apr 05 18:11:24 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 3 Apr 05 18:11:24 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 4 Apr 05 18:11:24 volumio-pi4 volumio-remote-updater[509]: [2024-04-05 18:11:24] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1712347881 101 Apr 05 18:11:24 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 5 Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreStateMachine::pushState Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0 Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioPushState Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreStateMachine::updateTrackBlock Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrackBlock Apr 05 18:11:24 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioRetrievevolume Apr 05 18:11:25 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 6 Apr 05 18:11:25 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 7 Apr 05 18:11:25 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 8 Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 05 18:11:25 volumio-pi4 volumio[841]: info: Reloading queue from file Apr 05 18:11:25 volumio-pi4 volumio[841]: info: Setting Device type: Raspberry PI Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreStateMachine::setRepeat true single undefined Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreStateMachine::pushState Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0 Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioPushState Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreStateMachine::setRandom true Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreStateMachine::pushState Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0 Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioPushState Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreStateMachine::pushState Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0 Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioPushState Apr 05 18:11:25 volumio-pi4 volumio[841]: info: Discovery: adding d9036297-85a0-4406-a0ff-51b00fe556bf Apr 05 18:11:25 volumio-pi4 volumio[841]: info: Discovery: Found device Volumio PI4 Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState Apr 05 18:11:25 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0 Apr 05 18:11:25 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 9 Apr 05 18:11:27 volumio-pi4 systemd[1]: systemd-fsckd.service: Succeeded. Apr 05 18:11:27 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 10 Apr 05 18:11:28 volumio-pi4 sh[409]: timed out Apr 05 18:11:28 volumio-pi4 dhcpcd[450]: timed out Apr 05 18:11:28 volumio-pi4 sh[409]: dhcpcd exited Apr 05 18:11:28 volumio-pi4 dhcpcd[450]: dhcpcd exited Apr 05 18:11:28 volumio-pi4 sh[409]: ifup: failed to bring up eth0 Apr 05 18:11:28 volumio-pi4 systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Apr 05 18:11:28 volumio-pi4 systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Apr 05 18:11:30 volumio-pi4 systemd[1]: systemd-hostnamed.service: Succeeded. Apr 05 18:11:31 volumio-pi4 sudo[1000]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 05 18:11:31 volumio-pi4 sudo[1000]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:31 volumio-pi4 sudo[1000]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:31 volumio-pi4 sudo[1002]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 05 18:11:31 volumio-pi4 sudo[1002]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:31 volumio-pi4 sudo[1002]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:31 volumio-pi4 sudo[1006]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 05 18:11:31 volumio-pi4 sudo[1006]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:31 volumio-pi4 systemd[1]: Started UPnP Renderer front-end to MPD. Apr 05 18:11:31 volumio-pi4 sudo[1006]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:31 volumio-pi4 volumio[841]: info: Upmpdcli Daemon Started Apr 05 18:11:31 volumio-pi4 volumio[841]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Apr 05 18:11:35 volumio-pi4 volumio[841]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Apr 05 18:11:41 volumio-pi4 volumio[841]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Apr 05 18:11:46 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 05 18:11:46 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 05 18:11:46 volumio-pi4 volumio[841]: info: Discovery: Getting this device information Apr 05 18:11:46 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState Apr 05 18:11:46 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0 Apr 05 18:11:46 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 05 18:11:50 volumio-pi4 sudo[1010]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 05 18:11:50 volumio-pi4 sudo[1010]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:50 volumio-pi4 sudo[1010]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:50 volumio-pi4 sudo[1012]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 05 18:11:50 volumio-pi4 sudo[1012]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:50 volumio-pi4 sudo[1012]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:50 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 11 Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetVisibleSources Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0 Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 05 18:11:50 volumio-pi4 volumio[841]: info: Received Get System Info Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 05 18:11:50 volumio-pi4 volumio[841]: info: Discovery: Getting this device information Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0 Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0 Apr 05 18:11:50 volumio-pi4 volumio[841]: info: Listing playlists Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 05 18:11:50 volumio-pi4 volumio[841]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 05 18:11:51 volumio-pi4 volumio[841]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Apr 05 18:11:51 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to 192.168.111.78 from 192.168.111.22 UA: unknown Total Clients: 12 Apr 05 18:11:51 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState Apr 05 18:11:51 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0 Apr 05 18:11:51 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 05 18:11:51 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 05 18:11:52 volumio-pi4 volumio[841]: info: Received Get System Info Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 05 18:11:52 volumio-pi4 volumio[841]: info: Discovery: Getting this device information Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0 Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 05 18:11:52 volumio-pi4 volumio[841]: info: Received Get System Info Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 05 18:11:52 volumio-pi4 volumio[841]: info: Discovery: Getting this device information Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0 Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Apr 05 18:11:52 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Apr 05 18:11:53 volumio-pi4 wpa_supplicant[753]: RRM: Ignoring radio measurement request: Not RRM network Apr 05 18:11:54 volumio-pi4 volumio[841]: error: Plugin system_controller system failed to complete 'onVolumioStart' in a timely fashion Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Preparing to generate the ALSA configuration file Apr 05 18:11:54 volumio-pi4 volumio[841]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Apr 05 18:11:54 volumio-pi4 volumio[841]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Reading ALSA contributions from plugins. Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Asound.conf file unchanged, so no further update is needed Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Output device has changed, restarting MPD Apr 05 18:11:54 volumio-pi4 sudo[1016]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 05 18:11:54 volumio-pi4 sudo[1016]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:54 volumio-pi4 volumio[841]: info: ___________ START PLUGINS ___________ Apr 05 18:11:54 volumio-pi4 volumio[841]: info: ControllerMpd::onStart: Initializing MPD Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Creating MPD Configuration file Apr 05 18:11:54 volumio-pi4 sudo[1016]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:54 volumio-pi4 sudo[1018]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 05 18:11:54 volumio-pi4 sudo[1018]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:54 volumio-pi4 sudo[1022]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 05 18:11:54 volumio-pi4 sudo[1022]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 05 18:11:54 volumio-pi4 volumio[841]: info: [1712347914595] CoreMusicLibrary::Adding element Medienserver Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 05 18:11:54 volumio-pi4 sudo[1022]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:54 volumio-pi4 sudo[1024]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 05 18:11:54 volumio-pi4 sudo[1024]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 05 18:11:54 volumio-pi4 volumio[841]: info: [1712347914620] CoreMusicLibrary::Adding element Last_100 Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 05 18:11:54 volumio-pi4 volumio[841]: info: [1712347914622] CoreMusicLibrary::Adding element Webradio Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 05 18:11:54 volumio-pi4 volumio[841]: info: [1712347914634] CoreMusicLibrary::Adding element Mixcloud Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 05 18:11:54 volumio-pi4 volumio[841]: Cannot find translation for source Mixcloud Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Creating Spotify config file Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Loading i18n strings for locale de Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: FusionDsp - mixtype--------------------- Software Apr 05 18:11:54 volumio-pi4 systemd[1]: Listening on mpd.socket. Apr 05 18:11:54 volumio-pi4 systemd[1]: Starting Music Player Daemon... Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 05 18:11:54 volumio-pi4 volumio[841]: info: [1712347914669] CoreMusicLibrary::Adding element Podcast Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 05 18:11:54 volumio-pi4 volumio[841]: Cannot find translation for source Mixcloud Apr 05 18:11:54 volumio-pi4 volumio[841]: Cannot find translation for source Podcast Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Volumio Calling Home Apr 05 18:11:54 volumio-pi4 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 05 18:11:54 volumio-pi4 systemd[1]: mpd.service: Succeeded. Apr 05 18:11:54 volumio-pi4 systemd[1]: Stopped Music Player Daemon. Apr 05 18:11:54 volumio-pi4 systemd[1]: Starting Music Player Daemon... Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Preparing to generate the ALSA configuration file Apr 05 18:11:54 volumio-pi4 volumio[841]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Apr 05 18:11:54 volumio-pi4 volumio[841]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Reading ALSA contributions from plugins. Apr 05 18:11:54 volumio-pi4 volumio[841]: info: MPD Permissions set Apr 05 18:11:54 volumio-pi4 volumio[841]: info: MPD Permissions set Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Volumio called home Apr 05 18:11:54 volumio-pi4 volumio[841]: info: Spotify config file written Apr 05 18:11:54 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 13 Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 sudo[1034]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 05 18:11:54 volumio-pi4 sudo[1034]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 05 18:11:54 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:54 volumio-pi4 systemd[1]: Started go-librespot Daemon. Apr 05 18:11:55 volumio-pi4 go-librespot[1044]: Librespot-go daemon starting... Apr 05 18:11:55 volumio-pi4 sudo[1034]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:55 volumio-pi4 volumio[841]: info: Asound.conf file unchanged, so no further update is needed Apr 05 18:11:55 volumio-pi4 volumio[841]: info: Output device has changed, restarting MPD Apr 05 18:11:55 volumio-pi4 sudo[1047]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 05 18:11:55 volumio-pi4 sudo[1047]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:55 volumio-pi4 sudo[1047]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:55 volumio-pi4 sudo[1049]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 05 18:11:55 volumio-pi4 sudo[1049]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:55 volumio-pi4 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 05 18:11:55 volumio-pi4 systemd[1]: mpd.service: Succeeded. Apr 05 18:11:55 volumio-pi4 systemd[1]: Stopped Music Player Daemon. Apr 05 18:11:55 volumio-pi4 systemd[1]: Starting Music Player Daemon... Apr 05 18:11:55 volumio-pi4 volumio[841]: info: MPD Permissions set Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0 Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 05 18:11:55 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:55 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:11:55-02:00" level=info msg="generated new device id: fdf24893e1bc91a172217684aa3dfc7c1f562b28" Apr 05 18:11:55 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:11:55-02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 05 18:11:55 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:11:55-02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 05 18:11:55 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:11:55-02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 05 18:11:55 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:11:55-02:00" level=debug msg="zeroconf server listening on port 44215" Apr 05 18:11:56 volumio-pi4 mpd[1052]: Apr 05 18:11 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 05 18:11:56 volumio-pi4 systemd[1]: Started Music Player Daemon. Apr 05 18:11:56 volumio-pi4 sudo[1049]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:56 volumio-pi4 sudo[1018]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:56 volumio-pi4 sudo[1024]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:56 volumio-pi4 volumio[841]: info: Completed starting Core Plugins Apr 05 18:11:56 volumio-pi4 volumio[841]: info: ------------------------------------------- Apr 05 18:11:56 volumio-pi4 volumio[841]: info: ----- MyVolumio plugins startup ---- Apr 05 18:11:56 volumio-pi4 volumio[841]: info: ------------------------------------------- Apr 05 18:11:56 volumio-pi4 volumio[841]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 05 18:11:56 volumio-pi4 volumio[841]: error: MPD error: The expression evaluated to a falsy value: Apr 05 18:11:56 volumio-pi4 volumio[841]: assert.ok(self.idling) Apr 05 18:11:56 volumio-pi4 volumio[841]: error: The expression evaluated to a falsy value: Apr 05 18:11:56 volumio-pi4 volumio[841]: assert.ok(self.idling) Apr 05 18:11:56 volumio-pi4 volumio[841]: error: MPD error: The expression evaluated to a falsy value: Apr 05 18:11:56 volumio-pi4 volumio[841]: assert.ok(self.idling) Apr 05 18:11:56 volumio-pi4 volumio[841]: error: The expression evaluated to a falsy value: Apr 05 18:11:56 volumio-pi4 volumio[841]: assert.ok(self.idling) Apr 05 18:11:56 volumio-pi4 volumio[841]: info: MPD running with PID1052 Apr 05 18:11:56 volumio-pi4 volumio[841]: ,establishing connection Apr 05 18:11:56 volumio-pi4 volumio[841]: error: updateQueue error: null Apr 05 18:11:56 volumio-pi4 volumio[841]: error: updateQueue error: null Apr 05 18:11:56 volumio-pi4 volumio[841]: info: camilladsp spawned new process with pid 1073, instance 1, run: true Apr 05 18:11:56 volumio-pi4 volumio[841]: info: camilladsp service started and running in background, instance 1 Apr 05 18:11:56 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 05 18:11:56 volumio-pi4 kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 05 18:11:56 volumio-pi4 volumio[841]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 384000 <-AAAAAAAAAAAAA Apr 05 18:11:56 volumio-pi4 volumio[841]: info: FusionDsp loaded Apr 05 18:11:56 volumio-pi4 volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 05 18:11:56 volumio-pi4 sudo[1077]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Apr 05 18:11:56 volumio-pi4 sudo[1077]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 05 18:11:56 volumio-pi4 volumio[841]: info: FusionDsp - Reporting Fusion DSP Enabled Apr 05 18:11:56 volumio-pi4 volumio[841]: info: Adding Signal Path Element [object Object] Apr 05 18:11:56 volumio-pi4 volumio[841]: info: Adding fusiondspeq DSP Signal Path Element Apr 05 18:11:56 volumio-pi4 volumio[841]: info: FusionDsp - ---- installed callbackRead Apr 05 18:11:56 volumio-pi4 volumio[841]: info: FusionDsp - If filter freq >samplerate/2 then disable it Apr 05 18:11:56 volumio-pi4 volumio[841]: info: FusionDsp - Effects disabled Apr 05 18:11:56 volumio-pi4 volumio[841]: error: FusionDsp - WebSocket error: [object Object] Apr 05 18:11:56 volumio-pi4 volumio[841]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 14 Apr 05 18:11:56 volumio-pi4 kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 05 18:11:56 volumio-pi4 systemd[1]: Started FusionDsp Daemon. Apr 05 18:11:56 volumio-pi4 sudo[1077]: pam_unix(sudo:session): session closed for user root Apr 05 18:11:58 volumio-pi4 volumio[841]: info: go-librespot daemon successfully initialized Apr 05 18:11:58 volumio-pi4 volumiologrotate[484]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Apr 05 18:11:58 volumio-pi4 volumiologrotate[484]: ls: cannot access 'PI4': No such file or directory Apr 05 18:12:00 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:00-02:00" level=debug msg="obtained new client token: AABp9VrhSqzumJhkAcyJtlBrWgtAf10mPdEx+iydP1p73v/2hNq/znBl7oYzdkX7n80CSFRgkOVKYigxLSf2JESlhbcpC0RcbJOK9vpkGmi/94LQCX/1CHd5AwyBYi4xXV4va4fGThfkonXDozZbU+BlEX1AY6UxS29eLMIIshElX1/sl6qEQJmUMu6YIKShNqMvsut7yPqfRsHinZs+W3iYH7RmhlZQkHGBmP842ZXp8T1msLgHUHLZK5AWGw==" Apr 05 18:12:00 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:00-02:00" level=debug msg="completed keyexchange" Apr 05 18:12:01 volumio-pi4 volumio[841]: info: Initializing connection to go-librespot Websocket Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="new websocket client" Apr 05 18:12:01 volumio-pi4 volumio[841]: info: Connection to go-librespot Websocket established Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="completed challenge" Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="authenticated as 3gur3xe35s7qop2giwk9bklfz" Apr 05 18:12:01 volumio-pi4 volumio[841]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="authenticated as 3gur3xe35s7qop2giwk9bklfz" Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="dealer connection opened" Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=info msg="accepted zeroconf user 3gur3xe35s7qop2giwk9bklfz from iPhone" Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="received connection id: NjcwZjM1MTQtZTBlMy00Njg4LWJmZDAtMmFjMDM5ZDY1NTVmK2RlYWxlcit0Y3A6Ly9nZXc0LWRlYWxlci1hLWtwMzEuZ2V3NC5zcG90aWZ5Lm5ldDo1NzAwK0RCNTM3MEQ2MTkzQUIwOTU4RkM2QzE2RkVFMkU0NjZEREU1OEYyMUFCOThBRDZFNUNENDkyRjQ0Q0ZCNjUwNTA=" Apr 05 18:12:01 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:01-02:00" level=debug msg="put connect state because NEW_DEVICE" Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="handling transfer player command from da2907fe9749dbf2065e93d59bf9bdf1373d5912" Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=trace msg="fetched new page 0 with 81 items (list: 81)" Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="loading track spotify:track:09t5pNK7TPmboRJb69I1y6 (paused: true, position: 19571ms)" Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=trace msg="emitting websocket event: will_play" Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:09t5pNK7TPmboRJb69I1y6" Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="requested aes key for file 0d6179886af0687bf27c21c8776a7fae74c4177f, gid: 09t5pNK7TPmboRJb69I1y6" Apr 05 18:12:02 volumio-pi4 volumio[841]: Cannot compose Albumart path Apr 05 18:12:02 volumio-pi4 volumio[841]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:09t5pNK7TPmboRJb69I1y6","play_origin":"playlist/ondemand"}} Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="fetched first chunk of 34, total size is 17384660 bytes" Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="fetched chunk 1/33, size: 524288" Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=trace msg="seek to 19571ms (diff: 202ms, samples: 863081, bytes: 812749)" Apr 05 18:12:02 volumio-pi4 volumio[841]: info: FusionDsp - ---- read samplerate, raw: Apr 05 18:12:02 volumio-pi4 volumio[841]: error: FusionDsp - invalid sample rate Apr 05 18:12:02 volumio-pi4 volumio[841]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Apr 05 18:12:02 volumio-pi4 volumio[841]: info: FusionDsp - ---- read samplerate from file: 44100 Apr 05 18:12:02 volumio-pi4 volumio[841]: info: camilladsp stopping service pid 1073... Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=info msg="loaded track \"Graf Twerk\" (uri: spotify:track:09t5pNK7TPmboRJb69I1y6, paused: true, position: 19571ms, duration: 413386ms)" Apr 05 18:12:02 volumio-pi4 volumio[841]: info: camilladsp service terminated, instance 1 Apr 05 18:12:02 volumio-pi4 volumio[841]: info: FusionDsp - If filter freq >samplerate/2 then disable it Apr 05 18:12:02 volumio-pi4 volumio[841]: info: FusionDsp - Effects disabled Apr 05 18:12:02 volumio-pi4 volumio[841]: info: camilladsp service started and running in background, instance 1 Apr 05 18:12:02 volumio-pi4 volumio[841]: info: camilladsp spawned new process with pid 1131, instance 1, run: true Apr 05 18:12:02 volumio-pi4 kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=trace msg="emitting websocket event: metadata" Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=trace msg="emitting websocket event: active" Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="sending successful reply for delaer request" Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Apr 05 18:12:02 volumio-pi4 volumio[841]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:09t5pNK7TPmboRJb69I1y6","name":"Graf Twerk","artist_names":["Drahthaus"],"album_name":"Drahthaus","album_cover_url":"https://i.scdn.co/image/ab67616d00001e028cbc39c3c721901e3c1c8ff3","position":19571,"duration":413386,"release_date":"year:2020 month:4 day:24","track_number":1,"disc_number":1}} Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 05 18:12:02 volumio-pi4 volumio[841]: SPOTIFY: received: {"type":"active","data":null} Apr 05 18:12:02 volumio-pi4 volumio[841]: info: Aligning Spotify Volume to Volumio Volume Apr 05 18:12:02 volumio-pi4 volumio[841]: info: CoreCommandRouter::volumioGetState Apr 05 18:12:02 volumio-pi4 volumio[841]: info: CorePlayQueue::getTrack 0 Apr 05 18:12:02 volumio-pi4 volumio[841]: info: Setting Spotify Volume from Volumio: 100 Apr 05 18:12:02 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:02-02:00" level=debug msg="fetched chunk 3/33, size: 524288" Apr 05 18:12:03 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:03-02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 05 18:12:03 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:03-02:00" level=trace msg="emitting websocket event: paused" Apr 05 18:12:03 volumio-pi4 volumio[841]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:09t5pNK7TPmboRJb69I1y6","play_origin":"playlist/ondemand"}} Apr 05 18:12:03 volumio-pi4 volumio[841]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 05 18:12:03 volumio-pi4 volumio[841]: TypeError: Cannot read property 'service' of undefined Apr 05 18:12:03 volumio-pi4 volumio[841]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Apr 05 18:12:03 volumio-pi4 volumio[841]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:270:18) Apr 05 18:12:03 volumio-pi4 volumio[841]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Apr 05 18:12:03 volumio-pi4 volumio[841]: at WebSocket.emit (events.js:315:20) Apr 05 18:12:03 volumio-pi4 volumio[841]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1203:20) Apr 05 18:12:03 volumio-pi4 volumio[841]: at Receiver.emit (events.js:315:20) Apr 05 18:12:03 volumio-pi4 volumio[841]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:608:16 Apr 05 18:12:03 volumio-pi4 volumio[841]: at internal/process/task_queues.js:149:7 Apr 05 18:12:03 volumio-pi4 volumio[841]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) Apr 05 18:12:03 volumio-pi4 volumio[841]: at AsyncResource.runMicrotask (internal/process/task_queues.js:146:8) Apr 05 18:12:03 volumio-pi4 volumio[841]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Apr 05 18:12:03 volumio-pi4 volumio[841]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 05 18:12:03 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:03-02:00" level=debug msg="fetched chunk 2/33, size: 524288" Apr 05 18:12:03 volumio-pi4 go-librespot[1044]: time="2024-04-05T18:12:03-02:00" level=debug msg="fetched chunk 4/33, size: 524288" Apr 05 18:12:03 volumio-pi4 sudo[1147]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-05 18:11 Apr 05 18:12:03 volumio-pi4 sudo[1147]: 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"