-- Logs begin at Sat 2024-04-13 12:05:23 JST, end at Sat 2024-04-13 12:07:57 JST. -- Apr 13 12:06:00 muse2 systemd[1]: hciuart.service: Succeeded. Apr 13 12:06:00 muse2 systemd[1]: Started Configure Bluetooth Modems connected by UART. Apr 13 12:06:00 muse2 systemd[1]: Starting Raspberry Pi bluetooth helper... Apr 13 12:06:00 muse2 kernel: pcm512x 1-004d: supply AVDD not found, using dummy regulator Apr 13 12:06:00 muse2 systemd[1]: Started Load/Save RF Kill Switch Status. Apr 13 12:06:00 muse2 kernel: pcm512x 1-004d: supply DVDD not found, using dummy regulator Apr 13 12:06:00 muse2 kernel: pcm512x 1-004d: supply CPVDD not found, using dummy regulator Apr 13 12:06:00 muse2 bthelper[526]: Raspberry Pi BDADDR already set Apr 13 12:06:00 muse2 systemd[1]: Started Raspberry Pi bluetooth helper. Apr 13 12:06:01 muse2 systemd[1]: Starting Bluetooth service... Apr 13 12:06:01 muse2 haveged[270]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Apr 13 12:06:01 muse2 bluetoothd[537]: Bluetooth daemon 5.50 Apr 13 12:06:01 muse2 haveged[270]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Apr 13 12:06:01 muse2 haveged[270]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99647 Apr 13 12:06:01 muse2 haveged[270]: haveged: fills: 0, generated: 0 Apr 13 12:06:01 muse2 bluetoothd[537]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Apr 13 12:06:01 muse2 systemd[1]: Started Bluetooth service. Apr 13 12:06:01 muse2 systemd[1]: Reached target Bluetooth. Apr 13 12:06:01 muse2 bluetoothd[537]: Starting SDP server Apr 13 12:06:01 muse2 bluetoothd[537]: Excluding (cli) sap Apr 13 12:06:01 muse2 kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Apr 13 12:06:01 muse2 kernel: Bluetooth: BNEP filters: protocol multicast Apr 13 12:06:01 muse2 kernel: Bluetooth: BNEP socket layer initialized Apr 13 12:06:01 muse2 bluetoothd[537]: Bluetooth management interface 1.22 initialized Apr 13 12:06:01 muse2 kernel: Bluetooth: MGMT ver 1.22 Apr 13 12:06:01 muse2 dbus-daemon[283]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=537 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Apr 13 12:06:02 muse2 bluetoothd[537]: Failed to set privacy: Rejected (0x0b) Apr 13 12:06:02 muse2 systemd[1]: systemd-fsckd.service: Succeeded. Apr 13 12:06:02 muse2 systemd[1]: Starting Hostname Service... Apr 13 12:06:03 muse2 wireless.js[290]: Cleaning previous... Apr 13 12:06:03 muse2 systemd[1]: Found device /sys/subsystem/net/devices/wlan0. Apr 13 12:06:03 muse2 dbus-daemon[283]: [system] Successfully activated service 'org.freedesktop.hostname1' Apr 13 12:06:03 muse2 systemd[1]: Started Hostname Service. Apr 13 12:06:03 muse2 systemd[1]: Started ifup for wlan0. Apr 13 12:06:04 muse2 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 13 12:06:04 muse2 sudo[572]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 13 12:06:04 muse2 sudo[572]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:04 muse2 sudo[572]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:04 muse2 sudo[594]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 13 12:06:04 muse2 sudo[594]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:04 muse2 sh[555]: wlan0=wlan0 Apr 13 12:06:05 muse2 sudo[594]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:05 muse2 volumio-remote-updater[277]: [2024-04-13 12:06:05] [info] asio async_connect error: system:111 (Connection refused) Apr 13 12:06:05 muse2 volumio-remote-updater[277]: [2024-04-13 12:06:05] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 13 12:06:05 muse2 volumio-remote-updater[277]: [2024-04-13 12:06:05] [error] handle_connect error: Underlying Transport Error Apr 13 12:06:05 muse2 wireless.js[290]: Stopped aP Apr 13 12:06:05 muse2 sudo[608]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 13 12:06:05 muse2 sudo[608]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:05 muse2 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 13 12:06:05 muse2 sudo[608]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:05 muse2 systemd[1]: systemd-rfkill.service: Succeeded. Apr 13 12:06:05 muse2 sudo[610]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Apr 13 12:06:05 muse2 sudo[610]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:05 muse2 sudo[610]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:05 muse2 sudo[617]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 13 12:06:05 muse2 sudo[617]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:05 muse2 sudo[617]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:05 muse2 sudo[619]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Apr 13 12:06:05 muse2 sudo[619]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:05 muse2 bthelper[526]: Changing power off succeeded Apr 13 12:06:06 muse2 bthelper[526]: [CHG] Controller B8:27:EB:76:1A:62 Class: 0x0000041c Apr 13 12:06:06 muse2 bthelper[526]: Changing power on succeeded Apr 13 12:06:06 muse2 bthelper[526]: [CHG] Controller B8:27:EB:76:1A:62 Powered: yes Apr 13 12:06:06 muse2 sudo[619]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:06 muse2 wireless.js[290]: SETTING APPROPRIATE REG DOMAIN: JP Apr 13 12:06:06 muse2 sudo[634]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 13 12:06:06 muse2 sudo[634]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:06 muse2 sudo[634]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:06 muse2 sudo[636]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set JP Apr 13 12:06:06 muse2 sudo[636]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:06 muse2 sudo[636]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:06 muse2 wireless.js[290]: SUCCESSFULLY SET NEW REGDOMAIN: JP Apr 13 12:06:06 muse2 wireless.js[290]: Start wireless flow Apr 13 12:06:06 muse2 wireless.js[290]: Stopped hotspot (if there).. Apr 13 12:06:06 muse2 sudo[641]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 13 12:06:06 muse2 sudo[641]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:06 muse2 sudo[641]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:06 muse2 sudo[643]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 13 12:06:06 muse2 sudo[643]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:07 muse2 sudo[643]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:07 muse2 wireless.js[290]: DHCP IP Apr 13 12:06:07 muse2 wireless.js[290]: Start ap Apr 13 12:06:07 muse2 wpa_supplicant[645]: Successfully initialized wpa_supplicant Apr 13 12:06:07 muse2 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 13 12:06:07 muse2 sudo[646]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Apr 13 12:06:07 muse2 sudo[646]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:07 muse2 dhcpcd[647]: dev: loaded udev Apr 13 12:06:07 muse2 kernel: 8021q: 802.1Q VLAN Support v1.8 Apr 13 12:06:08 muse2 dhcpcd[647]: wlan0: connected to Access Point `' Apr 13 12:06:08 muse2 dhcpcd[647]: no interfaces have a carrier Apr 13 12:06:08 muse2 dhcpcd[671]: wlan0: waiting for carrier Apr 13 12:06:08 muse2 dhcpcd[647]: forked to background, child pid 671 Apr 13 12:06:08 muse2 sudo[646]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:08 muse2 wireless.js[290]: trying... Apr 13 12:06:08 muse2 wpa_supplicant[651]: wlan0: Trying to associate with SSID '_wpv' Apr 13 12:06:08 muse2 sudo[673]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 13 12:06:08 muse2 sudo[673]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:08 muse2 sudo[673]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:09 muse2 wpa_supplicant[651]: wlan0: Associated with e8:9f:80:d9:a6:a8 Apr 13 12:06:09 muse2 wpa_supplicant[651]: wlan0: CTRL-EVENT-CONNECTED - Connection to e8:9f:80:d9:a6:a8 completed [id=0 id_str=] Apr 13 12:06:09 muse2 dhcpcd[671]: wlan0: carrier acquired Apr 13 12:06:09 muse2 dhcpcd[671]: wlan0: connected to Access Point `_wpv' Apr 13 12:06:09 muse2 wpa_supplicant[651]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Apr 13 12:06:09 muse2 dhcpcd[671]: DUID 00:01:00:01:2d:69:1e:f8:b8:27:eb:89:e5:9d Apr 13 12:06:09 muse2 dhcpcd[671]: wlan0: IAID eb:89:e5:9d Apr 13 12:06:09 muse2 dhcpcd[671]: wlan0: adding address fe80::3e8b:f92f:f003:451d Apr 13 12:06:09 muse2 dhcpcd[671]: ipv6_addaddr1: Permission denied Apr 13 12:06:09 muse2 dhcpcd[671]: wlan0: rebinding lease of 192.168.100.34 Apr 13 12:06:09 muse2 dhcpcd[671]: wlan0: probing address 192.168.100.34/24 Apr 13 12:06:09 muse2 wireless.js[290]: trying... Apr 13 12:06:09 muse2 dhcpcd[671]: wlan0: soliciting an IPv6 router Apr 13 12:06:09 muse2 sudo[677]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 13 12:06:09 muse2 sudo[677]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:09 muse2 sudo[677]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:10 muse2 wireless.js[290]: trying... Apr 13 12:06:10 muse2 sudo[680]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 13 12:06:10 muse2 sudo[680]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:10 muse2 sudo[680]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:11 muse2 wireless.js[290]: trying... Apr 13 12:06:11 muse2 sudo[683]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 13 12:06:11 muse2 sudo[683]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:11 muse2 sudo[683]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:12 muse2 wireless.js[290]: trying... Apr 13 12:06:12 muse2 sudo[686]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 13 12:06:12 muse2 sudo[686]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:12 muse2 sudo[686]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:13 muse2 wireless.js[290]: trying... Apr 13 12:06:13 muse2 sudo[689]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 13 12:06:13 muse2 sudo[689]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:13 muse2 sudo[689]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:14 muse2 wireless.js[290]: trying... Apr 13 12:06:14 muse2 dhcpcd[671]: wlan0: leased 192.168.100.34 for 86400 seconds Apr 13 12:06:14 muse2 avahi-daemon[279]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.100.34. Apr 13 12:06:14 muse2 dhcpcd[671]: wlan0: adding route to 192.168.100.0/24 Apr 13 12:06:14 muse2 avahi-daemon[279]: New relevant interface wlan0.IPv4 for mDNS. Apr 13 12:06:14 muse2 avahi-daemon[279]: Registering new address record for 192.168.100.34 on wlan0.IPv4. Apr 13 12:06:14 muse2 dhcpcd[671]: wlan0: adding default route via 192.168.100.1 Apr 13 12:06:14 muse2 sudo[693]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 13 12:06:14 muse2 sudo[693]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:14 muse2 sudo[693]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:14 muse2 wireless.js[290]: Connected to: ----_wpv Apr 13 12:06:14 muse2 wireless.js[290]: ---- Apr 13 12:06:14 muse2 sudo[709]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 13 12:06:14 muse2 sudo[709]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:14 muse2 sudo[709]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:15 muse2 wireless.js[290]: ... joined AP, wlan0 IPv4 is 192.168.100.34, ipV6 is undefined Apr 13 12:06:15 muse2 wireless.js[290]: It's done! AP Apr 13 12:06:15 muse2 volumio-remote-updater[277]: [2024-04-13 12:06:15] [info] asio async_connect error: system:111 (Connection refused) Apr 13 12:06:15 muse2 volumio-remote-updater[277]: [2024-04-13 12:06:15] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 13 12:06:15 muse2 volumio-remote-updater[277]: [2024-04-13 12:06:15] [error] handle_connect error: Underlying Transport Error Apr 13 12:06:15 muse2 systemd[1]: Started Samba NMB Daemon. Apr 13 12:06:15 muse2 nmbd[455]: [2024/04/13 12:06:15.136409, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 13 12:06:15 muse2 nmbd[455]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Apr 13 12:06:15 muse2 systemd[1]: Starting Samba Winbind Daemon... Apr 13 12:06:15 muse2 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 13 12:06:15 muse2 systemd[1]: Started Wireless Services. Apr 13 12:06:15 muse2 systemd[1]: Started Volumio Backend Module. Apr 13 12:06:15 muse2 systemd[1]: Started Volumio Cpu Tweaker. Apr 13 12:06:15 muse2 volumio-cpu-tweak[724]: Setting RT Priority for mpd Apr 13 12:06:15 muse2 volumio-cpu-tweak[724]: pid 35's current scheduling policy: SCHED_OTHER Apr 13 12:06:15 muse2 volumio-cpu-tweak[724]: pid 35's current scheduling priority: 0 Apr 13 12:06:15 muse2 volumio-cpu-tweak[724]: Not enough cores to set MPD affinity Apr 13 12:06:16 muse2 volumio-cpu-tweak[724]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Apr 13 12:06:16 muse2 volumio-cpu-tweak[724]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Apr 13 12:06:16 muse2 systemd[1]: volumio_cpu_tweak.service: Succeeded. Apr 13 12:06:16 muse2 ntpd[456]: Listen normally on 3 wlan0 192.168.100.34:123 Apr 13 12:06:16 muse2 ntpd[456]: new interface(s) found: waking up resolver Apr 13 12:06:17 muse2 winbindd[719]: [2024/04/13 12:06:17.904207, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Apr 13 12:06:17 muse2 winbindd[719]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Apr 13 12:06:17 muse2 systemd[1]: Started Samba Winbind Daemon. Apr 13 12:06:17 muse2 winbindd[719]: [2024/04/13 12:06:17.996323, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 13 12:06:17 muse2 winbindd[719]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Apr 13 12:06:18 muse2 systemd[1]: Starting Samba SMB Daemon... Apr 13 12:06:21 muse2 systemd[1]: Started Samba SMB Daemon. Apr 13 12:06:21 muse2 systemd[1]: Reached target Multi-User System. Apr 13 12:06:21 muse2 smbd[742]: [2024/04/13 12:06:21.601200, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 13 12:06:21 muse2 smbd[742]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Apr 13 12:06:21 muse2 systemd[1]: Reached target Graphical Interface. Apr 13 12:06:21 muse2 systemd[1]: Starting Update UTMP about System Runlevel Changes... Apr 13 12:06:22 muse2 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Apr 13 12:06:22 muse2 systemd[1]: Started Update UTMP about System Runlevel Changes. Apr 13 12:06:22 muse2 systemd[1]: Startup finished in 13.526s (kernel) + 1min 5.168s (userspace) = 1min 18.694s. Apr 13 12:06:25 muse2 volumio-remote-updater[277]: [2024-04-13 12:06:25] [info] asio async_connect error: system:111 (Connection refused) Apr 13 12:06:25 muse2 volumio-remote-updater[277]: [2024-04-13 12:06:25] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 13 12:06:25 muse2 volumio-remote-updater[277]: [2024-04-13 12:06:25] [error] handle_connect error: Underlying Transport Error Apr 13 12:06:28 muse2 volumio[723]: info: ------------------------------------------- Apr 13 12:06:28 muse2 volumio[723]: info: ----- Volumio3 ---- Apr 13 12:06:28 muse2 volumio[723]: info: ------------------------------------------- Apr 13 12:06:28 muse2 volumio[723]: info: ----- System startup ---- Apr 13 12:06:28 muse2 volumio[723]: info: ------------------------------------------- Apr 13 12:06:32 muse2 volumio[723]: info: MYVOLUMIO Environment detected Apr 13 12:06:32 muse2 volumio[723]: info: Plugin folders cleanup Apr 13 12:06:32 muse2 volumio[723]: info: Scanning into folder /volumio/app/plugins/ Apr 13 12:06:32 muse2 volumio[723]: info: Scanning category audio_interface Apr 13 12:06:32 muse2 volumio[723]: info: Scanning category miscellanea Apr 13 12:06:32 muse2 volumio[723]: info: Scanning category music_service Apr 13 12:06:32 muse2 volumio[723]: info: Scanning category plugins.json Apr 13 12:06:32 muse2 volumio[723]: info: Scanning category system_controller Apr 13 12:06:32 muse2 volumio[723]: info: Scanning category user_interface Apr 13 12:06:32 muse2 volumio[723]: info: Scanning into folder /data/plugins/ Apr 13 12:06:32 muse2 volumio[723]: info: Scanning category audio_interface Apr 13 12:06:32 muse2 volumio[723]: info: Plugin folders cleanup completed Apr 13 12:06:32 muse2 volumio[723]: info: ------------------------------------------- Apr 13 12:06:32 muse2 volumio[723]: info: ----- Core plugins startup ---- Apr 13 12:06:32 muse2 volumio[723]: info: ------------------------------------------- Apr 13 12:06:32 muse2 volumio[723]: info: Loading plugins from folder /volumio/app/plugins/ Apr 13 12:06:32 muse2 volumio[723]: info: Adding plugin upnp to MyMusic Plugins Apr 13 12:06:32 muse2 volumio[723]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 13 12:06:32 muse2 volumio[723]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 13 12:06:32 muse2 volumio[723]: info: Loading plugins from folder /data/plugins/ Apr 13 12:06:32 muse2 volumio[723]: info: Loading plugin "system"... Apr 13 12:06:32 muse2 volumio[723]: info: Loading plugin "appearance"... Apr 13 12:06:33 muse2 systemd[1]: systemd-hostnamed.service: Succeeded. Apr 13 12:06:35 muse2 volumio-remote-updater[277]: [2024-04-13 12:06:35] [connect] Successful connection Apr 13 12:06:38 muse2 volumio[723]: info: Loading plugin "network"... Apr 13 12:06:38 muse2 volumio[723]: info: Refreshing Cached IP Addresses Apr 13 12:06:38 muse2 volumio[723]: info: Loading plugin "services"... Apr 13 12:06:38 muse2 sudo[767]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 13 12:06:38 muse2 sudo[767]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:38 muse2 volumio[723]: info: Loading plugin "alsa_controller"... Apr 13 12:06:38 muse2 sudo[769]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 13 12:06:38 muse2 sudo[769]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:38 muse2 sudo[767]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:38 muse2 sudo[771]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 13 12:06:38 muse2 sudo[769]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:38 muse2 sudo[771]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:38 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 13 12:06:38 muse2 volumio[723]: info: Loading plugin "wizard"... Apr 13 12:06:38 muse2 volumio[723]: info: Loading plugin "networkfs"... Apr 13 12:06:39 muse2 volumio[723]: info: Starting Udev Watcher for removable devices Apr 13 12:06:39 muse2 sudo[782]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=goos,password=g00s3306,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.2.1/shared\\music /mnt/NAS/nano Apr 13 12:06:39 muse2 sudo[782]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:39 muse2 volumio[723]: info: Ignoring mount for partition: boot Apr 13 12:06:39 muse2 volumio[723]: info: Ignoring mount for partition: volumio Apr 13 12:06:39 muse2 volumio[723]: info: Ignoring mount for partition: volumio_data Apr 13 12:06:39 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 13 12:06:39 muse2 volumio[723]: info: Loading plugin "volumio_command_line_client"... Apr 13 12:06:39 muse2 sudo[771]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:39 muse2 volumio[723]: info: Loading plugin "upnp"... Apr 13 12:06:39 muse2 volumio[723]: info: [1712977599625] Starting Upmpd Daemon Apr 13 12:06:39 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 13 12:06:39 muse2 volumio[723]: info: Loading plugin "my_music"... Apr 13 12:06:39 muse2 volumio[723]: info: Loading plugin "mpd"... Apr 13 12:06:40 muse2 kernel: Key type cifs.spnego registered Apr 13 12:06:40 muse2 kernel: Key type cifs.idmap registered Apr 13 12:06:40 muse2 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 13 12:06:40 muse2 kernel: CIFS: Attempting to mount \\192.168.2.1\shared Apr 13 12:06:40 muse2 sudo[782]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:41 muse2 volumio[723]: info: Loading plugin "upnp_browser"... Apr 13 12:06:44 muse2 volumio[723]: info: Loading plugin "alarm-clock"... Apr 13 12:06:45 muse2 volumio[723]: info: Loading plugin "airplay_emulation"... Apr 13 12:06:45 muse2 volumio[723]: info: Starting Shairport Sync Apr 13 12:06:45 muse2 volumio[723]: info: Loading plugin "last_100"... Apr 13 12:06:45 muse2 volumio[723]: info: Loading plugin "webradio"... Apr 13 12:06:45 muse2 volumio[723]: info: Loading plugin "i2s_dacs"... Apr 13 12:06:45 muse2 volumio[723]: info: Loading plugin "volumiodiscovery"... Apr 13 12:06:46 muse2 volumio[723]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 13 12:06:46 muse2 node[723]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 13 12:06:46 muse2 volumio[723]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 13 12:06:46 muse2 node[723]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 13 12:06:46 muse2 volumio[723]: *** WARNING *** For more information see Apr 13 12:06:46 muse2 node[723]: *** WARNING *** For more information see Apr 13 12:06:46 muse2 volumio[723]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 13 12:06:46 muse2 volumio[723]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 13 12:06:46 muse2 volumio[723]: *** WARNING *** For more information see Apr 13 12:06:46 muse2 node[723]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 13 12:06:46 muse2 node[723]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 13 12:06:46 muse2 node[723]: *** WARNING *** For more information see Apr 13 12:06:46 muse2 volumio[723]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 13 12:06:46 muse2 volumio[723]: info: Discovery: Started advertising with name: muse2 Apr 13 12:06:46 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 13 12:06:46 muse2 volumio[723]: info: Loading plugin "outputs"... Apr 13 12:06:46 muse2 volumio[723]: info: Loading plugin "albumart"... Apr 13 12:06:46 muse2 volumio[723]: info: Plugin example_plugin is not enabled Apr 13 12:06:46 muse2 volumio[723]: info: Loading plugin "inputs"... Apr 13 12:06:46 muse2 volumio[723]: info: Loading plugin "updater_comm"... Apr 13 12:06:48 muse2 volumio[723]: info: Plugin mpdemulation is not enabled Apr 13 12:06:48 muse2 volumio[723]: info: Loading plugin "rest_api"... Apr 13 12:06:48 muse2 volumio[723]: info: Loading plugin "websocket"... Apr 13 12:06:48 muse2 volumio[723]: info: Loading plugin "fusiondsp"... Apr 13 12:06:49 muse2 volumio[723]: Forking 1 albumart workers Apr 13 12:06:50 muse2 volumio-remote-updater[277]: [2024-04-13 12:06:50] [connect] Successful connection Apr 13 12:06:51 muse2 volumio[723]: info: Applying required configuration parameters for plugin fusiondsp Apr 13 12:06:52 muse2 volumio[723]: info: Loading i18n strings for locale en Apr 13 12:06:52 muse2 volumio[723]: Updating browse sources language Apr 13 12:06:52 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 13 12:06:54 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 12:06:54 muse2 volumio[723]: info: CoreCommandRouter::initPlayerControls Apr 13 12:06:54 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 12:06:54 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 12:06:54 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 12:06:54 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 12:06:54 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 12:06:54 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 12:06:54 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 12:06:54 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 12:06:54 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 12:06:54 muse2 volumio[723]: Express server listening on port 3000 Apr 13 12:06:54 muse2 volumio[723]: [Metrics] WebUI: 29s 665.66ms Apr 13 12:06:55 muse2 volumio[723]: info: CoreStateMachine::resetVolumioState Apr 13 12:06:55 muse2 volumio[723]: info: CoreStateMachine::getcurrentVolume Apr 13 12:06:55 muse2 volumio[723]: info: CoreCommandRouter::volumioRetrievevolume Apr 13 12:06:55 muse2 sudo[865]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 13 12:06:55 muse2 sudo[865]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:55 muse2 sudo[867]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 13 12:06:55 muse2 sudo[867]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:55 muse2 sudo[865]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:55 muse2 sudo[867]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:56 muse2 volumio[723]: Starting albumart workers Apr 13 12:06:56 muse2 volumio[723]: verbose: New Socket.io Connection to 192.168.100.34 from 192.168.100.200 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Total Clients: 1 Apr 13 12:06:57 muse2 volumio[723]: verbose: New Socket.io Connection to 192.168.100.34 from 192.168.100.200 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Total Clients: 2 Apr 13 12:06:57 muse2 volumio[723]: verbose: New Socket.io Connection to 192.168.100.34 from 192.168.100.200 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Total Clients: 3 Apr 13 12:06:57 muse2 volumio[723]: verbose: New Socket.io Connection to 192.168.100.34 from 192.168.100.200 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Total Clients: 4 Apr 13 12:06:57 muse2 volumio[723]: verbose: New Socket.io Connection to 192.168.100.34 from 192.168.100.200 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Total Clients: 5 Apr 13 12:06:57 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 12:06:57 muse2 volumio[723]: info: Reloading queue from file Apr 13 12:06:58 muse2 volumio[723]: verbose: New Socket.io Connection to 192.168.100.34 from 192.168.100.200 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Total Clients: 6 Apr 13 12:06:58 muse2 volumio[723]: info: CoreStateMachine::setRepeat null single undefined Apr 13 12:06:58 muse2 volumio[723]: info: CoreStateMachine::pushState Apr 13 12:06:58 muse2 volumio[723]: info: CorePlayQueue::getTrack 0 Apr 13 12:06:58 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 13 12:06:58 muse2 volumio[723]: info: CoreCommandRouter::volumioPushState Apr 13 12:06:58 muse2 volumio[723]: info: CoreStateMachine::setRandom null Apr 13 12:06:58 muse2 volumio[723]: info: CoreStateMachine::pushState Apr 13 12:06:58 muse2 volumio[723]: info: CorePlayQueue::getTrack 0 Apr 13 12:06:58 muse2 volumio[723]: info: CoreCommandRouter::volumioPushState Apr 13 12:06:58 muse2 volumio[723]: info: Setting Device type: Raspberry PI Apr 13 12:06:58 muse2 volumio[723]: info: VolumeController:: Volume=83 Mute =false Apr 13 12:06:58 muse2 volumio[723]: info: CoreStateMachine::pushState Apr 13 12:06:58 muse2 volumio[723]: info: CorePlayQueue::getTrack 0 Apr 13 12:06:58 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 13 12:06:58 muse2 volumio[723]: info: CoreCommandRouter::volumioPushState Apr 13 12:06:58 muse2 volumio[723]: info: CoreStateMachine::updateTrackBlock Apr 13 12:06:58 muse2 volumio[723]: info: CorePlayQueue::getTrackBlock Apr 13 12:06:58 muse2 volumio[723]: info: CoreCommandRouter::volumioRetrievevolume Apr 13 12:06:59 muse2 volumio[723]: info: Discovery: adding 61ee82df-5a96-4cd7-a03e-02281e190837 Apr 13 12:06:59 muse2 volumio[723]: info: Discovery: Found device muse2 Apr 13 12:06:59 muse2 volumio[723]: info: CoreCommandRouter::volumioGetState Apr 13 12:06:59 muse2 volumio[723]: info: CorePlayQueue::getTrack 0 Apr 13 12:06:59 muse2 sudo[880]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 13 12:06:59 muse2 sudo[880]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:06:59 muse2 systemd[1]: Started UPnP Renderer front-end to MPD. Apr 13 12:06:59 muse2 sudo[880]: pam_unix(sudo:session): session closed for user root Apr 13 12:06:59 muse2 ntpd[456]: Soliciting pool server 202.182.111.234 Apr 13 12:06:59 muse2 ntpd[456]: Soliciting pool server 202.181.103.212 Apr 13 12:06:59 muse2 ntpd[456]: Soliciting pool server 160.16.113.133 Apr 13 12:07:00 muse2 volumio[723]: info: Upmpdcli Daemon Started Apr 13 12:07:00 muse2 sudo[885]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 13 12:07:00 muse2 sudo[885]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:07:00 muse2 volumio[723]: info: VolumeController:: Volume=83 Mute =false Apr 13 12:07:00 muse2 volumio[723]: info: CoreStateMachine::pushState Apr 13 12:07:00 muse2 volumio[723]: info: CorePlayQueue::getTrack 0 Apr 13 12:07:00 muse2 volumio[723]: info: CoreCommandRouter::volumioPushState Apr 13 12:07:00 muse2 sudo[887]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 13 12:07:00 muse2 sudo[885]: pam_unix(sudo:session): session closed for user root Apr 13 12:07:00 muse2 sudo[887]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:07:00 muse2 sudo[887]: pam_unix(sudo:session): session closed for user root Apr 13 12:07:00 muse2 ntpd[456]: Soliciting pool server 172.105.240.243 Apr 13 12:07:00 muse2 ntpd[456]: Soliciting pool server 162.159.200.1 Apr 13 12:07:00 muse2 ntpd[456]: Soliciting pool server 139.162.96.56 Apr 13 12:07:00 muse2 volumio[723]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Apr 13 12:07:00 muse2 ntpd[456]: Soliciting pool server 129.250.35.250 Apr 13 12:07:00 muse2 volumio[723]: verbose: New Socket.io Connection to 192.168.100.34 from 192.168.100.200 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Total Clients: 7 Apr 13 12:07:00 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 13 12:07:01 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 13 12:07:01 muse2 volumio[723]: info: CoreCommandRouter::volumioGetVisibleSources Apr 13 12:07:01 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 13 12:07:01 muse2 volumio[723]: info: CoreCommandRouter::volumioGetState Apr 13 12:07:01 muse2 volumio[723]: info: CorePlayQueue::getTrack 0 Apr 13 12:07:01 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 13 12:07:01 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 13 12:07:01 muse2 volumio[723]: info: Received Get System Info Apr 13 12:07:01 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 12:07:01 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 12:07:01 muse2 volumio[723]: info: Discovery: Getting this device information Apr 13 12:07:01 muse2 volumio[723]: info: CoreCommandRouter::volumioGetState Apr 13 12:07:01 muse2 volumio[723]: info: CorePlayQueue::getTrack 0 Apr 13 12:07:01 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 12:07:01 muse2 volumio[723]: info: CoreCommandRouter::volumioGetState Apr 13 12:07:01 muse2 volumio[723]: info: CorePlayQueue::getTrack 0 Apr 13 12:07:01 muse2 ntpd[456]: Soliciting pool server 172.105.204.105 Apr 13 12:07:01 muse2 ntpd[456]: Soliciting pool server 133.243.238.163 Apr 13 12:07:01 muse2 ntpd[456]: Soliciting pool server 167.179.119.205 Apr 13 12:07:01 muse2 ntpd[456]: Soliciting pool server 162.159.200.123 Apr 13 12:07:01 muse2 volumio[723]: info: Listing playlists Apr 13 12:07:01 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 13 12:07:01 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 13 12:07:02 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 13 12:07:02 muse2 volumio[723]: info: Received Get System Info Apr 13 12:07:02 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 12:07:02 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 12:07:02 muse2 volumio[723]: info: Discovery: Getting this device information Apr 13 12:07:02 muse2 volumio[723]: info: CoreCommandRouter::volumioGetState Apr 13 12:07:02 muse2 volumio[723]: info: CorePlayQueue::getTrack 0 Apr 13 12:07:02 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 12:07:02 muse2 volumio[723]: info: CoreCommandRouter::volumioGetState Apr 13 12:07:02 muse2 volumio[723]: info: CorePlayQueue::getTrack 0 Apr 13 12:07:02 muse2 volumio[723]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 13 12:07:02 muse2 ntpd[456]: Soliciting pool server 133.243.238.243 Apr 13 12:07:02 muse2 ntpd[456]: Soliciting pool server 45.76.218.37 Apr 13 12:07:02 muse2 ntpd[456]: Soliciting pool server 122.215.240.52 Apr 13 12:07:02 muse2 ntpd[456]: Soliciting pool server 129.250.35.251 Apr 13 12:07:03 muse2 ntpd[456]: Soliciting pool server 45.77.20.103 Apr 13 12:07:04 muse2 volumio[723]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Apr 13 12:07:05 muse2 volumio-remote-updater[277]: [2024-04-13 12:07:05] [connect] Successful connection Apr 13 12:07:05 muse2 volumio-remote-updater[277]: [2024-04-13 12:07:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1712977625 101 Apr 13 12:07:05 muse2 volumio[723]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 8 Apr 13 12:07:30 muse2 ntpd[456]: receive: Unexpected origin timestamp 0xe9c4755a.64a3f275 does not match aorg 0000000000.00000000 from server@162.159.200.123 xmt 0xe9c47572.bc308591 Apr 13 12:07:30 muse2 ntpd[456]: receive: Unexpected origin timestamp 0xe9c4755a.64bf983a does not match aorg 0000000000.00000000 from server@162.159.200.1 xmt 0xe9c47572.bc1435e0 Apr 13 12:07:30 muse2 ntpd[456]: receive: Unexpected origin timestamp 0xe9c4755a.64cb6aba does not match aorg 0000000000.00000000 from server@160.16.113.133 xmt 0xe9c47572.bcd491ab Apr 13 12:07:30 muse2 ntpd[456]: receive: Unexpected origin timestamp 0xe9c4755a.648b7af8 does not match aorg 0000000000.00000000 from server@122.215.240.52 xmt 0xe9c47572.bc428db1 Apr 13 12:07:34 muse2 volumio[723]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Apr 13 12:07:35 muse2 volumio[723]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 13 12:07:36 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 13 12:07:36 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 12:07:36 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 13 12:07:36 muse2 volumio[723]: info: Getting Alsa Cards List without I2S DAC Apr 13 12:07:36 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Apr 13 12:07:36 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 12:07:36 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 12:07:36 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 12:07:36 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 12:07:36 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 12:07:36 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 12:07:36 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 12:07:36 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 12:07:36 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 13 12:07:36 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 13 12:07:42 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 13 12:07:42 muse2 volumio[723]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 13 12:07:42 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 13 12:07:42 muse2 volumio[723]: info: Received Get System Version Apr 13 12:07:42 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 13 12:07:42 muse2 volumio[723]: info: Received Get System Info Apr 13 12:07:42 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 12:07:42 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 12:07:42 muse2 volumio[723]: info: Discovery: Getting this device information Apr 13 12:07:42 muse2 volumio[723]: info: CoreCommandRouter::volumioGetState Apr 13 12:07:42 muse2 volumio[723]: info: CorePlayQueue::getTrack 0 Apr 13 12:07:42 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 12:07:44 muse2 volumio[723]: info: CoreCommandRouter::volumioGetState Apr 13 12:07:44 muse2 volumio[723]: info: CorePlayQueue::getTrack 0 Apr 13 12:07:44 muse2 volumio[723]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Apr 13 12:07:46 muse2 volumio[723]: error: Plugin system_controller system failed to complete 'onVolumioStart' in a timely fashion Apr 13 12:07:46 muse2 volumio[723]: info: Preparing to generate the ALSA configuration file Apr 13 12:07:46 muse2 volumio[723]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Apr 13 12:07:46 muse2 volumio[723]: info: Reading ALSA contributions from plugins. Apr 13 12:07:46 muse2 volumio[723]: info: Asound.conf file unchanged, so no further update is needed Apr 13 12:07:46 muse2 volumio[723]: info: Output device has changed, restarting MPD Apr 13 12:07:46 muse2 volumio[723]: info: Output device has changed, restarting Shairport Sync Apr 13 12:07:46 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 12:07:46 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 12:07:46 muse2 sudo[909]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 13 12:07:47 muse2 sudo[909]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:07:47 muse2 sudo[909]: pam_unix(sudo:session): session closed for user root Apr 13 12:07:47 muse2 sudo[911]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 13 12:07:47 muse2 sudo[911]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:07:47 muse2 volumio[723]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 13 12:07:47 muse2 volumio[723]: info: ___________ START PLUGINS ___________ Apr 13 12:07:47 muse2 systemd[1]: Listening on mpd.socket. Apr 13 12:07:47 muse2 systemd[1]: Starting Music Player Daemon... Apr 13 12:07:47 muse2 volumio[723]: info: ControllerMpd::onStart: Initializing MPD Apr 13 12:07:47 muse2 volumio[723]: info: Creating MPD Configuration file Apr 13 12:07:47 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 12:07:47 muse2 volumio[723]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 13 12:07:47 muse2 volumio[723]: info: [1712977667707] CoreMusicLibrary::Adding element Media Servers Apr 13 12:07:47 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 13 12:07:47 muse2 sudo[920]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 13 12:07:47 muse2 sudo[920]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:07:47 muse2 sudo[920]: pam_unix(sudo:session): session closed for user root Apr 13 12:07:47 muse2 sudo[922]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 13 12:07:48 muse2 sudo[922]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:07:48 muse2 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 13 12:07:48 muse2 systemd[1]: mpd.service: Succeeded. Apr 13 12:07:48 muse2 systemd[1]: Stopped Music Player Daemon. Apr 13 12:07:48 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 12:07:48 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 12:07:48 muse2 systemd[1]: Starting Music Player Daemon... Apr 13 12:07:48 muse2 volumio[723]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 13 12:07:48 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 12:07:48 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 12:07:48 muse2 volumio[723]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 13 12:07:48 muse2 volumio[723]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 13 12:07:48 muse2 volumio[723]: info: [1712977668956] CoreMusicLibrary::Adding element Last_100 Apr 13 12:07:48 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 13 12:07:49 muse2 volumio[723]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 13 12:07:49 muse2 volumio[723]: info: [1712977669025] CoreMusicLibrary::Adding element Webradio Apr 13 12:07:49 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 13 12:07:49 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 13 12:07:49 muse2 volumio[723]: info: Loading i18n strings for locale en Apr 13 12:07:49 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Apr 13 12:07:49 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 12:07:49 muse2 volumio[723]: info: FusionDsp - mixtype--------------------- Hardware Apr 13 12:07:49 muse2 volumio[723]: info: Volumio Calling Home Apr 13 12:07:50 muse2 volumio[723]: info: Preparing to generate the ALSA configuration file Apr 13 12:07:51 muse2 volumio[723]: info: camilladsp spawned new process with pid undefined, instance 1, run: true Apr 13 12:07:51 muse2 volumio[723]: info: camilladsp service started and running in background, instance 1 Apr 13 12:07:51 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 12:07:51 muse2 volumio[723]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Apr 13 12:07:51 muse2 volumio[723]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json Apr 13 12:07:51 muse2 volumio[723]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Apr 13 12:07:51 muse2 volumio[723]: info: FusionDsp loaded Apr 13 12:07:51 muse2 volumio[723]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 12:07:52 muse2 sudo[945]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Apr 13 12:07:52 muse2 sudo[945]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 12:07:52 muse2 volumio[723]: info: FusionDsp - Reporting Fusion DSP Enabled Apr 13 12:07:52 muse2 volumio[723]: info: Adding Signal Path Element [object Object] Apr 13 12:07:52 muse2 volumio[723]: info: Adding fusiondspeq DSP Signal Path Element Apr 13 12:07:52 muse2 volumio[723]: info: FusionDsp - ---- installed callbackRead Apr 13 12:07:52 muse2 sudo[945]: pam_unix(sudo:session): session closed for user root Apr 13 12:07:52 muse2 volumio[723]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 13 12:07:52 muse2 volumio[723]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp ENOENT Apr 13 12:07:52 muse2 volumio[723]: at Process.ChildProcess._handle.onexit (internal/child_process.js:269:19) Apr 13 12:07:52 muse2 volumio[723]: at onErrorNT (internal/child_process.js:465:16) Apr 13 12:07:52 muse2 volumio[723]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Apr 13 12:07:52 muse2 volumio[723]: at runNextTicks (internal/process/task_queues.js:62:3) Apr 13 12:07:52 muse2 volumio[723]: at listOnTimeout (internal/timers.js:523:9) Apr 13 12:07:52 muse2 volumio[723]: at processTimers (internal/timers.js:497:7) { Apr 13 12:07:52 muse2 volumio[723]: errno: -2, Apr 13 12:07:52 muse2 volumio[723]: code: 'ENOENT', Apr 13 12:07:52 muse2 volumio[723]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', Apr 13 12:07:52 muse2 volumio[723]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', Apr 13 12:07:52 muse2 volumio[723]: spawnargs: [ Apr 13 12:07:52 muse2 volumio[723]: '-p', Apr 13 12:07:52 muse2 volumio[723]: 9876, Apr 13 12:07:52 muse2 volumio[723]: '-o', Apr 13 12:07:52 muse2 volumio[723]: '/tmp/camilladsp.log', Apr 13 12:07:52 muse2 volumio[723]: '-l', Apr 13 12:07:52 muse2 volumio[723]: 'warn', Apr 13 12:07:52 muse2 volumio[723]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' Apr 13 12:07:52 muse2 volumio[723]: ] Apr 13 12:07:52 muse2 volumio[723]: } Apr 13 12:07:52 muse2 volumio[723]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 13 12:07:57 muse2 sudo[956]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-13 12:06 Apr 13 12:07:57 muse2 sudo[956]: 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"