-- Logs begin at Thu 2019-02-14 10:11:59 UTC, end at Thu 2022-06-09 16:02:50 UTC. -- Jun 09 16:01:00 volumio systemd[1]: Started triggerhappy global hotkey daemon. Jun 09 16:01:00 volumio systemd[1]: Started Save/Restore Sound Card State. Jun 09 16:01:00 volumio systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Jun 09 16:01:00 volumio systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Jun 09 16:01:00 volumio systemd[1]: Failed to start dhcpcd on all interfaces. Jun 09 16:01:00 volumio avahi-daemon[468]: Successfully called chroot(). Jun 09 16:01:00 volumio avahi-daemon[468]: Successfully dropped remaining capabilities. Jun 09 16:01:00 volumio avahi-daemon[468]: No service file found in /etc/avahi/services. Jun 09 16:01:00 volumio kernel: uart-pl011 3f201000.serial: no DMA platform data Jun 09 16:01:00 volumio systemd[1]: Started Avahi mDNS/DNS-SD Stack. Jun 09 16:01:00 volumio systemd[1]: Reached target Sound Card. Jun 09 16:01:00 volumio sh[398]: wlan0=wlan0 Jun 09 16:01:00 volumio sh[401]: eth0: waiting for carrier Jun 09 16:01:00 volumio kernel: SMSC LAN8700 usb-001:003:01: attached PHY driver [SMSC LAN8700] (mii_bus:phy_addr=usb-001:003:01, irq=POLL) Jun 09 16:01:00 volumio kernel: smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup Jun 09 16:01:00 volumio kernel: random: crng init done Jun 09 16:01:00 volumio kernel: random: 7 urandom warning(s) missed due to ratelimiting Jun 09 16:01:00 volumio dhcpcd[447]: eth0: waiting for carrier Jun 09 16:01:00 volumio avahi-daemon[468]: Network interface enumeration completed. Jun 09 16:01:00 volumio avahi-daemon[468]: Server startup complete. Host name is volumio.local. Local service cookie is 1759470111. Jun 09 16:01:00 volumio kernel: smsc95xx 1-1.1:1.0 eth0: Link is Down Jun 09 16:01:00 volumio systemd[1]: Started RPC bind portmap service. Jun 09 16:01:00 volumio systemd[1]: Reached target RPC Port Mapper. Jun 09 16:01:00 volumio systemd[1]: Reached target Remote File Systems (Pre). Jun 09 16:01:00 volumio systemd[1]: Reached target Remote File Systems. Jun 09 16:01:00 volumio systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Jun 09 16:01:00 volumio systemd[1]: Started Raise network interfaces. Jun 09 16:01:00 volumio systemd-logind[476]: New seat seat0. Jun 09 16:01:00 volumio systemd[1]: Started Login Service. Jun 09 16:01:00 volumio kernel: Under-voltage detected! (0x00050005) Jun 09 16:01:01 volumio loadcpufreq[567]: Loading cpufreq kernel modules...done (none). Jun 09 16:01:01 volumio systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Jun 09 16:01:01 volumio systemd[1]: Starting LSB: set CPUFreq kernel parameters... Jun 09 16:01:01 volumio cpufrequtils[602]: CPUFreq Utilities: Setting performance CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Jun 09 16:01:01 volumio systemd[1]: Started LSB: set CPUFreq kernel parameters. Jun 09 16:01:01 volumio haveged[434]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Jun 09 16:01:01 volumio haveged[434]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Jun 09 16:01:01 volumio haveged[434]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99795 Jun 09 16:01:01 volumio haveged[434]: haveged: fills: 0, generated: 0 Jun 09 16:01:02 volumio systemd[1]: iptables.service: Succeeded. Jun 09 16:01:02 volumio systemd[1]: Started WPA supplicant. Jun 09 16:01:02 volumio systemd[1]: Reached target Network. Jun 09 16:01:02 volumio systemd[1]: Reached target Network is Online. Jun 09 16:01:02 volumio wpa_supplicant[473]: Successfully initialized wpa_supplicant Jun 09 16:01:02 volumio systemd[1]: Starting LSB: Brings up/down network automatically... Jun 09 16:01:02 volumio systemd[1]: Starting Samba NMB Daemon... Jun 09 16:01:02 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 09 16:01:02 volumio systemd[1]: Starting /etc/rc.local Compatibility... Jun 09 16:01:02 volumio systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Jun 09 16:01:02 volumio systemd[1]: Starting Network Time Service... Jun 09 16:01:02 volumio systemd[1]: Starting Music Player Daemon... Jun 09 16:01:02 volumio systemd[1]: Starting Permit User Sessions... Jun 09 16:01:02 volumio systemd[1]: Started /etc/rc.local Compatibility. Jun 09 16:01:02 volumio systemd[1]: Started Permit User Sessions. Jun 09 16:01:02 volumio systemd[1]: Starting Terminate Plymouth Boot Screen... Jun 09 16:01:02 volumio systemd[1]: Starting Hold until boot process finishes up... Jun 09 16:01:02 volumio systemd[1]: Received SIGRTMIN+21 from PID 234 (plymouthd). Jun 09 16:01:02 volumio systemd[1]: Received SIGRTMIN+21 from PID 234 (plymouthd). Jun 09 16:01:02 volumio ifplugd[623]: Network Interface Plugging Daemon...error: unexpectedly disconnected from boot status daemon Jun 09 16:01:02 volumio systemd[1]: plymouth-start.service: Succeeded. Jun 09 16:01:02 volumio systemd[1]: plymouth-quit.service: Succeeded. Jun 09 16:01:02 volumio systemd[1]: Started Terminate Plymouth Boot Screen. Jun 09 16:01:02 volumio systemd[1]: plymouth-quit-wait.service: Succeeded. Jun 09 16:01:02 volumio systemd[1]: Started Hold until boot process finishes up. Jun 09 16:01:02 volumio systemd[1]: Started Getty on tty1. Jun 09 16:01:02 volumio systemd[1]: Reached target Login Prompts. Jun 09 16:01:02 volumio ifplugd(eth0)[650]: ifplugd 0.28 initializing. Jun 09 16:01:02 volumio ifplugd(eth0)[650]: Using interface eth0/B8:27:EB:02:07:5A with driver (version: 5.10.92-v7+) Jun 09 16:01:03 volumio systemd[1]: systemd-rfkill.service: Succeeded. Jun 09 16:01:03 volumio ntpd[629]: ntpd 4.2.8p12@1.3728-o (1): Starting Jun 09 16:01:03 volumio systemd[1]: Started Network Time Service. Jun 09 16:01:03 volumio ntpd[629]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Jun 09 16:01:04 volumio ifplugd(eth0)[650]: Using detection mode: SIOCETHTOOL Jun 09 16:01:04 volumio ifplugd(eth0)[650]: Initialization complete, link beat not detected. Jun 09 16:01:04 volumio ntpd[655]: proto: precision = 1.407 usec (-19) Jun 09 16:01:04 volumio ntpd[655]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jun 09 16:01:04 volumio ntpd[655]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-06-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Jun 09 16:01:04 volumio ntpd[655]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): will expire in less than 19 days Jun 09 16:01:04 volumio ntpd[655]: Listen and drop on 0 v6wildcard [::]:123 Jun 09 16:01:04 volumio ntpd[655]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jun 09 16:01:04 volumio ntpd[655]: Listen normally on 2 lo 127.0.0.1:123 Jun 09 16:01:04 volumio ntpd[655]: Listening on routing socket on fd #19 for interface updates Jun 09 16:01:04 volumio ntpd[655]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 09 16:01:04 volumio ntpd[655]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 09 16:01:04 volumio ifplugd[623]: start eth0...done. Jun 09 16:01:04 volumio systemd[1]: Started LSB: Brings up/down network automatically. Jun 09 16:01:04 volumio volumio-remote-updater[477]: Error: No active session Jun 09 16:01:04 volumio volumio-remote-updater[477]: [2022-06-09 16:01:04] [info] asio async_connect error: system:111 (Connection refused) Jun 09 16:01:04 volumio volumio-remote-updater[477]: [2022-06-09 16:01:04] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jun 09 16:01:04 volumio volumio-remote-updater[477]: [2022-06-09 16:01:04] [error] handle_connect error: Underlying Transport Error Jun 09 16:01:04 volumio ntpd[655]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jun 09 16:01:05 volumio kernel: Bluetooth: Core ver 2.22 Jun 09 16:01:05 volumio kernel: NET: Registered protocol family 31 Jun 09 16:01:05 volumio kernel: Bluetooth: HCI device and connection manager initialized Jun 09 16:01:05 volumio kernel: Bluetooth: HCI socket layer initialized Jun 09 16:01:05 volumio kernel: Bluetooth: L2CAP socket layer initialized Jun 09 16:01:05 volumio kernel: Bluetooth: SCO socket layer initialized Jun 09 16:01:05 volumio kernel: Bluetooth: HCI UART driver ver 2.3 Jun 09 16:01:05 volumio kernel: Bluetooth: HCI UART protocol H4 registered Jun 09 16:01:05 volumio kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Jun 09 16:01:05 volumio kernel: Bluetooth: HCI UART protocol Broadcom registered Jun 09 16:01:05 volumio btuart[480]: bcm43xx_init Jun 09 16:01:05 volumio btuart[480]: Flash firmware /lib/firmware/brcm/BCM43430A1.hcd Jun 09 16:01:05 volumio btuart[480]: Set BDADDR UART: b8:27:eb:a8:ad:f0 Jun 09 16:01:05 volumio btuart[480]: Set Controller UART speed to 460800 bit/s Jun 09 16:01:05 volumio btuart[480]: Device setup complete Jun 09 16:01:05 volumio ntpd[655]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jun 09 16:01:05 volumio systemd[1]: Starting Load/Save RF Kill Switch Status... Jun 09 16:01:05 volumio systemd[1]: Started Configure Bluetooth Modems connected by UART. Jun 09 16:01:05 volumio volumio[486]: Could not open config: /tmp/upmpdcli.conf Jun 09 16:01:05 volumio systemd[1]: Started Load/Save RF Kill Switch Status. Jun 09 16:01:05 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jun 09 16:01:05 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jun 09 16:01:05 volumio systemd[1]: Created slice system-bthelper.slice. Jun 09 16:01:05 volumio systemd[1]: Starting Raspberry Pi bluetooth helper... Jun 09 16:01:06 volumio bthelper[666]: Raspberry Pi BDADDR already set Jun 09 16:01:06 volumio systemd[1]: Started Raspberry Pi bluetooth helper. Jun 09 16:01:06 volumio systemd[1]: Starting Bluetooth service... Jun 09 16:01:06 volumio ntpd[655]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Jun 09 16:01:07 volumio bluetoothd[675]: Bluetooth daemon 5.50 Jun 09 16:01:07 volumio bluetoothd[675]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Jun 09 16:01:07 volumio systemd[1]: Started Bluetooth service. Jun 09 16:01:07 volumio systemd[1]: Reached target Bluetooth. Jun 09 16:01:07 volumio nmbd[633]: [2022/06/09 16:01:07.469504, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Jun 09 16:01:07 volumio nmbd[633]: started asyncdns process 677 Jun 09 16:01:07 volumio nmbd[633]: [2022/06/09 16:01:07.474070, 0] ../lib/util/become_daemon.c:149(daemon_status) Jun 09 16:01:07 volumio nmbd[633]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Jun 09 16:01:07 volumio nmbd[633]: [2022/06/09 16:01:07.474415, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Jun 09 16:01:07 volumio nmbd[633]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Jun 09 16:01:07 volumio bluetoothd[675]: Starting SDP server Jun 09 16:01:07 volumio bluetoothd[675]: Excluding (cli) sap Jun 09 16:01:07 volumio ntpd[655]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jun 09 16:01:07 volumio kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Jun 09 16:01:07 volumio kernel: Bluetooth: BNEP filters: protocol multicast Jun 09 16:01:07 volumio kernel: Bluetooth: BNEP socket layer initialized Jun 09 16:01:07 volumio bluetoothd[675]: Bluetooth management interface 1.18 initialized Jun 09 16:01:07 volumio dbus-daemon[470]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=675 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Jun 09 16:01:07 volumio systemd[1]: Starting Hostname Service... Jun 09 16:01:07 volumio bluetoothd[675]: Failed to set privacy: Rejected (0x0b) Jun 09 16:01:08 volumio dbus-daemon[470]: [system] Successfully activated service 'org.freedesktop.hostname1' Jun 09 16:01:08 volumio systemd[1]: Started Hostname Service. Jun 09 16:01:09 volumio volumio-remote-updater[477]: [2022-06-09 16:01:09] [info] asio async_connect error: system:111 (Connection refused) Jun 09 16:01:09 volumio volumio-remote-updater[477]: [2022-06-09 16:01:09] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jun 09 16:01:09 volumio volumio-remote-updater[477]: [2022-06-09 16:01:09] [error] handle_connect error: Underlying Transport Error Jun 09 16:01:10 volumio wireless.js[483]: Cleaning previous... Jun 09 16:01:10 volumio sudo[693]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jun 09 16:01:10 volumio sudo[693]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:10 volumio sudo[693]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:10 volumio sudo[695]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jun 09 16:01:10 volumio sudo[695]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:10 volumio systemd[1]: systemd-rfkill.service: Succeeded. Jun 09 16:01:10 volumio mpd[652]: Jun 09 16:01 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 09 16:01:10 volumio sudo[695]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:10 volumio mpd[652]: Jun 09 16:01 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Jun 09 16:01:10 volumio mpd[652]: Jun 09 16:01 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Jun 09 16:01:10 volumio wireless.js[483]: Stopped aP Jun 09 16:01:10 volumio wireless.js[483]: Start wireless flow Jun 09 16:01:10 volumio wireless.js[483]: Stopped hotspot (if there).. Jun 09 16:01:11 volumio bthelper[666]: Changing power off succeeded Jun 09 16:01:11 volumio bthelper[666]: [CHG] Controller B8:27:EB:A8:AD:F0 Powered: no Jun 09 16:01:11 volumio bthelper[666]: [CHG] Controller B8:27:EB:A8:AD:F0 Discovering: no Jun 09 16:01:11 volumio bthelper[666]: [CHG] Controller B8:27:EB:A8:AD:F0 Class: 0x00000000 Jun 09 16:01:11 volumio bthelper[666]: [CHG] Controller B8:27:EB:A8:AD:F0 Class: 0x0000041c Jun 09 16:01:11 volumio bthelper[666]: Changing power on succeeded Jun 09 16:01:12 volumio systemd[1]: Started Music Player Daemon. Jun 09 16:01:12 volumio sudo[702]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jun 09 16:01:12 volumio sudo[702]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:12 volumio sudo[702]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:12 volumio sudo[712]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jun 09 16:01:12 volumio sudo[712]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:12 volumio sudo[712]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:12 volumio wireless.js[483]: DHCP IP Jun 09 16:01:12 volumio wireless.js[483]: Start ap Jun 09 16:01:12 volumio wpa_supplicant[714]: Successfully initialized wpa_supplicant Jun 09 16:01:12 volumio sudo[715]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Jun 09 16:01:12 volumio sudo[715]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:12 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jun 09 16:01:12 volumio dhcpcd[716]: dev: loaded udev Jun 09 16:01:12 volumio dhcpcd-run-hooks[734]: wlan0: starting wpa_supplicant Jun 09 16:01:12 volumio dhcpcd-run-hooks[739]: wlan0: failed to start wpa_supplicant Jun 09 16:01:12 volumio dhcpcd-run-hooks[740]: 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 Jun 09 16:01:12 volumio dhcpcd[716]: wlan0: connected to Access Point `' Jun 09 16:01:12 volumio dhcpcd[716]: no interfaces have a carrier Jun 09 16:01:12 volumio dhcpcd[716]: forked to background, child pid 750 Jun 09 16:01:12 volumio dhcpcd[750]: eth0: waiting for carrier Jun 09 16:01:12 volumio dhcpcd[750]: wlan0: waiting for carrier Jun 09 16:01:12 volumio sudo[715]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:13 volumio wpa_supplicant[738]: wlan0: Trying to associate with SSID 'CU-DA5C' Jun 09 16:01:13 volumio wireless.js[483]: trying... Jun 09 16:01:14 volumio kernel: cam1-reg: disabling Jun 09 16:01:14 volumio kernel: cam-dummy-reg: disabling Jun 09 16:01:14 volumio sudo[752]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:14 volumio sudo[752]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:14 volumio sudo[752]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:14 volumio wireless.js[483]: trying... Jun 09 16:01:14 volumio sudo[755]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:14 volumio sudo[755]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:14 volumio sudo[755]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:15 volumio wireless.js[483]: trying... Jun 09 16:01:17 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=98:00:6a:06:da:5c status_code=16 Jun 09 16:01:17 volumio volumio-remote-updater[477]: [2022-06-09 16:01:17] [info] asio async_connect error: system:111 (Connection refused) Jun 09 16:01:17 volumio volumio-remote-updater[477]: [2022-06-09 16:01:17] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jun 09 16:01:17 volumio volumio-remote-updater[477]: [2022-06-09 16:01:17] [error] handle_connect error: Underlying Transport Error Jun 09 16:01:17 volumio sudo[758]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:17 volumio sudo[758]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:17 volumio sudo[758]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:17 volumio wireless.js[483]: trying... Jun 09 16:01:17 volumio sudo[761]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:17 volumio sudo[761]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:17 volumio sudo[761]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:17 volumio dhcpcd[750]: wlan0: carrier acquired Jun 09 16:01:17 volumio dhcpcd[750]: DUID 00:01:00:01:2a:34:d5:c2:b8:27:eb:02:07:5a Jun 09 16:01:17 volumio dhcpcd[750]: wlan0: IAID eb:57:52:0f Jun 09 16:01:17 volumio dhcpcd[750]: wlan0: adding address fe80::72c2:ee93:fb6b:e74d Jun 09 16:01:17 volumio dhcpcd[750]: ipv6_addaddr1: Permission denied Jun 09 16:01:18 volumio dhcpcd[750]: wlan0: soliciting an IPv6 router Jun 09 16:01:18 volumio wpa_supplicant[738]: wlan0: Trying to associate with SSID 'CU-DA5C' Jun 09 16:01:18 volumio dhcpcd[750]: wlan0: carrier lost Jun 09 16:01:18 volumio wireless.js[483]: trying... Jun 09 16:01:19 volumio sudo[775]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:19 volumio sudo[775]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:19 volumio sudo[775]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:19 volumio wireless.js[483]: trying... Jun 09 16:01:19 volumio sudo[778]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:19 volumio sudo[778]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:19 volumio sudo[778]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:20 volumio wireless.js[483]: trying... Jun 09 16:01:22 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=98:00:6a:06:da:5c status_code=16 Jun 09 16:01:22 volumio sudo[781]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:22 volumio sudo[781]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:22 volumio sudo[781]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:22 volumio wireless.js[483]: trying... Jun 09 16:01:22 volumio sudo[784]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:22 volumio sudo[784]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:22 volumio sudo[784]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:23 volumio wireless.js[483]: trying... Jun 09 16:01:24 volumio wpa_supplicant[738]: wlan0: Trying to associate with SSID 'CU-DA5C' Jun 09 16:01:24 volumio sudo[787]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:24 volumio sudo[787]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:24 volumio sudo[787]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:24 volumio wireless.js[483]: trying... Jun 09 16:01:24 volumio sudo[790]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:24 volumio sudo[790]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:24 volumio sudo[790]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:25 volumio kernel: Voltage normalised (0x00000000) Jun 09 16:01:25 volumio wireless.js[483]: trying... Jun 09 16:01:27 volumio volumio-remote-updater[477]: [2022-06-09 16:01:27] [info] asio async_connect error: system:111 (Connection refused) Jun 09 16:01:27 volumio volumio-remote-updater[477]: [2022-06-09 16:01:27] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jun 09 16:01:27 volumio volumio-remote-updater[477]: [2022-06-09 16:01:27] [error] handle_connect error: Underlying Transport Error Jun 09 16:01:27 volumio sudo[793]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:27 volumio sudo[793]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:27 volumio sudo[793]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:27 volumio wireless.js[483]: trying... Jun 09 16:01:27 volumio sudo[796]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:27 volumio sudo[796]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:27 volumio sudo[796]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:28 volumio wireless.js[483]: trying... Jun 09 16:01:28 volumio systemd[1]: systemd-fsckd.service: Succeeded. Jun 09 16:01:29 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=98:00:6a:06:da:5c status_code=16 Jun 09 16:01:29 volumio sudo[799]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:29 volumio sudo[799]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:29 volumio sudo[799]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:29 volumio wireless.js[483]: trying... Jun 09 16:01:29 volumio sudo[802]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:29 volumio sudo[802]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:29 volumio sudo[802]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:30 volumio sh[401]: timed out Jun 09 16:01:30 volumio dhcpcd[447]: timed out Jun 09 16:01:30 volumio sh[401]: dhcpcd exited Jun 09 16:01:30 volumio dhcpcd[447]: dhcpcd exited Jun 09 16:01:30 volumio sh[401]: ifup: failed to bring up eth0 Jun 09 16:01:30 volumio systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Jun 09 16:01:30 volumio systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Jun 09 16:01:30 volumio wireless.js[483]: trying... Jun 09 16:01:32 volumio sudo[806]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:32 volumio sudo[806]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:32 volumio sudo[806]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:32 volumio wireless.js[483]: trying... Jun 09 16:01:32 volumio sudo[809]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:32 volumio sudo[809]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:32 volumio sudo[809]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:33 volumio wpa_supplicant[738]: wlan0: Trying to associate with SSID 'CU-DA5C' Jun 09 16:01:33 volumio wireless.js[483]: trying... Jun 09 16:01:33 volumio kernel: Under-voltage detected! (0x00050005) Jun 09 16:01:34 volumio wpa_supplicant[738]: wlan0: Associated with 98:00:6a:06:da:5c Jun 09 16:01:34 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-CONNECTED - Connection to 98:00:6a:06:da:5c completed [id=0 id_str=] Jun 09 16:01:34 volumio dhcpcd[750]: wlan0: carrier acquired Jun 09 16:01:34 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jun 09 16:01:34 volumio dhcpcd[750]: wlan0: connected to Access Point `CU-DA5C' Jun 09 16:01:34 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=CN Jun 09 16:01:34 volumio sudo[812]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:34 volumio dhcpcd[750]: wlan0: IAID eb:57:52:0f Jun 09 16:01:34 volumio sudo[812]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:34 volumio sudo[812]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:34 volumio wireless.js[483]: trying... Jun 09 16:01:35 volumio sudo[816]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:35 volumio sudo[816]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:35 volumio sudo[816]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:35 volumio dhcpcd[750]: wlan0: rebinding lease of 192.168.5.156 Jun 09 16:01:35 volumio dhcpcd[750]: wlan0: soliciting an IPv6 router Jun 09 16:01:35 volumio wireless.js[483]: trying... Jun 09 16:01:37 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-DISCONNECTED bssid=98:00:6a:06:da:5c reason=15 Jun 09 16:01:37 volumio dhcpcd[750]: wlan0: carrier lost Jun 09 16:01:37 volumio volumio-remote-updater[477]: [2022-06-09 16:01:37] [info] asio async_connect error: system:111 (Connection refused) Jun 09 16:01:37 volumio volumio-remote-updater[477]: [2022-06-09 16:01:37] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jun 09 16:01:37 volumio volumio-remote-updater[477]: [2022-06-09 16:01:37] [error] handle_connect error: Underlying Transport Error Jun 09 16:01:37 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Jun 09 16:01:37 volumio sudo[819]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:37 volumio sudo[819]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:37 volumio sudo[819]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:37 volumio wireless.js[483]: trying... Jun 09 16:01:37 volumio sudo[832]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 09 16:01:37 volumio sudo[832]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:37 volumio sudo[832]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:38 volumio systemd[1]: systemd-hostnamed.service: Succeeded. Jun 09 16:01:38 volumio kernel: Voltage normalised (0x00000000) Jun 09 16:01:38 volumio wpa_supplicant[738]: wlan0: Trying to associate with SSID 'CU-DA5C' Jun 09 16:01:38 volumio wireless.js[483]: Overtime, starting plan B Jun 09 16:01:39 volumio systemd[1]: Started Wireless Services. Jun 09 16:01:39 volumio systemd[1]: Started Volumio Backend Module. Jun 09 16:01:39 volumio systemd[1]: Started Volumio Streaming Daemon. Jun 09 16:01:40 volumio volumio-streaming-daemon[848]: ############################ Jun 09 16:01:40 volumio volumio-streaming-daemon[848]: # Volumio Streaming Daemon # Jun 09 16:01:40 volumio volumio-streaming-daemon[848]: # Running on port 7777 # Jun 09 16:01:40 volumio volumio-streaming-daemon[848]: ############################ Jun 09 16:01:40 volumio volumio-streaming-daemon[848]: Environment: Jun 09 16:01:42 volumio kernel: Under-voltage detected! (0x00050005) Jun 09 16:01:42 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=98:00:6a:06:da:5c status_code=16 Jun 09 16:01:42 volumio dhcpcd[750]: wlan0: carrier acquired Jun 09 16:01:42 volumio dhcpcd[750]: wlan0: IAID eb:57:52:0f Jun 09 16:01:43 volumio dhcpcd[750]: wlan0: rebinding lease of 192.168.5.156 Jun 09 16:01:43 volumio volumio[847]: info: ------------------------------------------- Jun 09 16:01:43 volumio volumio[847]: info: ----- Volumio3 ---- Jun 09 16:01:43 volumio volumio[847]: info: ------------------------------------------- Jun 09 16:01:43 volumio volumio[847]: info: ----- System startup ---- Jun 09 16:01:43 volumio volumio[847]: info: ------------------------------------------- Jun 09 16:01:43 volumio dhcpcd[750]: wlan0: soliciting an IPv6 router Jun 09 16:01:44 volumio wpa_supplicant[738]: wlan0: Trying to associate with SSID 'CU-DA5C' Jun 09 16:01:44 volumio dhcpcd[750]: wlan0: carrier lost Jun 09 16:01:45 volumio volumio[847]: info: MYVOLUMIO Environment detected Jun 09 16:01:45 volumio volumio[847]: info: Plugin folders cleanup Jun 09 16:01:45 volumio volumio[847]: info: Scanning into folder /volumio/app/plugins/ Jun 09 16:01:45 volumio volumio[847]: info: Scanning category audio_interface Jun 09 16:01:45 volumio volumio[847]: info: Scanning category miscellanea Jun 09 16:01:45 volumio volumio[847]: info: Scanning category music_service Jun 09 16:01:45 volumio volumio[847]: info: Scanning category plugins.json Jun 09 16:01:45 volumio volumio[847]: info: Scanning category system_controller Jun 09 16:01:45 volumio volumio[847]: info: Scanning category user_interface Jun 09 16:01:45 volumio volumio[847]: info: Scanning into folder /data/plugins/ Jun 09 16:01:45 volumio volumio[847]: info: Plugin folders cleanup completed Jun 09 16:01:45 volumio volumio[847]: info: ------------------------------------------- Jun 09 16:01:45 volumio volumio[847]: info: ----- Core plugins startup ---- Jun 09 16:01:45 volumio volumio[847]: info: ------------------------------------------- Jun 09 16:01:45 volumio volumio[847]: info: Loading plugins from folder /volumio/app/plugins/ Jun 09 16:01:45 volumio volumio[847]: info: Adding plugin upnp to MyMusic Plugins Jun 09 16:01:45 volumio volumio[847]: info: Adding plugin airplay_emulation to MyMusic Plugins Jun 09 16:01:45 volumio volumio[847]: info: Adding plugin upnp_browser to MyMusic Plugins Jun 09 16:01:45 volumio volumio[847]: info: Loading plugins from folder /data/plugins/ Jun 09 16:01:45 volumio volumio[847]: info: Loading plugin "system"... Jun 09 16:01:45 volumio volumio[847]: info: Loading plugin "appearance"... Jun 09 16:01:47 volumio volumio[847]: info: Loading plugin "network"... Jun 09 16:01:47 volumio volumio[847]: info: Refreshing Cached IP Addresses Jun 09 16:01:47 volumio volumio[847]: info: Loading plugin "services"... Jun 09 16:01:47 volumio volumio[847]: info: Loading plugin "alsa_controller"... Jun 09 16:01:47 volumio volumio-remote-updater[477]: [2022-06-09 16:01:47] [connect] Successful connection Jun 09 16:01:47 volumio sudo[894]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 09 16:01:47 volumio sudo[894]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:47 volumio sudo[896]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jun 09 16:01:47 volumio sudo[896]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:47 volumio volumio[847]: info: Loading plugin "wizard"... Jun 09 16:01:47 volumio sudo[894]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:47 volumio sudo[892]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 09 16:01:47 volumio sudo[892]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:47 volumio sudo[896]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:47 volumio kernel: ieee80211 phy0: brcmf_cfg80211_scan: Connecting: status (67) Jun 09 16:01:47 volumio sudo[892]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:47 volumio volumio[847]: info: Loading plugin "volumio_command_line_client"... Jun 09 16:01:47 volumio volumio[847]: info: Loading plugin "upnp"... Jun 09 16:01:47 volumio volumio[847]: info: [1654790507512] Starting Upmpd Daemon Jun 09 16:01:47 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 09 16:01:47 volumio volumio[847]: info: Loading plugin "my_music"... Jun 09 16:01:47 volumio volumio[847]: info: Loading plugin "mpd"... Jun 09 16:01:48 volumio volumio[847]: info: Creating MPD Configuration file Jun 09 16:01:48 volumio volumio[847]: info: Loading plugin "upnp_browser"... Jun 09 16:01:48 volumio sudo[905]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 09 16:01:48 volumio sudo[905]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:48 volumio sudo[905]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:48 volumio sudo[907]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 09 16:01:48 volumio sudo[907]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:48 volumio systemd[1]: Stopping Music Player Daemon... Jun 09 16:01:48 volumio systemd[1]: mpd.service: Succeeded. Jun 09 16:01:48 volumio systemd[1]: Stopped Music Player Daemon. Jun 09 16:01:48 volumio systemd[1]: Starting Music Player Daemon... Jun 09 16:01:49 volumio volumio[847]: info: Loading plugin "networkfs"... Jun 09 16:01:49 volumio volumio[847]: info: Starting Udev Watcher for removable devices Jun 09 16:01:50 volumio volumio[847]: info: Ignoring mount for partition: boot Jun 09 16:01:50 volumio volumio[847]: info: Ignoring mount for partition: volumio Jun 09 16:01:50 volumio volumio[847]: info: Ignoring mount for partition: volumio_data Jun 09 16:01:50 volumio volumio[847]: info: Mounting Device NHAC_LUU_TRU_DI_DONG Jun 09 16:01:50 volumio sudo[918]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/NHAC_LUU_TRU_DI_DONG -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jun 09 16:01:50 volumio sudo[918]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:51 volumio mpd[912]: Jun 09 16:01 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 09 16:01:51 volumio kernel: fuse: init (API version 7.32) Jun 09 16:01:51 volumio systemd[1]: Mounting FUSE Control File System... Jun 09 16:01:51 volumio mpd[912]: Jun 09 16:01 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Jun 09 16:01:51 volumio mpd[912]: Jun 09 16:01 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Jun 09 16:01:51 volumio systemd[1]: Mounted FUSE Control File System. Jun 09 16:01:51 volumio ntfs-3g[925]: Version 2017.3.23AR.3 integrated FUSE 28 Jun 09 16:01:51 volumio ntfs-3g[925]: Mounted /dev/sda1 (Read-Write, label "NHAC LUU TRU DI DONG", NTFS 3.1) Jun 09 16:01:51 volumio ntfs-3g[925]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Jun 09 16:01:51 volumio ntfs-3g[925]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda1,blkdev,blksize=4096 Jun 09 16:01:51 volumio ntfs-3g[925]: Global ownership and permissions enforced, configuration type 7 Jun 09 16:01:51 volumio sudo[918]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:51 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 09 16:01:51 volumio volumio[847]: info: Loading plugin "alarm-clock"... Jun 09 16:01:51 volumio volumio[847]: info: Loading plugin "airplay_emulation"... Jun 09 16:01:52 volumio volumio[847]: info: Starting Shairport Sync Jun 09 16:01:52 volumio volumio[847]: info: Loading plugin "last_100"... Jun 09 16:01:52 volumio volumio[847]: info: Loading plugin "webradio"... Jun 09 16:01:52 volumio volumio[847]: info: Loading plugin "i2s_dacs"... Jun 09 16:01:52 volumio volumio[847]: info: I2S DAC not set, start Auto-detection Jun 09 16:01:52 volumio volumio[847]: info: Loading plugin "volumiodiscovery"... Jun 09 16:01:52 volumio systemd[1]: Started Music Player Daemon. Jun 09 16:01:52 volumio volumio[847]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 09 16:01:52 volumio volumio[847]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 09 16:01:52 volumio volumio[847]: *** WARNING *** For more information see Jun 09 16:01:52 volumio node[847]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 09 16:01:52 volumio volumio[847]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 09 16:01:52 volumio volumio[847]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 09 16:01:52 volumio volumio[847]: *** WARNING *** For more information see Jun 09 16:01:52 volumio node[847]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 09 16:01:52 volumio node[847]: *** WARNING *** For more information see Jun 09 16:01:52 volumio node[847]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 09 16:01:52 volumio node[847]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 09 16:01:52 volumio node[847]: *** WARNING *** For more information see Jun 09 16:01:52 volumio sudo[907]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:52 volumio volumio[847]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 09 16:01:52 volumio volumio[847]: info: Discovery: Started advertising with name: Volumio Jun 09 16:01:52 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 09 16:01:52 volumio volumio[847]: info: Loading plugin "outputs"... Jun 09 16:01:52 volumio volumio[847]: info: Loading plugin "albumart"... Jun 09 16:01:52 volumio volumio[847]: info: Plugin example_plugin is not enabled Jun 09 16:01:52 volumio volumio[847]: info: Loading plugin "inputs"... Jun 09 16:01:52 volumio volumio[847]: info: Loading plugin "updater_comm"... Jun 09 16:01:53 volumio volumio[847]: info: Plugin mpdemulation is not enabled Jun 09 16:01:53 volumio volumio[847]: info: Loading plugin "rest_api"... Jun 09 16:01:53 volumio volumio[847]: info: Loading plugin "websocket"... Jun 09 16:01:53 volumio volumio[847]: info: Loading i18n strings for locale vi Jun 09 16:01:53 volumio volumio[847]: Updating browse sources language Jun 09 16:01:53 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 09 16:01:53 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 09 16:01:53 volumio volumio[847]: info: CoreCommandRouter::initPlayerControls Jun 09 16:01:53 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:53 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:53 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:53 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:53 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:53 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:53 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:53 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:53 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 09 16:01:53 volumio volumio[847]: Express server listening on port 3000 Jun 09 16:01:53 volumio volumio[847]: [Metrics] WebUI: 11s 468.14ms Jun 09 16:01:53 volumio volumio[847]: info: CoreStateMachine::resetVolumioState Jun 09 16:01:53 volumio volumio[847]: info: CoreStateMachine::getcurrentVolume Jun 09 16:01:53 volumio volumio[847]: info: CoreCommandRouter::volumioRetrievevolume Jun 09 16:01:53 volumio volumio[847]: Forking 3 albumart workers Jun 09 16:01:53 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 09 16:01:53 volumio volumio[847]: info: MPD Permissions set Jun 09 16:01:53 volumio volumio[847]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Jun 09 16:01:53 volumio volumio[847]: wlan0 Interface doesn't support scanning : Resource temporarily unavailable Jun 09 16:01:53 volumio volumio[847]: info: Cannot use regular scanning, forcing with ap-force Jun 09 16:01:54 volumio wpa_supplicant[738]: wlan0: Authentication with 98:00:6a:06:da:5c timed out. Jun 09 16:01:54 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-DISCONNECTED bssid=98:00:6a:06:da:5c reason=3 locally_generated=1 Jun 09 16:01:54 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="CU-DA5C" auth_failures=1 duration=10 reason=CONN_FAILED Jun 09 16:01:54 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Jun 09 16:01:55 volumio sudo[964]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Jun 09 16:01:55 volumio sudo[964]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:55 volumio volumio[847]: Starting albumart workers Jun 09 16:01:55 volumio volumio[847]: Starting albumart workers Jun 09 16:01:55 volumio volumio[847]: Starting albumart workers Jun 09 16:01:55 volumio sudo[964]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:55 volumio volumio[847]: info: MPD running with PID912 Jun 09 16:01:55 volumio volumio[847]: ,establishing connection Jun 09 16:01:56 volumio volumio[847]: error: MPD error: The expression evaluated to a falsy value: Jun 09 16:01:56 volumio volumio[847]: assert.ok(self.idling) Jun 09 16:01:56 volumio volumio[847]: error: MPD error: The expression evaluated to a falsy value: Jun 09 16:01:56 volumio volumio[847]: assert.ok(self.idling) Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:56 volumio volumio[847]: info: Reloading queue from file Jun 09 16:01:56 volumio volumio[847]: info: VolumeController:: Volume=89 Mute =false Jun 09 16:01:56 volumio volumio[847]: info: CoreStateMachine::pushState Jun 09 16:01:56 volumio volumio[847]: info: CorePlayQueue::getTrack 0 Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::volumioPushState Jun 09 16:01:56 volumio volumio[847]: info: CoreStateMachine::updateTrackBlock Jun 09 16:01:56 volumio volumio[847]: info: CorePlayQueue::getTrackBlock Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::volumioRetrievevolume Jun 09 16:01:56 volumio volumio[847]: info: CoreStateMachine::setRepeat null single undefined Jun 09 16:01:56 volumio volumio[847]: info: CoreStateMachine::pushState Jun 09 16:01:56 volumio volumio[847]: info: CorePlayQueue::getTrack 0 Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::volumioPushState Jun 09 16:01:56 volumio volumio[847]: info: CoreStateMachine::setRandom null Jun 09 16:01:56 volumio volumio[847]: info: CoreStateMachine::pushState Jun 09 16:01:56 volumio volumio[847]: info: CorePlayQueue::getTrack 0 Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::volumioPushState Jun 09 16:01:56 volumio volumio[847]: info: Setting Device type: Raspberry PI Jun 09 16:01:56 volumio volumio[847]: error: updateQueue error: null Jun 09 16:01:56 volumio volumio[847]: info: Completed loading Core Plugins Jun 09 16:01:56 volumio volumio[847]: info: Preparing to generate the ALSA configuration file Jun 09 16:01:56 volumio volumio[847]: info: Asound.conf file unchanged, so no further update is needed Jun 09 16:01:56 volumio volumio[847]: info: Output device has changed, restarting MPD Jun 09 16:01:56 volumio volumio[847]: info: Output device has changed, restarting Shairport Sync Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 09 16:01:56 volumio volumio[847]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 09 16:01:56 volumio volumio[847]: info: ___________ START PLUGINS ___________ Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 09 16:01:56 volumio volumio[847]: info: [1654790516746] CoreMusicLibrary::Adding element Media Servers Jun 09 16:01:56 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 09 16:01:56 volumio volumio[847]: Cannot find translation for sourceMedia Servers Jun 09 16:01:57 volumio sudo[1003]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 09 16:01:57 volumio sudo[1003]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:57 volumio sudo[1005]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 09 16:01:57 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:57 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 09 16:01:57 volumio sudo[1005]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:57 volumio sudo[1003]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:57 volumio systemd[1]: Stopping Music Player Daemon... Jun 09 16:01:57 volumio volumio[847]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 09 16:01:57 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:57 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 09 16:01:57 volumio systemd[1]: mpd.service: Succeeded. Jun 09 16:01:57 volumio systemd[1]: Stopped Music Player Daemon. Jun 09 16:01:57 volumio systemd[1]: Starting Music Player Daemon... Jun 09 16:01:57 volumio volumio[847]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 09 16:01:57 volumio volumio[847]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 09 16:01:57 volumio volumio[847]: info: [1654790517752] CoreMusicLibrary::Adding element Last_100 Jun 09 16:01:57 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 09 16:01:57 volumio volumio[847]: Cannot find translation for sourceMedia Servers Jun 09 16:01:57 volumio volumio[847]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 09 16:01:57 volumio volumio[847]: info: [1654790517760] CoreMusicLibrary::Adding element Webradio Jun 09 16:01:57 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 09 16:01:57 volumio volumio[847]: Cannot find translation for sourceMedia Servers Jun 09 16:01:57 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 09 16:01:57 volumio volumio[847]: info: Volumio Calling Home Jun 09 16:01:58 volumio volumio[847]: info: Completed starting Core Plugins Jun 09 16:01:58 volumio volumio[847]: info: ------------------------------------------- Jun 09 16:01:58 volumio volumio[847]: info: ----- MyVolumio plugins startup ---- Jun 09 16:01:58 volumio volumio[847]: info: ------------------------------------------- Jun 09 16:01:58 volumio volumio[847]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 09 16:01:58 volumio volumio[847]: Unhandled rejection Error: No sockets available, cannot start. Jun 09 16:01:58 volumio volumio[847]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Jun 09 16:01:58 volumio volumio[847]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Jun 09 16:01:58 volumio volumio[847]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Jun 09 16:01:58 volumio volumio[847]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Jun 09 16:01:58 volumio volumio[847]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Jun 09 16:01:58 volumio volumio[847]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Jun 09 16:01:58 volumio volumio[847]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Jun 09 16:01:58 volumio volumio[847]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Jun 09 16:01:58 volumio volumio[847]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Jun 09 16:01:58 volumio volumio[847]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Jun 09 16:01:58 volumio volumio[847]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Jun 09 16:01:58 volumio volumio[847]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Jun 09 16:01:58 volumio volumio[847]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Jun 09 16:01:58 volumio volumio[847]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Jun 09 16:01:58 volumio volumio[847]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Jun 09 16:01:58 volumio volumio[847]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jun 09 16:01:58 volumio sudo[1024]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 09 16:01:58 volumio sudo[1024]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:58 volumio sudo[1024]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:58 volumio volumio[847]: info: MPD Permissions set Jun 09 16:01:58 volumio volumio[847]: info: VolumeController:: Volume=89 Mute =false Jun 09 16:01:58 volumio volumio[847]: info: CoreStateMachine::pushState Jun 09 16:01:58 volumio volumio[847]: info: CorePlayQueue::getTrack 0 Jun 09 16:01:58 volumio volumio[847]: info: CoreCommandRouter::volumioPushState Jun 09 16:01:58 volumio sudo[1026]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 09 16:01:58 volumio sudo[1026]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:01:58 volumio sudo[1026]: pam_unix(sudo:session): session closed for user root Jun 09 16:01:58 volumio volumio[847]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 1 Jun 09 16:01:58 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:58 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:58 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:58 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:58 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:58 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:58 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:58 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:58 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 09 16:01:58 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:01:58 volumio volumio[847]: info: Starting Shairport Sync Jun 09 16:01:58 volumio volumio[847]: info: Starting Shairport Sync Jun 09 16:01:58 volumio volumio[847]: info: Starting Shairport Sync Jun 09 16:01:59 volumio mpd[1022]: Jun 09 16:01 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 09 16:01:59 volumio mpd[1022]: Jun 09 16:01 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Jun 09 16:01:59 volumio mpd[1022]: Jun 09 16:01 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Jun 09 16:02:00 volumio sudo[1034]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 09 16:02:00 volumio systemd[1]: Started Music Player Daemon. Jun 09 16:02:00 volumio sudo[1034]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:02:00 volumio sudo[1005]: pam_unix(sudo:session): session closed for user root Jun 09 16:02:00 volumio sudo[1040]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 09 16:02:00 volumio sudo[1040]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:02:00 volumio sudo[1036]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 09 16:02:00 volumio sudo[1036]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:02:00 volumio sudo[1038]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 09 16:02:00 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 09 16:02:00 volumio systemd[1]: shairport-sync.service: Succeeded. Jun 09 16:02:00 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 09 16:02:00 volumio sudo[1038]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 09 16:02:00 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 09 16:02:00 volumio sudo[1034]: pam_unix(sudo:session): session closed for user root Jun 09 16:02:00 volumio volumio[847]: info: Shairport-Sync Started Jun 09 16:02:00 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 09 16:02:00 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Jun 09 16:02:00 volumio volumio[847]: Error adding Membership: Error: addMembership EINVAL Jun 09 16:02:00 volumio sudo[1040]: pam_unix(sudo:session): session closed for user root Jun 09 16:02:00 volumio systemd[1]: shairport-sync.service: Succeeded. Jun 09 16:02:00 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 09 16:02:00 volumio volumio[847]: error: updateQueue error: null Jun 09 16:02:00 volumio volumio[847]: info: CoreCommandRouter::volumioGetState Jun 09 16:02:00 volumio volumio[847]: info: CorePlayQueue::getTrack 0 Jun 09 16:02:00 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 09 16:02:00 volumio sudo[1036]: pam_unix(sudo:session): session closed for user root Jun 09 16:02:00 volumio sudo[1038]: pam_unix(sudo:session): session closed for user root Jun 09 16:02:00 volumio volumio[847]: info: Upmpdcli Daemon Started Jun 09 16:02:00 volumio volumio[847]: info: Shairport-Sync Started Jun 09 16:02:00 volumio volumio[847]: info: Shairport-Sync Started Jun 09 16:02:00 volumio kernel: Voltage normalised (0x00000000) Jun 09 16:02:01 volumio volumio[847]: error: updateQueue error: null Jun 09 16:02:01 volumio volumio[847]: error: updateQueue error: null Jun 09 16:02:02 volumio volumio-remote-updater[477]: [2022-06-09 16:02:02] [connect] Successful connection Jun 09 16:02:02 volumio volumio-remote-updater[477]: [2022-06-09 16:02:02] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1654790522 101 Jun 09 16:02:02 volumio volumio[847]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 2 Jun 09 16:02:07 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-SSID-REENABLED id=0 ssid="CU-DA5C" Jun 09 16:02:07 volumio wpa_supplicant[738]: wlan0: Trying to associate with SSID 'CU-DA5C' Jun 09 16:02:08 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=98:00:6a:06:da:5c status_code=16 Jun 09 16:02:08 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="CU-DA5C" auth_failures=2 duration=23 reason=CONN_FAILED Jun 09 16:02:08 volumio volumio[847]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.301&uuid=a9724fe953d398bf133edb12a359cbeb" http://updates.volumio.org/downloader-v1/track-device Jun 09 16:02:08 volumio volumio[847]: % Total % Received % Xferd Average Speed Time Time Time Current Jun 09 16:02:08 volumio volumio[847]: Dload Upload Total Spent Left Speed Jun 09 16:02:08 volumio volumio[847]: [132B blob data] Jun 09 16:02:08 volumio volumio[847]: retrying in 5 seconds, trial 0 Jun 09 16:02:08 volumio volumio[847]: info: Volumio Calling Home Jun 09 16:02:10 volumio ntpd[655]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jun 09 16:02:11 volumio ntpd[655]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jun 09 16:02:12 volumio ntpd[655]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jun 09 16:02:13 volumio ntpd[655]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Jun 09 16:02:18 volumio volumio[847]: error: MyVolumio Plugin failed to start in a timely fashion Jun 09 16:02:18 volumio volumio[847]: info: BOOT COMPLETED Jun 09 16:02:18 volumio volumio[847]: [Metrics] CommandRouter: 34s 469.35ms Jun 09 16:02:18 volumio volumio[847]: info: CoreCommandRouter::volumiosetStartupVolume Jun 09 16:02:18 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 09 16:02:18 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 09 16:02:18 volumio volumio[847]: info: CoreCommandRouter::Close All Modals sent Jun 09 16:02:18 volumio volumio[847]: info: CoreCommandRouter::Close All Modals sent Jun 09 16:02:18 volumio volumio[847]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.301&uuid=a9724fe953d398bf133edb12a359cbeb" http://updates.volumio.org/downloader-v1/track-device Jun 09 16:02:18 volumio volumio[847]: % Total % Received % Xferd Average Speed Time Time Time Current Jun 09 16:02:18 volumio volumio[847]: Dload Upload Total Spent Left Speed Jun 09 16:02:18 volumio volumio[847]: [132B blob data] Jun 09 16:02:18 volumio volumio[847]: retrying in 5 seconds, trial 1 Jun 09 16:02:18 volumio volumio[847]: info: Volumio Calling Home Jun 09 16:02:19 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 09 16:02:19 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 09 16:02:19 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 09 16:02:27 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 09 16:02:27 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 09 16:02:28 volumio volumio[847]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.301&uuid=a9724fe953d398bf133edb12a359cbeb" http://updates.volumio.org/downloader-v1/track-device Jun 09 16:02:28 volumio volumio[847]: % Total % Received % Xferd Average Speed Time Time Time Current Jun 09 16:02:28 volumio volumio[847]: Dload Upload Total Spent Left Speed Jun 09 16:02:28 volumio volumio[847]: [132B blob data] Jun 09 16:02:28 volumio volumio[847]: retrying in 5 seconds, trial 2 Jun 09 16:02:28 volumio volumio[847]: info: Volumio Calling Home Jun 09 16:02:32 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-SSID-REENABLED id=0 ssid="CU-DA5C" Jun 09 16:02:32 volumio wpa_supplicant[738]: wlan0: Trying to associate with SSID 'CU-DA5C' Jun 09 16:02:32 volumio systemd[1]: nmbd.service: Start operation timed out. Terminating. Jun 09 16:02:32 volumio systemd[1]: nmbd.service: Main process exited, code=killed, status=15/TERM Jun 09 16:02:32 volumio systemd[1]: nmbd.service: Failed with result 'timeout'. Jun 09 16:02:32 volumio systemd[1]: Failed to start Samba NMB Daemon. Jun 09 16:02:32 volumio systemd[1]: Starting Samba Winbind Daemon... Jun 09 16:02:33 volumio winbindd[1080]: [2022/06/09 16:02:33.311475, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Jun 09 16:02:33 volumio winbindd[1080]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jun 09 16:02:33 volumio wpa_supplicant[738]: wlan0: Associated with 98:00:6a:06:da:5c Jun 09 16:02:33 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-CONNECTED - Connection to 98:00:6a:06:da:5c completed [id=0 id_str=] Jun 09 16:02:33 volumio dhcpcd[750]: wlan0: carrier acquired Jun 09 16:02:33 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jun 09 16:02:33 volumio wpa_supplicant[738]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=CN Jun 09 16:02:33 volumio dhcpcd[750]: wlan0: IAID eb:57:52:0f Jun 09 16:02:33 volumio dhcpcd[750]: wlan0: rebinding lease of 192.168.5.156 Jun 09 16:02:33 volumio dhcpcd[750]: wlan0: soliciting an IPv6 router Jun 09 16:02:33 volumio dhcpcd[750]: wlan0: probing address 192.168.5.156/24 Jun 09 16:02:34 volumio winbindd[1080]: [2022/06/09 16:02:34.049820, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 09 16:02:34 volumio winbindd[1080]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jun 09 16:02:34 volumio systemd[1]: Started Samba Winbind Daemon. Jun 09 16:02:34 volumio systemd[1]: Starting Samba SMB Daemon... Jun 09 16:02:35 volumio winbindd[1080]: [2022/06/09 16:02:35.318813, 0] ../source3/winbindd/wb_lookupsids.c:659(wb_lookupsids_recv) Jun 09 16:02:35 volumio winbindd[1080]: res_names->count = 1, expected 2 Jun 09 16:02:35 volumio systemd[1]: Started Samba SMB Daemon. Jun 09 16:02:35 volumio systemd[1]: Reached target Multi-User System. Jun 09 16:02:35 volumio systemd[1]: Reached target Graphical Interface. Jun 09 16:02:35 volumio smbd[1085]: [2022/06/09 16:02:35.369339, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 09 16:02:35 volumio smbd[1085]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jun 09 16:02:35 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Jun 09 16:02:35 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jun 09 16:02:35 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Jun 09 16:02:35 volumio systemd[1]: Startup finished in 11.222s (kernel) + 1min 44.389s (userspace) = 1min 55.611s. Jun 09 16:02:38 volumio dhcpcd[750]: wlan0: leased 192.168.5.156 for 86400 seconds Jun 09 16:02:40 volumio avahi-daemon[468]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.5.156. Jun 09 16:02:40 volumio dhcpcd[750]: wlan0: adding route to 192.168.5.0/24 Jun 09 16:02:40 volumio dhcpcd[750]: wlan0: adding default route via 192.168.5.1 Jun 09 16:02:40 volumio avahi-daemon[468]: New relevant interface wlan0.IPv4 for mDNS. Jun 09 16:02:40 volumio avahi-daemon[468]: Registering new address record for 192.168.5.156 on wlan0.IPv4. Jun 09 16:02:41 volumio volumio[847]: info: Discovery: adding 815c44c3-f099-4f15-8e87-83860b2be8d0 Jun 09 16:02:41 volumio volumio[847]: info: mDNS: Found device Volumio Jun 09 16:02:41 volumio volumio[847]: info: CoreCommandRouter::volumioGetState Jun 09 16:02:41 volumio volumio[847]: info: CorePlayQueue::getTrack 0 Jun 09 16:02:42 volumio ntpd[655]: Listen normally on 3 wlan0 192.168.5.156:123 Jun 09 16:02:42 volumio ntpd[655]: new interface(s) found: waking up resolver Jun 09 16:02:42 volumio volumio[1049]: Generating RSA private key, 4096 bit long modulus (2 primes) Jun 09 16:02:46 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 09 16:02:46 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 09 16:02:46 volumio volumio[847]: info: Discovery: Getting this device information Jun 09 16:02:46 volumio volumio[847]: info: CoreCommandRouter::volumioGetState Jun 09 16:02:46 volumio volumio[847]: info: CorePlayQueue::getTrack 0 Jun 09 16:02:46 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 09 16:02:46 volumio volumio[847]: verbose: New Socket.io Connection to 192.168.5.156:3000 from 192.168.5.154 UA: Dart/3.4 (dart:io) Total Clients: 3 Jun 09 16:02:46 volumio volumio[847]: info: CoreCommandRouter::volumioGetState Jun 09 16:02:46 volumio volumio[847]: info: CorePlayQueue::getTrack 0 Jun 09 16:02:46 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 09 16:02:46 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 09 16:02:48 volumio volumio[847]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 09 16:02:48 volumio volumio[847]: Error: certificate is not yet valid Jun 09 16:02:48 volumio volumio[847]: at TLSSocket.onConnectSecure (_tls_wrap.js:1497:34) Jun 09 16:02:48 volumio volumio[847]: at TLSSocket.emit (events.js:315:20) Jun 09 16:02:48 volumio volumio[847]: at TLSSocket._finishInit (_tls_wrap.js:932:8) Jun 09 16:02:48 volumio volumio[847]: at TLSWrap.ssl.onhandshakedone (_tls_wrap.js:706:12) { Jun 09 16:02:48 volumio volumio[847]: code: 'CERT_NOT_YET_VALID' Jun 09 16:02:48 volumio volumio[847]: } Jun 09 16:02:48 volumio volumio[847]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 09 16:02:50 volumio sudo[1128]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2022-06-09 16:01 Jun 09 16:02:50 volumio sudo[1128]: 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="3cfa1502993c2310fc263d6ebda1707071fe4cc2" VOLUMIO_FE_VERSION="8efe4f08f83e5de574651b8ed2333629c140d365" VOLUMIO_FE3_VERSION="8f1d07fcde806ea34f52cff908ec76359e14970e" VOLUMIO_BE_VERSION="e249dfa388452e6b8443121dc9b4cabca459c531" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 09 Jun 2022 05:55:51 PM CEST" VOLUMIO_VERSION="3.301" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="6a8974e587cd4bab189d231f79b65462"