-- Logs begin at Tue 2025-04-15 07:51:57 UTC, end at Tue 2025-04-15 07:53:03 UTC. -- Apr 15 07:52:00 volumio systemd-fsck[840]: , 441:7d/00, 442:ac/00, 443:20/00, 444:c0/00, 445:74/00, 446:09/00 Apr 15 07:52:00 volumio systemd-fsck[840]: , 447:b4/00, 448:0e/00, 449:bb/00, 450:07/00, 452:cd/00, 453:10/00 Apr 15 07:52:00 volumio systemd-fsck[840]: , 454:eb/00, 455:f2/00, 456:31/00, 457:c0/00, 458:cd/00, 459:16/00 Apr 15 07:52:00 volumio systemd-fsck[840]: , 460:cd/00, 461:19/00, 462:f4/00, 463:eb/00, 464:fd/00, 465:8a/00 Apr 15 07:52:00 volumio systemd-fsck[840]: , 466:16/00, 467:74/00, 468:7b/00, 469:06/00, 470:cd/00, 471:13/00 Apr 15 07:52:00 volumio systemd-fsck[840]: , 472:07/00, 473:c3/00, 474:42/00, 475:6f/00, 476:6f/00, 477:74/00 Apr 15 07:52:00 volumio systemd-fsck[840]: , 478:20/00, 479:65/00, 480:72/00, 481:72/00, 482:6f/00, 483:72/00 Apr 15 07:52:00 volumio systemd-fsck[840]: , 484:0d/00, 485:0a/00, 504:fe/00, 505:02/00, 506:b2/00, 507:3e/00 Apr 15 07:52:00 volumio systemd-fsck[840]: , 508:18/00, 509:37/00 Apr 15 07:52:00 volumio systemd-fsck[840]: Not automatically fixing this. Apr 15 07:52:00 volumio systemd-fsck[840]: /dev/sda1: 18 files, 159614/344788 clusters Apr 15 07:52:00 volumio systemd[1]: Started File System Check on /dev/disk/by-uuid/0A5D-C90D. Apr 15 07:52:00 volumio systemd[1]: Mounting /boot... Apr 15 07:52:00 volumio kernel: FAT-fs (sda1): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! Apr 15 07:52:00 volumio systemd[1]: Mounted /boot. Apr 15 07:52:00 volumio systemd[1]: Reached target Local File Systems. Apr 15 07:52:00 volumio systemd[1]: Started ifup for wlan0. Apr 15 07:52:00 volumio systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Apr 15 07:52:00 volumio systemd[1]: Starting Preprocess NFS configuration... Apr 15 07:52:00 volumio systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Apr 15 07:52:00 volumio systemd[1]: Starting Create Volatile Files and Directories... Apr 15 07:52:00 volumio systemd[1]: Started ifup for eth0. Apr 15 07:52:00 volumio systemd[1]: Starting Raise network interfaces... Apr 15 07:52:00 volumio systemd[1]: Received SIGRTMIN+20 from PID 412 (plymouthd). Apr 15 07:52:00 volumio systemd[1]: plymouth-read-write.service: Succeeded. Apr 15 07:52:00 volumio systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Apr 15 07:52:00 volumio systemd[1]: nfs-config.service: Succeeded. Apr 15 07:52:00 volumio systemd[1]: Started Preprocess NFS configuration. Apr 15 07:52:00 volumio systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Apr 15 07:52:00 volumio systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Apr 15 07:52:00 volumio systemd[1]: Reached target NFS client services. Apr 15 07:52:00 volumio systemd[1]: Started Create Volatile Files and Directories. Apr 15 07:52:00 volumio systemd[1]: Starting RPC bind portmap service... Apr 15 07:52:00 volumio systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Apr 15 07:52:00 volumio systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Apr 15 07:52:00 volumio systemd[1]: Starting Update UTMP about System Boot/Shutdown... Apr 15 07:52:00 volumio kernel: warning: `iwconfig' uses wireless extensions which will stop working for Wi-Fi 7 hardware; use nl80211 Apr 15 07:52:00 volumio systemd[1]: Started RPC bind portmap service. Apr 15 07:52:00 volumio systemd[1]: Reached target Remote File Systems (Pre). Apr 15 07:52:00 volumio systemd[1]: Reached target Remote File Systems. Apr 15 07:52:00 volumio systemd[1]: Reached target RPC Port Mapper. Apr 15 07:52:00 volumio systemd[1]: Started Update UTMP about System Boot/Shutdown. Apr 15 07:52:00 volumio systemd[1]: Reached target System Initialization. Apr 15 07:52:00 volumio systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Apr 15 07:52:00 volumio systemd[1]: Started Daily man-db regeneration. Apr 15 07:52:00 volumio systemd[1]: Listening on D-Bus System Message Bus Socket. Apr 15 07:52:00 volumio systemd[1]: Started Daily Cleanup of Temporary Directories. Apr 15 07:52:00 volumio systemd[1]: Started Daily apt download activities. Apr 15 07:52:00 volumio systemd[1]: Started Daily apt upgrade and clean activities. Apr 15 07:52:00 volumio systemd[1]: Reached target Timers. Apr 15 07:52:00 volumio systemd[1]: Listening on triggerhappy.socket. Apr 15 07:52:00 volumio systemd[1]: Reached target Sockets. Apr 15 07:52:00 volumio systemd[1]: Reached target Basic System. Apr 15 07:52:00 volumio systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Apr 15 07:52:00 volumio systemd[1]: Starting triggerhappy global hotkey daemon... Apr 15 07:52:00 volumio systemd[1]: Started Volumio Log Rotation Service. Apr 15 07:52:00 volumio systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Apr 15 07:52:00 volumio systemd[1]: Started volumio-remote-updater.service. Apr 15 07:52:00 volumio systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Apr 15 07:52:00 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Apr 15 07:52:00 volumio systemd[1]: Starting Wireless Services... Apr 15 07:52:00 volumio systemd[1]: Starting Bluetooth service... Apr 15 07:52:00 volumio kernel: 8021q: 802.1Q VLAN Support v1.8 Apr 15 07:52:00 volumio systemd[1]: Started Volumio Iptables Module. Apr 15 07:52:00 volumio systemd[1]: Started Manage Sound Card State (restore and store). Apr 15 07:52:00 volumio systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Apr 15 07:52:00 volumio systemd[1]: Starting Volumio Time Update Utility... Apr 15 07:52:00 volumio alsactl[928]: alsactl 1.1.8 daemon started Apr 15 07:52:00 volumio systemd[1]: Starting DHCP Client Daemon... Apr 15 07:52:00 volumio systemd[1]: Started D-Bus System Message Bus. Apr 15 07:52:00 volumio systemd[1]: Starting WPA supplicant... Apr 15 07:52:00 volumio systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Apr 15 07:52:00 volumio systemd[1]: Starting Save/Restore Sound Card State... Apr 15 07:52:00 volumio systemd[1]: Starting Login Service... Apr 15 07:52:00 volumio systemd[1]: Started MPD Monitor Service. Apr 15 07:52:00 volumio alsactl[928]: No state is present for card PCH Apr 15 07:52:00 volumio alsactl[928]: Found hardware: "HDA-Intel" "Realtek ALC233" "HDA:10ec0235,80862074,00100002 HDA:8086280b,80860101,00100000" "0x8086" "0x2074" Apr 15 07:52:00 volumio alsactl[928]: Hardware is initialized using a generic method Apr 15 07:52:00 volumio alsactl[928]: No state is present for card PCH Apr 15 07:52:00 volumio alsactl[928]: No state is present for card UAC2 Apr 15 07:52:00 volumio alsactl[928]: Found hardware: "USB-Audio" "USB Mixer" "USB249c:9326" "" "" Apr 15 07:52:00 volumio alsactl[928]: Hardware is initialized using a generic method Apr 15 07:52:00 volumio alsactl[928]: No state is present for card UAC2 Apr 15 07:52:00 volumio volumio-time-update[929]: volumio-time-update-util: Fetching time from Volumio... Apr 15 07:52:00 volumio mpd_monitor.sh[936]: MPD Monitor Service: Starting MPD Monitor Service Apr 15 07:52:00 volumio thd[920]: Unable to parse trigger line: Apr 15 07:52:00 volumio thd[920]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Apr 15 07:52:00 volumio thd[920]: Unable to parse trigger line: Apr 15 07:52:00 volumio thd[920]: Found socket passed from systemd Apr 15 07:52:00 volumio alsactl[934]: No state is present for card PCH Apr 15 07:52:00 volumio alsactl[934]: Found hardware: "HDA-Intel" "Realtek ALC233" "HDA:10ec0235,80862074,00100002 HDA:8086280b,80860101,00100000" "0x8086" "0x2074" Apr 15 07:52:00 volumio alsactl[934]: Hardware is initialized using a generic method Apr 15 07:52:00 volumio alsactl[934]: No state is present for card PCH Apr 15 07:52:00 volumio alsactl[934]: No state is present for card UAC2 Apr 15 07:52:00 volumio alsactl[934]: Found hardware: "USB-Audio" "USB Mixer" "USB249c:9326" "" "" Apr 15 07:52:00 volumio alsactl[934]: Hardware is initialized using a generic method Apr 15 07:52:00 volumio alsactl[934]: No state is present for card UAC2 Apr 15 07:52:00 volumio haveged[878]: haveged: ver: 1.9.1; arch: x86; vend: GenuineIntel; build: (gcc 8.3.0 ITV); collect: 128K Apr 15 07:52:00 volumio haveged[878]: haveged: cpu: (L4 VC); data: 32K (L4 V); inst: 32K (L4 V); idx: 24/40; sz: 31410/52825 Apr 15 07:52:00 volumio haveged[878]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99814 Apr 15 07:52:00 volumio haveged[878]: haveged: fills: 0, generated: 0 Apr 15 07:52:00 volumio kernel: Bluetooth: hci0: Waiting for firmware download to complete Apr 15 07:52:00 volumio kernel: Bluetooth: hci0: Firmware loaded in 1532916 usecs Apr 15 07:52:00 volumio kernel: Bluetooth: hci0: Waiting for device to boot Apr 15 07:52:00 volumio kernel: Bluetooth: hci0: Device booted in 13634 usecs Apr 15 07:52:00 volumio systemd-logind[935]: New seat seat0. Apr 15 07:52:00 volumio systemd-logind[935]: Watching system buttons on /dev/input/event2 (Power Button) Apr 15 07:52:00 volumio systemd-logind[935]: Watching system buttons on /dev/input/event1 (Power Button) Apr 15 07:52:00 volumio systemd-logind[935]: Watching system buttons on /dev/input/event0 (Sleep Button) Apr 15 07:52:00 volumio kernel: Bluetooth: hci0: Found Intel DDC parameters: intel/ibt-17-16-1.ddc Apr 15 07:52:00 volumio kernel: Bluetooth: hci0: Applying Intel DDC parameters completed Apr 15 07:52:00 volumio kernel: Bluetooth: hci0: Firmware revision 0.1 build 108 week 45 2022 Apr 15 07:52:00 volumio kernel: Bluetooth: hci0: HCI LE Coded PHY feature bit is set, but its usage is not supported. Apr 15 07:52:00 volumio avahi-daemon[919]: Found user 'avahi' (UID 111) and group 'avahi' (GID 113). Apr 15 07:52:00 volumio avahi-daemon[919]: Successfully dropped root privileges. Apr 15 07:52:00 volumio avahi-daemon[919]: avahi-daemon 0.7 starting up. Apr 15 07:52:00 volumio mpd_monitor.sh[936]: MPD error: Cannot assign requested address Apr 15 07:52:00 volumio mpd_monitor.sh[936]: MPD Monitor Service: MPD Appears to be inactive, restarting Apr 15 07:52:01 volumio mpd_monitor.sh[936]: mpd: no process found Apr 15 07:52:01 volumio bluetoothd[926]: Bluetooth daemon 5.50 Apr 15 07:52:01 volumio volumio-time-update[929]: volumio-time-update-util: Date not found in response Apr 15 07:52:01 volumio volumio-time-update[929]: volumio-time-update-util: Retrying in 5 seconds... Apr 15 07:52:01 volumio volumio-remote-updater[922]: Error: No active session Apr 15 07:52:01 volumio volumio-remote-updater[922]: [2025-04-15 07:52:01] [info] asio async_connect error: system:111 (Connection refused) Apr 15 07:52:01 volumio volumio-remote-updater[922]: [2025-04-15 07:52:01] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 15 07:52:01 volumio volumio-remote-updater[922]: [2025-04-15 07:52:01] [error] handle_connect error: Underlying Transport Error Apr 15 07:52:01 volumio bluetoothd[926]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Apr 15 07:52:02 volumio dhcpcd[930]: no interfaces have a carrier Apr 15 07:52:02 volumio dhcpcd[930]: forked to background, child pid 1022 Apr 15 07:52:02 volumio dhcpcd[930]: no interfaces have a carrier Apr 15 07:52:02 volumio dhcpcd[930]: forked to background, child pid 1022 Apr 15 07:52:02 volumio volumio[924]: Could not open config: /tmp/upmpdcli.conf Apr 15 07:52:02 volumio systemd[1]: Started triggerhappy global hotkey daemon. Apr 15 07:52:02 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 15 07:52:02 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 15 07:52:02 volumio avahi-daemon[919]: Successfully called chroot(). Apr 15 07:52:02 volumio avahi-daemon[919]: Successfully dropped remaining capabilities. Apr 15 07:52:02 volumio systemd[1]: Started DHCP Client Daemon. Apr 15 07:52:02 volumio wpa_supplicant[933]: Successfully initialized wpa_supplicant Apr 15 07:52:02 volumio systemd[1]: Started Save/Restore Sound Card State. Apr 15 07:52:02 volumio avahi-daemon[919]: No service file found in /etc/avahi/services. Apr 15 07:52:02 volumio bluetoothd[926]: Starting SDP server Apr 15 07:52:02 volumio bluetoothd[926]: Excluding (cli) sap Apr 15 07:52:02 volumio kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Apr 15 07:52:02 volumio kernel: Bluetooth: BNEP filters: protocol multicast Apr 15 07:52:02 volumio kernel: Bluetooth: BNEP socket layer initialized Apr 15 07:52:02 volumio bluetoothd[926]: Bluetooth management interface 1.22 initialized Apr 15 07:52:02 volumio dbus-daemon[931]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.4' (uid=0 pid=926 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Apr 15 07:52:02 volumio kernel: Bluetooth: MGMT ver 1.22 Apr 15 07:52:02 volumio systemd[1]: Started Login Service. Apr 15 07:52:02 volumio systemd[1]: Started Avahi mDNS/DNS-SD Stack. Apr 15 07:52:02 volumio systemd[1]: Started WPA supplicant. Apr 15 07:52:02 volumio systemd[1]: Started Bluetooth service. Apr 15 07:52:02 volumio sh[848]: wlan0=wlan0 Apr 15 07:52:02 volumio sh[855]: eth0: waiting for carrier Apr 15 07:52:02 volumio dhcpcd[900]: eth0: waiting for carrier Apr 15 07:52:02 volumio dhcpcd[1022]: eth0: waiting for carrier Apr 15 07:52:02 volumio dhcpcd[1022]: wlan0: waiting for carrier Apr 15 07:52:02 volumio dhcpcd[1022]: wlan0: carrier acquired Apr 15 07:52:02 volumio avahi-daemon[919]: Network interface enumeration completed. Apr 15 07:52:02 volumio avahi-daemon[919]: Server startup complete. Host name is volumio.local. Local service cookie is 1035823865. Apr 15 07:52:02 volumio dhcpcd[1022]: DUID 00:04:c1:af:11:cd:32:18:9c:df:3b:1b:1c:69:7a:00:ad:ae Apr 15 07:52:02 volumio dhcpcd[1022]: wlan0: IAID af:3e:13:27 Apr 15 07:52:02 volumio dhcpcd[1022]: wlan0: adding address fe80::2d13:1436:61f5:d7b1 Apr 15 07:52:02 volumio dhcpcd[1022]: ipv6_addaddr1: Permission denied Apr 15 07:52:02 volumio dhcpcd[1022]: wlan0: carrier lost Apr 15 07:52:02 volumio systemd[1]: Starting Hostname Service... Apr 15 07:52:02 volumio systemd[1]: Reached target Bluetooth. Apr 15 07:52:02 volumio systemd[1]: Listening on mpd.socket. Apr 15 07:52:02 volumio systemd[1]: Reached target Sound Card. Apr 15 07:52:02 volumio systemd[1]: Started Raise network interfaces. Apr 15 07:52:02 volumio systemd[1]: Reached target Network. Apr 15 07:52:02 volumio systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Apr 15 07:52:02 volumio systemd[1]: Starting Network Time Service... Apr 15 07:52:02 volumio systemd[1]: Starting Permit User Sessions... Apr 15 07:52:02 volumio systemd[1]: Starting Music Player Daemon... Apr 15 07:52:02 volumio systemd[1]: Reached target Network is Online. Apr 15 07:52:02 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 15 07:52:02 volumio systemd[1]: Starting Samba NMB Daemon... Apr 15 07:52:02 volumio loadcpufreq[923]: Loading cpufreq kernel modules...done (acpi-cpufreq). Apr 15 07:52:02 volumio systemd[1]: Starting LSB: Brings up/down network automatically... Apr 15 07:52:02 volumio systemd[1]: Starting /etc/rc.local Compatibility... Apr 15 07:52:02 volumio systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Apr 15 07:52:02 volumio systemd[1]: Starting LSB: set CPUFreq kernel parameters... Apr 15 07:52:02 volumio dbus-daemon[931]: [system] Successfully activated service 'org.freedesktop.hostname1' Apr 15 07:52:02 volumio systemd[1]: Started Permit User Sessions. Apr 15 07:52:02 volumio systemd[1]: Started /etc/rc.local Compatibility. Apr 15 07:52:02 volumio systemd[1]: iptables.service: Succeeded. Apr 15 07:52:02 volumio systemd[1]: Started Hostname Service. Apr 15 07:52:02 volumio systemd[1]: Starting Terminate Plymouth Boot Screen... Apr 15 07:52:02 volumio systemd[1]: Starting Hold until boot process finishes up... Apr 15 07:52:02 volumio cpufrequtils[1106]: CPUFreq Utilities: Setting ondemand CPUFreq governor...error: unexpectedly disconnected from boot status daemon Apr 15 07:52:02 volumio cpufrequtils[1106]: disabled, governor not available...done. Apr 15 07:52:02 volumio systemd[1]: Started LSB: set CPUFreq kernel parameters. Apr 15 07:52:02 volumio systemd[1]: plymouth-quit.service: Succeeded. Apr 15 07:52:02 volumio systemd[1]: Started Terminate Plymouth Boot Screen. Apr 15 07:52:02 volumio systemd[1]: plymouth-quit-wait.service: Succeeded. Apr 15 07:52:02 volumio systemd[1]: Started Hold until boot process finishes up. Apr 15 07:52:02 volumio systemd[1]: Received SIGRTMIN+21 from PID 412 (n/a). Apr 15 07:52:02 volumio systemd[1]: Received SIGRTMIN+21 from PID 412 (n/a). Apr 15 07:52:02 volumio ifplugd(eth0)[1134]: ifplugd 0.28 initializing. Apr 15 07:52:02 volumio ifplugd(eth0)[1134]: Using interface eth0/1C:69:7A:00:AD:AE with driver (version: 6.6.32-volumio) Apr 15 07:52:02 volumio ifplugd(eth0)[1134]: Using detection mode: SIOCETHTOOL Apr 15 07:52:02 volumio ifplugd(eth0)[1134]: Initialization complete, link beat not detected. Apr 15 07:52:02 volumio systemd[1]: Started Getty on tty1. Apr 15 07:52:02 volumio systemd[1]: Reached target Login Prompts. Apr 15 07:52:02 volumio ifplugd[1102]: Network Interface Plugging Daemon...start eth0...done. Apr 15 07:52:02 volumio systemd[1]: Started LSB: Brings up/down network automatically. Apr 15 07:52:02 volumio ntpd[1080]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 15 07:52:02 volumio ntpd[1080]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 15 07:52:02 volumio systemd[1]: Started Network Time Service. Apr 15 07:52:02 volumio ntpd[1141]: proto: precision = 0.089 usec (-23) Apr 15 07:52:02 volumio ntpd[1141]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 15 07:52:02 volumio ntpd[1141]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 15 07:52:02 volumio ntpd[1141]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 840 days ago Apr 15 07:52:02 volumio ntpd[1141]: Listen and drop on 0 v6wildcard [::]:123 Apr 15 07:52:02 volumio ntpd[1141]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 15 07:52:02 volumio ntpd[1141]: Listen normally on 2 lo 127.0.0.1:123 Apr 15 07:52:02 volumio ntpd[1141]: Listening on routing socket on fd #19 for interface updates Apr 15 07:52:02 volumio ntpd[1141]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 15 07:52:02 volumio ntpd[1141]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 15 07:52:03 volumio sudo[1098]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 15 07:52:03 volumio sudo[1098]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:03 volumio sudo[1098]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Apr 15 07:52:03 volumio sudo[1098]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:03 volumio ntpd[1141]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Apr 15 07:52:04 volumio nmbd[1105]: [2025/04/15 07:52:04.040146, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Apr 15 07:52:04 volumio nmbd[1105]: started asyncdns process 1148 Apr 15 07:52:04 volumio nmbd[1105]: [2025/04/15 07:52:04.040588, 0] ../lib/util/become_daemon.c:149(daemon_status) Apr 15 07:52:04 volumio nmbd[1105]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Apr 15 07:52:04 volumio nmbd[1105]: [2025/04/15 07:52:04.040616, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Apr 15 07:52:04 volumio nmbd[1105]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Apr 15 07:52:04 volumio wireless.js[925]: Cleaning previous... Apr 15 07:52:04 volumio sudo[1156]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 15 07:52:04 volumio sudo[1156]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:04 volumio sudo[1156]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:04 volumio sudo[1158]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 15 07:52:04 volumio sudo[1158]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:04 volumio sudo[1158]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:04 volumio wireless.js[925]: Stopped aP Apr 15 07:52:04 volumio sudo[1165]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 15 07:52:04 volumio sudo[1165]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:04 volumio sudo[1165]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:04 volumio sudo[1167]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Apr 15 07:52:04 volumio sudo[1167]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:04 volumio sudo[1167]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:04 volumio sudo[1174]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 15 07:52:04 volumio sudo[1174]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:04 volumio sudo[1174]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:04 volumio sudo[1176]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Apr 15 07:52:04 volumio sudo[1176]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:04 volumio systemd[1]: systemd-rfkill.service: Succeeded. Apr 15 07:52:04 volumio ntpd[1141]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Apr 15 07:52:05 volumio sh[855]: eth0: carrier acquired Apr 15 07:52:05 volumio dhcpcd[900]: eth0: carrier acquired Apr 15 07:52:05 volumio kernel: e1000e 0000:00:1f.6 eth0: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx Apr 15 07:52:05 volumio dhcpcd[1022]: eth0: carrier acquired Apr 15 07:52:05 volumio dhcpcd[1022]: eth0: IAID 7a:00:ad:ae Apr 15 07:52:05 volumio sh[855]: DUID 00:04:c1:af:11:cd:32:18:9c:df:3b:1b:1c:69:7a:00:ad:ae Apr 15 07:52:05 volumio sh[855]: eth0: IAID 7a:00:ad:ae Apr 15 07:52:05 volumio dhcpcd[1022]: eth0: adding address fe80::5cd3:4c06:9223:6b22 Apr 15 07:52:05 volumio sh[855]: eth0: adding address fe80::5cd3:4c06:9223:6b22 Apr 15 07:52:05 volumio sh[855]: ipv6_addaddr1: Permission denied Apr 15 07:52:05 volumio dhcpcd[1022]: ipv6_addaddr1: Permission denied Apr 15 07:52:05 volumio dhcpcd[900]: DUID 00:04:c1:af:11:cd:32:18:9c:df:3b:1b:1c:69:7a:00:ad:ae Apr 15 07:52:05 volumio dhcpcd[900]: eth0: IAID 7a:00:ad:ae Apr 15 07:52:05 volumio dhcpcd[900]: eth0: adding address fe80::5cd3:4c06:9223:6b22 Apr 15 07:52:05 volumio dhcpcd[900]: ipv6_addaddr1: Permission denied Apr 15 07:52:05 volumio dhcpcd[1022]: eth0: soliciting an IPv6 router Apr 15 07:52:05 volumio sh[855]: eth0: soliciting a DHCP lease Apr 15 07:52:05 volumio dhcpcd[900]: eth0: soliciting a DHCP lease Apr 15 07:52:05 volumio mpd[1146]: Apr 15 07:52 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 15 07:52:05 volumio mpd[1146]: Apr 15 07:52 : exception: Database corrupted Apr 15 07:52:05 volumio systemd[1]: Started Music Player Daemon. Apr 15 07:52:05 volumio mpd_monitor.sh[936]: MPD Monitor Service: MPD restarted due to no mpc output. Apr 15 07:52:05 volumio sh[855]: eth0: soliciting an IPv6 router Apr 15 07:52:05 volumio dhcpcd[900]: eth0: soliciting an IPv6 router Apr 15 07:52:05 volumio ifplugd(eth0)[1134]: Link beat detected. Apr 15 07:52:05 volumio ntpd[1141]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Apr 15 07:52:05 volumio ifplugd(eth0)[1134]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Apr 15 07:52:05 volumio ifplugd(eth0)[1134]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Apr 15 07:52:06 volumio volumio-time-update[929]: volumio-time-update-util: Fetching time from Volumio... Apr 15 07:52:06 volumio volumio-time-update[929]: volumio-time-update-util: Date not found in response Apr 15 07:52:06 volumio volumio-time-update[929]: volumio-time-update-util: Retrying in 5 seconds... Apr 15 07:52:06 volumio volumio-remote-updater[922]: [2025-04-15 07:52:06] [info] asio async_connect error: system:111 (Connection refused) Apr 15 07:52:06 volumio volumio-remote-updater[922]: [2025-04-15 07:52:06] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 15 07:52:06 volumio volumio-remote-updater[922]: [2025-04-15 07:52:06] [error] handle_connect error: Underlying Transport Error Apr 15 07:52:06 volumio dhcpcd[1022]: eth0: soliciting a DHCP lease Apr 15 07:52:06 volumio ntpd[1141]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Apr 15 07:52:07 volumio dhcpcd[1022]: eth0: offered 192.168.1.164 from 192.168.1.254 Apr 15 07:52:07 volumio dhcpcd[1022]: eth0: probing address 192.168.1.164/24 Apr 15 07:52:07 volumio sudo[1176]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:07 volumio wireless.js[925]: SETTING APPROPRIATE REG DOMAIN: MY Apr 15 07:52:07 volumio sudo[1197]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 15 07:52:07 volumio sudo[1197]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:07 volumio sudo[1197]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:07 volumio sudo[1199]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set MY Apr 15 07:52:07 volumio sudo[1199]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:07 volumio sudo[1199]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:07 volumio wireless.js[925]: SUCCESSFULLY SET NEW REGDOMAIN: MY Apr 15 07:52:07 volumio sudo[1206]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 15 07:52:07 volumio sudo[1206]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:07 volumio sudo[1206]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:07 volumio sudo[1208]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 15 07:52:07 volumio sudo[1208]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:07 volumio sudo[1208]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:08 volumio avahi-daemon[919]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Apr 15 07:52:08 volumio avahi-daemon[919]: New relevant interface wlan0.IPv4 for mDNS. Apr 15 07:52:08 volumio avahi-daemon[919]: Registering new address record for 192.168.211.1 on wlan0.IPv4. Apr 15 07:52:08 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Apr 15 07:52:08 volumio hostapd[1214]: Configuration file: /etc/hostapd/hostapd.conf Apr 15 07:52:08 volumio avahi-daemon[919]: Interface wlan0.IPv4 no longer relevant for mDNS. Apr 15 07:52:08 volumio avahi-daemon[919]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Apr 15 07:52:08 volumio avahi-daemon[919]: Withdrawing address record for 192.168.211.1 on wlan0. Apr 15 07:52:08 volumio avahi-daemon[919]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Apr 15 07:52:08 volumio avahi-daemon[919]: New relevant interface wlan0.IPv4 for mDNS. Apr 15 07:52:08 volumio avahi-daemon[919]: Registering new address record for 192.168.211.1 on wlan0.IPv4. Apr 15 07:52:08 volumio hostapd[1214]: Using interface wlan0 with hwaddr 50:76:af:3e:13:27 and ssid "Volumio" Apr 15 07:52:08 volumio dhcpcd[1022]: wlan0: carrier acquired Apr 15 07:52:08 volumio dhcpcd[1022]: wlan0: IAID af:3e:13:27 Apr 15 07:52:08 volumio hostapd[1214]: wlan0: interface state UNINITIALIZED->ENABLED Apr 15 07:52:08 volumio hostapd[1214]: wlan0: AP-ENABLED Apr 15 07:52:08 volumio systemd[1]: Started Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Apr 15 07:52:08 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Apr 15 07:52:08 volumio iwconfig[1234]: Error for wireless request "Set Power Management" (8B2C) : Apr 15 07:52:08 volumio iwconfig[1234]: SET failed on device wlan0 ; Invalid argument. Apr 15 07:52:08 volumio systemd[1]: wireless.service: Succeeded. Apr 15 07:52:08 volumio systemd[1]: Started Wireless Services. Apr 15 07:52:08 volumio systemd[1]: Started Volumio Backend Module. Apr 15 07:52:08 volumio systemd[1]: Started First Start. Apr 15 07:52:08 volumio systemd[1]: Started Start Volumio Kiosk. Apr 15 07:52:08 volumio systemd[1]: Started Intel SST and HDA soundcard init service. Apr 15 07:52:08 volumio systemd[1]: Started Volumio Cpu Tweaker. Apr 15 07:52:08 volumio firststart.sh[1236]: Volumio first start configuration script Apr 15 07:52:08 volumio firststart.sh[1236]: Configuring unconfigured packages Apr 15 07:52:08 volumio dnsmasq[1232]: dnsmasq: syntax check OK. Apr 15 07:52:08 volumio dhcpcd[1022]: wlan0: soliciting an IPv6 router Apr 15 07:52:08 volumio volumio-cpu-tweak[1239]: Setting RT Priority for mpd Apr 15 07:52:08 volumio volumio-cpu-tweak[1239]: Setting MPD Affinity Apr 15 07:52:08 volumio volumio-cpu-tweak[1239]: pid 1146's current affinity mask: ff Apr 15 07:52:08 volumio volumio-cpu-tweak[1239]: pid 1146's new affinity mask: 3 Apr 15 07:52:08 volumio volumio-cpu-tweak[1239]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Apr 15 07:52:08 volumio startx[1237]: xauth: file /root/.Xauthority does not exist Apr 15 07:52:09 volumio dhcpcd[1022]: wlan0: soliciting a DHCP lease Apr 15 07:52:09 volumio systemd[1]: volumio_cpu_tweak.service: Succeeded. Apr 15 07:52:09 volumio nmbd[1105]: [2025/04/15 07:52:09.223126, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 15 07:52:09 volumio nmbd[1105]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Apr 15 07:52:09 volumio systemd[1]: Started Samba NMB Daemon. Apr 15 07:52:09 volumio systemd[1]: Starting Samba Winbind Daemon... Apr 15 07:52:09 volumio dnsmasq[1337]: started, version 2.80 cachesize 150 Apr 15 07:52:09 volumio dnsmasq[1337]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Apr 15 07:52:09 volumio dnsmasq-dhcp[1337]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Apr 15 07:52:09 volumio dnsmasq[1337]: reading /etc/resolv.conf Apr 15 07:52:09 volumio dnsmasq[1337]: using nameserver 208.67.222.222#53 Apr 15 07:52:09 volumio dnsmasq[1337]: using nameserver 208.67.220.220#53 Apr 15 07:52:09 volumio dnsmasq[1337]: read /etc/hosts - 5 addresses Apr 15 07:52:09 volumio firststart.sh[1236]: Creating /var/log/samba/cores folder Apr 15 07:52:09 volumio firststart.sh[1236]: Removing default SSH host keys Apr 15 07:52:09 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Apr 15 07:52:09 volumio systemd[1]: Reached target Host and Network Name Lookups. Apr 15 07:52:09 volumio firststart.sh[1236]: removed '/etc/ssh/ssh_host_ecdsa_key' Apr 15 07:52:09 volumio firststart.sh[1236]: removed '/etc/ssh/ssh_host_ecdsa_key.pub' Apr 15 07:52:09 volumio firststart.sh[1236]: removed '/etc/ssh/ssh_host_ed25519_key' Apr 15 07:52:09 volumio firststart.sh[1236]: removed '/etc/ssh/ssh_host_ed25519_key.pub' Apr 15 07:52:09 volumio firststart.sh[1236]: removed '/etc/ssh/ssh_host_rsa_key' Apr 15 07:52:09 volumio firststart.sh[1236]: removed '/etc/ssh/ssh_host_rsa_key.pub' Apr 15 07:52:09 volumio firststart.sh[1236]: Generating SSH host keys Apr 15 07:52:09 volumio startx[1237]: X.Org X Server 1.20.4 Apr 15 07:52:09 volumio startx[1237]: X Protocol Version 11, Revision 0 Apr 15 07:52:09 volumio startx[1237]: Build Operating System: Linux 5.10.0-10-amd64 x86_64 Debian Apr 15 07:52:09 volumio startx[1237]: Current Operating System: Linux volumio 6.6.32-volumio #2 SMP PREEMPT_DYNAMIC Wed May 29 23:04:42 CEST 2024 x86_64 Apr 15 07:52:09 volumio startx[1237]: Kernel command line: BOOT_IMAGE=/vmlinuz initramfs.clear splash plymouth.ignore-serial-consoles quiet loglevel=0 biosdevname=0 imgpart=UUID=3cc03e2d-018e-43c1-b7e6-361cc0a7c20f bootpart=UUID=0A5D-C90D datapart=UUID=de34b9f5-9b78-4162-a289-2de9c46fbb26 hwdevice=x86 uuidconfig=syslinux.cfg,efi/BOOT/grub.cfg imgfile=/volumio_current.sqsh logo.nologo vt.global_cursor_default=0 acpi_backlight=vendor net.ifnames=0 use_kmsg=no Apr 15 07:52:09 volumio startx[1237]: Build Date: 18 December 2021 09:05:36AM Apr 15 07:52:09 volumio startx[1237]: xorg-server 2:1.20.4-1+deb10u4 (https://www.debian.org/support) Apr 15 07:52:09 volumio startx[1237]: Current version of pixman: 0.36.0 Apr 15 07:52:09 volumio startx[1237]: Before reporting problems, check http://wiki.x.org Apr 15 07:52:09 volumio startx[1237]: to make sure that you have the latest version. Apr 15 07:52:09 volumio startx[1237]: Markers: (--) probed, (**) from config file, (==) default setting, Apr 15 07:52:09 volumio startx[1237]: (++) from command line, (!!) notice, (II) informational, Apr 15 07:52:09 volumio startx[1237]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Apr 15 07:52:09 volumio startx[1237]: (==) Log file: "/var/log/Xorg.0.log", Time: Tue Apr 15 07:52:09 2025 Apr 15 07:52:09 volumio startx[1237]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Apr 15 07:52:09 volumio systemd[1]: soundcard-init.service: Succeeded. Apr 15 07:52:09 volumio winbindd[1314]: [2025/04/15 07:52:09.642132, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Apr 15 07:52:09 volumio winbindd[1314]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Apr 15 07:52:09 volumio winbindd[1314]: [2025/04/15 07:52:09.749894, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 15 07:52:09 volumio winbindd[1314]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Apr 15 07:52:09 volumio systemd[1]: Started Samba Winbind Daemon. Apr 15 07:52:09 volumio systemd[1]: Starting Samba SMB Daemon... Apr 15 07:52:09 volumio ntpd[1141]: Listen normally on 3 wlan0 192.168.211.1:123 Apr 15 07:52:09 volumio ntpd[1141]: new interface(s) found: waking up resolver Apr 15 07:52:10 volumio sh[855]: eth0: probing for an IPv4LL address Apr 15 07:52:10 volumio dhcpcd[900]: eth0: probing for an IPv4LL address Apr 15 07:52:10 volumio kernel: broken atomic modeset userspace detected, disabling atomic Apr 15 07:52:10 volumio smbd[1398]: [2025/04/15 07:52:10.631685, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 15 07:52:10 volumio smbd[1398]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Apr 15 07:52:10 volumio systemd[1]: Started Samba SMB Daemon. Apr 15 07:52:10 volumio startx[1237]: (II) modeset(0): Initializing kms color map for depth 24, 8 bpc. Apr 15 07:52:11 volumio volumio-time-update[929]: volumio-time-update-util: Fetching time from Volumio... Apr 15 07:52:11 volumio sh[855]: eth0: offered 192.168.1.164 from 192.168.1.254 Apr 15 07:52:11 volumio dhcpcd[900]: eth0: offered 192.168.1.164 from 192.168.1.254 Apr 15 07:52:11 volumio volumio-time-update[929]: volumio-time-update-util: Date not found in response Apr 15 07:52:11 volumio volumio-time-update[929]: volumio-time-update-util: Retrying in 5 seconds... Apr 15 07:52:11 volumio sh[855]: eth0: probing address 192.168.1.164/24 Apr 15 07:52:11 volumio dhcpcd[900]: eth0: probing address 192.168.1.164/24 Apr 15 07:52:11 volumio dhcpcd[1022]: eth0: leased 192.168.1.164 for 86400 seconds Apr 15 07:52:11 volumio avahi-daemon[919]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.164. Apr 15 07:52:11 volumio dhcpcd[1022]: eth0: adding route to 192.168.1.0/24 Apr 15 07:52:11 volumio dhcpcd[1022]: eth0: adding default route via 192.168.1.254 Apr 15 07:52:11 volumio avahi-daemon[919]: New relevant interface eth0.IPv4 for mDNS. Apr 15 07:52:11 volumio avahi-daemon[919]: Registering new address record for 192.168.1.164 on eth0.IPv4. Apr 15 07:52:12 volumio ntpd[1141]: Listen normally on 4 eth0 192.168.1.164:123 Apr 15 07:52:12 volumio ntpd[1141]: new interface(s) found: waking up resolver Apr 15 07:52:13 volumio dnsmasq[1337]: reading /etc/resolv.conf Apr 15 07:52:13 volumio dnsmasq[1337]: using nameserver 192.168.1.254#53 Apr 15 07:52:13 volumio dnsmasq[1337]: using nameserver 208.67.222.222#53 Apr 15 07:52:13 volumio dnsmasq[1337]: using nameserver 208.67.220.220#53 Apr 15 07:52:13 volumio ntpd[1141]: ntpd exiting on signal 15 (Terminated) Apr 15 07:52:13 volumio systemd[1]: Stopping Network Time Service... Apr 15 07:52:13 volumio systemd[1]: ntp.service: Succeeded. Apr 15 07:52:13 volumio systemd[1]: Stopped Network Time Service. Apr 15 07:52:13 volumio systemd[1]: Starting Network Time Service... Apr 15 07:52:13 volumio ntpd[1449]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 15 07:52:13 volumio ntpd[1449]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 15 07:52:13 volumio systemd[1]: Started Network Time Service. Apr 15 07:52:13 volumio ntpd[1457]: proto: precision = 0.063 usec (-24) Apr 15 07:52:13 volumio ntpd[1457]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 15 07:52:13 volumio ntpd[1457]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 15 07:52:13 volumio ntpd[1457]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 840 days ago Apr 15 07:52:13 volumio ntpd[1457]: Listen and drop on 0 v6wildcard [::]:123 Apr 15 07:52:13 volumio ntpd[1457]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 15 07:52:13 volumio ntpd[1457]: Listen normally on 2 lo 127.0.0.1:123 Apr 15 07:52:13 volumio ntpd[1457]: Listen normally on 3 eth0 192.168.1.164:123 Apr 15 07:52:13 volumio ntpd[1457]: Listen normally on 4 wlan0 192.168.211.1:123 Apr 15 07:52:13 volumio ntpd[1457]: Listening on routing socket on fd #21 for interface updates Apr 15 07:52:13 volumio ntpd[1457]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 15 07:52:13 volumio ntpd[1457]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 15 07:52:13 volumio firststart.sh[1236]: debconf: unable to initialize frontend: Dialog Apr 15 07:52:13 volumio firststart.sh[1236]: debconf: (TERM is not set, so the dialog frontend is not usable.) Apr 15 07:52:13 volumio firststart.sh[1236]: debconf: falling back to frontend: Readline Apr 15 07:52:13 volumio firststart.sh[1236]: debconf: unable to initialize frontend: Readline Apr 15 07:52:13 volumio firststart.sh[1236]: debconf: (This frontend requires a controlling tty.) Apr 15 07:52:13 volumio firststart.sh[1236]: debconf: falling back to frontend: Teletype Apr 15 07:52:13 volumio volumio-remote-updater[922]: [2025-04-15 07:52:13] [connect] Successful connection Apr 15 07:52:14 volumio dhcpcd[1022]: wlan0: probing for an IPv4LL address Apr 15 07:52:14 volumio ntpd[1457]: Soliciting pool server 38.60.193.17 Apr 15 07:52:15 volumio ntpd[1457]: Soliciting pool server 111.90.158.134 Apr 15 07:52:15 volumio ntpd[1457]: Soliciting pool server 103.16.182.23 Apr 15 07:52:15 volumio sh[855]: eth0: using IPv4LL address 169.254.230.1 Apr 15 07:52:15 volumio dhcpcd[900]: eth0: using IPv4LL address 169.254.230.1 Apr 15 07:52:15 volumio sh[855]: eth0: adding route to 169.254.0.0/16 Apr 15 07:52:15 volumio sh[855]: eth0: adding default route Apr 15 07:52:15 volumio avahi-daemon[919]: Registering new address record for 169.254.230.1 on eth0.IPv4. Apr 15 07:52:15 volumio dhcpcd[900]: eth0: adding route to 169.254.0.0/16 Apr 15 07:52:15 volumio dhcpcd[900]: eth0: adding default route Apr 15 07:52:15 volumio dhcpcd[1022]: eth0: deleted default route via 192.168.1.254 Apr 15 07:52:15 volumio sh[855]: forked to background, child pid 1496 Apr 15 07:52:15 volumio dhcpcd[900]: forked to background, child pid 1496 Apr 15 07:52:15 volumio ifplugd(eth0)[1134]: client: ifup: interface eth0 already configured Apr 15 07:52:15 volumio sh[855]: eth0=eth0 Apr 15 07:52:15 volumio ifplugd(eth0)[1134]: Program executed successfully. Apr 15 07:52:15 volumio dhcpcd[1496]: eth0: leased 192.168.1.164 for 86400 seconds Apr 15 07:52:15 volumio dhcpcd[1496]: eth0: adding route to 192.168.1.0/24 Apr 15 07:52:15 volumio dhcpcd[1496]: eth0: changing default route via 192.168.1.254 Apr 15 07:52:15 volumio ntpd[1457]: ntpd exiting on signal 15 (Terminated) Apr 15 07:52:15 volumio ntpd[1457]: 38.60.193.17 local addr 192.168.1.164 -> Apr 15 07:52:15 volumio systemd[1]: Stopping Network Time Service... Apr 15 07:52:15 volumio ntpd[1457]: 111.90.158.134 local addr 192.168.1.164 -> Apr 15 07:52:15 volumio ntpd[1457]: 103.16.182.23 local addr 192.168.1.164 -> Apr 15 07:52:15 volumio systemd[1]: ntp.service: Succeeded. Apr 15 07:52:15 volumio systemd[1]: Stopped Network Time Service. Apr 15 07:52:16 volumio systemd[1]: Starting Network Time Service... Apr 15 07:52:16 volumio ntpd[1574]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 15 07:52:16 volumio ntpd[1574]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 15 07:52:16 volumio ntpd[1581]: proto: precision = 0.036 usec (-25) Apr 15 07:52:16 volumio ntpd[1581]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 15 07:52:16 volumio ntpd[1581]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 15 07:52:16 volumio ntpd[1581]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 840 days ago Apr 15 07:52:16 volumio ntpd[1581]: Listen and drop on 0 v6wildcard [::]:123 Apr 15 07:52:16 volumio ntpd[1581]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 15 07:52:16 volumio ntpd[1581]: Listen normally on 2 lo 127.0.0.1:123 Apr 15 07:52:16 volumio ntpd[1581]: Listen normally on 3 eth0 192.168.1.164:123 Apr 15 07:52:16 volumio ntpd[1581]: Listen normally on 4 eth0 169.254.230.1:123 Apr 15 07:52:16 volumio ntpd[1581]: Listen normally on 5 wlan0 192.168.211.1:123 Apr 15 07:52:16 volumio ntpd[1581]: Listening on routing socket on fd #22 for interface updates Apr 15 07:52:16 volumio ntpd[1581]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 15 07:52:16 volumio ntpd[1581]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 15 07:52:16 volumio volumio-time-update[929]: volumio-time-update-util: Fetching time from Volumio... Apr 15 07:52:16 volumio systemd[1]: Started Network Time Service. Apr 15 07:52:16 volumio avahi-daemon[919]: Withdrawing address record for 169.254.230.1 on eth0. Apr 15 07:52:16 volumio dhcpcd[1496]: eth0: deleting route to 169.254.0.0/16 Apr 15 07:52:16 volumio volumio-time-update[929]: volumio-time-update-util: Setting system time to: 2025-04-15 07:52:17 Apr 15 07:52:16 volumio sudo[1700]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-04-15 07:52:17 Apr 15 07:52:16 volumio sudo[1700]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:16 volumio dbus-daemon[931]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.9' (uid=0 pid=1703 comm="timedatectl set-time 2025-04-15 07:52:17 ") Apr 15 07:52:16 volumio volumio[1235]: info: ------------------------------------------- Apr 15 07:52:16 volumio volumio[1235]: info: ----- Volumio3 ---- Apr 15 07:52:16 volumio volumio[1235]: info: ------------------------------------------- Apr 15 07:52:16 volumio volumio[1235]: info: ----- System startup ---- Apr 15 07:52:16 volumio volumio[1235]: info: ------------------------------------------- Apr 15 07:52:16 volumio systemd[1]: Starting Time & Date Service... Apr 15 07:52:16 volumio dbus-daemon[931]: [system] Successfully activated service 'org.freedesktop.timedate1' Apr 15 07:52:16 volumio systemd[1]: Started Time & Date Service. Apr 15 07:52:17 volumio systemd-timedated[1704]: Changed local time to Tue Apr 15 07:52:17 2025 Apr 15 07:52:17 volumio sudo[1700]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:17 volumio volumio-time-update[929]: volumio-time-update-util: System time updated successfully. Apr 15 07:52:17 volumio systemd[1]: Started Volumio Time Update Utility. Apr 15 07:52:17 volumio systemd[1]: Reached target Multi-User System. Apr 15 07:52:17 volumio systemd[1]: Reached target Graphical Interface. Apr 15 07:52:17 volumio firststart.sh[1236]: Creating SSH2 RSA key; this may take some time ... Apr 15 07:52:17 volumio firststart.sh[1236]: 2048 SHA256:hZRyJ2V4G9bVJZ5uPtnHIBzwbsLK4n6LLsmp2XfbVVA root@volumio (RSA) Apr 15 07:52:17 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Apr 15 07:52:17 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Apr 15 07:52:17 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Apr 15 07:52:17 volumio systemd[1]: Startup finished in 14.724s (firmware) + 5.175s (loader) + 59.644s (kernel) + 19.939s (userspace) = 1min 39.483s. Apr 15 07:52:17 volumio firststart.sh[1236]: Creating SSH2 DSA key; this may take some time ... Apr 15 07:52:17 volumio firststart.sh[1236]: 1024 SHA256:QtLHtps9fUn6zxHAeBfO71V1/n9QRhRuvR8DTWCqIDk root@volumio (DSA) Apr 15 07:52:17 volumio firststart.sh[1236]: Creating SSH2 ECDSA key; this may take some time ... Apr 15 07:52:17 volumio firststart.sh[1236]: 256 SHA256:YokJ1kmbbWg4b20xASxFwOf/hVc4g4oXsIPTwS0HS+U root@volumio (ECDSA) Apr 15 07:52:17 volumio volumio[1235]: info: File /data/configuration/plugins.json does not exist. Copying from Volumio Apr 15 07:52:17 volumio volumio[1235]: info: MYVOLUMIO Environment detected Apr 15 07:52:17 volumio volumio[1235]: info: Plugin folders cleanup Apr 15 07:52:17 volumio volumio[1235]: info: Scanning into folder /volumio/app/plugins/ Apr 15 07:52:17 volumio volumio[1235]: info: Scanning category audio_interface Apr 15 07:52:17 volumio volumio[1235]: info: Scanning category miscellanea Apr 15 07:52:17 volumio volumio[1235]: info: Scanning category music_service Apr 15 07:52:17 volumio volumio[1235]: info: Scanning category plugins.json Apr 15 07:52:17 volumio volumio[1235]: info: Scanning category system_controller Apr 15 07:52:17 volumio volumio[1235]: info: Scanning category user_interface Apr 15 07:52:17 volumio volumio[1235]: info: Scanning into folder /data/plugins/ Apr 15 07:52:17 volumio volumio[1235]: info: Plugin folders cleanup completed Apr 15 07:52:17 volumio volumio[1235]: info: ------------------------------------------- Apr 15 07:52:17 volumio volumio[1235]: info: ----- Core plugins startup ---- Apr 15 07:52:17 volumio volumio[1235]: info: ------------------------------------------- Apr 15 07:52:17 volumio volumio[1235]: info: Loading plugins from folder /volumio/app/plugins/ Apr 15 07:52:17 volumio volumio[1235]: info: Adding plugin upnp to MyMusic Plugins Apr 15 07:52:17 volumio volumio[1235]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 15 07:52:17 volumio volumio[1235]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 15 07:52:17 volumio volumio[1235]: info: Loading plugins from folder /data/plugins/ Apr 15 07:52:17 volumio volumio[1235]: info: Loading plugin "system"... Apr 15 07:52:17 volumio volumio[1235]: info: No id defined. Creating one Apr 15 07:52:17 volumio volumio[1235]: info: Loading plugin "appearance"... Apr 15 07:52:17 volumio ntpd[1581]: Soliciting pool server 47.254.196.78 Apr 15 07:52:17 volumio systemd[1]: Reloading. Apr 15 07:52:17 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Apr 15 07:52:17 volumio systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. Apr 15 07:52:17 volumio firststart.sh[1236]: rescue-ssh.target is a disabled or a static unit, not starting it. Apr 15 07:52:17 volumio firststart.sh[1236]: insserv: warning: current start runlevel(s) (empty) of script `ssh' overrides LSB defaults (2 3 4 5). Apr 15 07:52:17 volumio firststart.sh[1236]: insserv: warning: current stop runlevel(s) (2 3 4 5) of script `ssh' overrides LSB defaults (empty). Apr 15 07:52:17 volumio systemd[1]: Reloading. Apr 15 07:52:17 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Apr 15 07:52:17 volumio volumio[1235]: info: Loading plugin "network"... Apr 15 07:52:17 volumio volumio[1235]: info: Refreshing Cached IP Addresses Apr 15 07:52:17 volumio sudo[1786]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 07:52:17 volumio sudo[1786]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:17 volumio volumio[1235]: info: Loading plugin "services"... Apr 15 07:52:17 volumio volumio[1235]: info: Loading plugin "alsa_controller"... Apr 15 07:52:17 volumio sudo[1786]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:17 volumio sudo[1788]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 07:52:17 volumio sudo[1788]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:17 volumio sudo[1788]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:17 volumio sudo[1797]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 15 07:52:17 volumio sudo[1797]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:17 volumio sudo[1797]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:17 volumio volumio[1235]: warn: The ALSA output card is not set, defaulting to card [object Object] Apr 15 07:52:17 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 15 07:52:17 volumio volumio[1235]: info: Found match in Cards Database: setting mixer for card Analog Out Apr 15 07:52:17 volumio volumio[1235]: info: Setting mixer Master for card Analog Out Apr 15 07:52:17 volumio volumio[1235]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 15 07:52:17 volumio volumio[1235]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 15 07:52:17 volumio volumio[1235]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 15 07:52:17 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 07:52:17 volumio volumio[1235]: info: Loading plugin "wizard"... Apr 15 07:52:17 volumio volumio[1235]: info: Loading plugin "networkfs"... Apr 15 07:52:17 volumio volumio[1235]: info: Starting Udev Watcher for removable devices Apr 15 07:52:17 volumio volumio[1235]: info: Ignoring mount for partition: boot Apr 15 07:52:17 volumio volumio[1235]: info: Ignoring mount for partition: volumio Apr 15 07:52:17 volumio volumio[1235]: info: Ignoring mount for partition: volumio_data Apr 15 07:52:17 volumio volumio[1235]: info: Ignoring mount for partition: B8DD-59BB Apr 15 07:52:17 volumio volumio[1235]: error: Cannot associate FS Label, not mounting Apr 15 07:52:17 volumio volumio[1235]: info: Ignoring mount for partition: Windows_11_Pro Apr 15 07:52:17 volumio volumio[1235]: info: Ignoring mount for partition: 36AE0760AE0717CF Apr 15 07:52:17 volumio volumio[1235]: info: Ignoring mount for partition: Intel_SSD_DATA Apr 15 07:52:17 volumio volumio[1235]: info: Ignoring mount for partition: Sandsk119GB Apr 15 07:52:17 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 15 07:52:17 volumio volumio[1235]: info: Loading plugin "volumio_command_line_client"... Apr 15 07:52:17 volumio volumio[1235]: info: Loading plugin "upnp"... Apr 15 07:52:17 volumio volumio[1235]: info: [1744703537988] Starting Upmpd Daemon Apr 15 07:52:17 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 15 07:52:17 volumio volumio[1235]: info: Loading plugin "my_music"... Apr 15 07:52:17 volumio volumio[1235]: info: Loading plugin "mpd"... Apr 15 07:52:18 volumio volumio[1235]: info: Loading plugin "upnp_browser"... Apr 15 07:52:18 volumio ntpd[1581]: Deleting interface #4 eth0, 169.254.230.1#123, interface stats: received=0, sent=0, dropped=0, active_time=2 secs Apr 15 07:52:18 volumio ntpd[1581]: Soliciting pool server 47.254.196.78 Apr 15 07:52:19 volumio ntpd[1581]: Soliciting pool server 111.90.158.134 Apr 15 07:52:19 volumio dhcpcd[1022]: wlan0: using IPv4LL address 169.254.69.19 Apr 15 07:52:19 volumio dhcpcd[1022]: eth0: adding default route via 192.168.1.254 Apr 15 07:52:19 volumio avahi-daemon[919]: Registering new address record for 169.254.69.19 on wlan0.IPv4. Apr 15 07:52:19 volumio dhcpcd[1022]: wlan0: adding route to 169.254.0.0/16 Apr 15 07:52:19 volumio firststart.sh[1236]: Enabling SSH for first boot Apr 15 07:52:19 volumio systemd[1]: Starting OpenBSD Secure Shell server... Apr 15 07:52:19 volumio sshd[1863]: Server listening on 0.0.0.0 port 22. Apr 15 07:52:19 volumio sshd[1863]: Server listening on :: port 22. Apr 15 07:52:19 volumio systemd[1]: Started OpenBSD Secure Shell server. Apr 15 07:52:19 volumio firststart.sh[1236]: Disabling firststart service Apr 15 07:52:19 volumio firststart.sh[1236]: Removed /etc/systemd/system/multi-user.target.wants/firststart.service. Apr 15 07:52:19 volumio systemd[1]: Reloading. Apr 15 07:52:19 volumio volumio[1235]: info: Loading plugin "alarm-clock"... Apr 15 07:52:19 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Apr 15 07:52:19 volumio volumio[1235]: info: Loading plugin "airplay_emulation"... Apr 15 07:52:19 volumio volumio[1235]: info: Starting Shairport Sync Apr 15 07:52:19 volumio volumio[1235]: info: Loading plugin "last_100"... Apr 15 07:52:19 volumio volumio[1235]: info: Loading plugin "webradio"... Apr 15 07:52:19 volumio volumio[1235]: info: Loading plugin "i2s_dacs"... Apr 15 07:52:19 volumio volumio[1235]: info: I2S DAC not set, start Auto-detection Apr 15 07:52:19 volumio volumio[1235]: info: Loading plugin "volumiodiscovery"... Apr 15 07:52:19 volumio volumio[1235]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 15 07:52:19 volumio volumio[1235]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 07:52:19 volumio volumio[1235]: *** WARNING *** For more information see Apr 15 07:52:19 volumio volumio[1235]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 15 07:52:19 volumio node[1235]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 15 07:52:19 volumio volumio[1235]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 07:52:19 volumio volumio[1235]: *** WARNING *** For more information see Apr 15 07:52:19 volumio node[1235]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 07:52:19 volumio node[1235]: *** WARNING *** For more information see Apr 15 07:52:19 volumio node[1235]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 15 07:52:19 volumio node[1235]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 15 07:52:19 volumio node[1235]: *** WARNING *** For more information see Apr 15 07:52:19 volumio volumio[1235]: info: Discovery: Started advertising with name: Volumio Apr 15 07:52:19 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 15 07:52:19 volumio volumio[1235]: info: Loading plugin "outputs"... Apr 15 07:52:19 volumio volumio[1235]: info: Loading plugin "albumart"... Apr 15 07:52:19 volumio volumio[1235]: info: Plugin example_plugin is not enabled Apr 15 07:52:19 volumio volumio[1235]: info: Loading plugin "inputs"... Apr 15 07:52:19 volumio volumio[1235]: info: Loading plugin "updater_comm"... Apr 15 07:52:19 volumio firststart.sh[1236]: Finalizing Apr 15 07:52:19 volumio volumio[1235]: Forking 7 albumart workers Apr 15 07:52:19 volumio volumio[1235]: info: Plugin mpdemulation is not enabled Apr 15 07:52:19 volumio volumio[1235]: info: Loading plugin "rest_api"... Apr 15 07:52:19 volumio volumio[1235]: info: Loading plugin "websocket"... Apr 15 07:52:19 volumio volumio[1235]: info: Starting Socket.io Server version 2.3.0 Apr 15 07:52:20 volumio volumio[1235]: Starting albumart workers Apr 15 07:52:20 volumio volumio[1235]: Starting albumart workers Apr 15 07:52:20 volumio volumio[1235]: Starting albumart workers Apr 15 07:52:20 volumio volumio[1235]: Starting albumart workers Apr 15 07:52:20 volumio volumio[1235]: Starting albumart workers Apr 15 07:52:20 volumio volumio[1235]: Starting albumart workers Apr 15 07:52:20 volumio volumio[1235]: Starting albumart workers Apr 15 07:52:20 volumio volumio[1235]: info: Loading i18n strings for locale en Apr 15 07:52:20 volumio volumio[1235]: Updating browse sources language Apr 15 07:52:20 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 07:52:20 volumio ntpd[1581]: Soliciting pool server 111.90.158.134 Apr 15 07:52:21 volumio ntpd[1581]: Soliciting pool server 103.16.182.23 Apr 15 07:52:21 volumio ntpd[1581]: Listen normally on 6 wlan0 169.254.69.19:123 Apr 15 07:52:21 volumio ntpd[1581]: new interface(s) found: waking up resolver Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::initPlayerControls Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 07:52:22 volumio volumio[1235]: Express server listening on port 3000 Apr 15 07:52:22 volumio volumio[1235]: [Metrics] WebUI: 8s 674.34ms Apr 15 07:52:22 volumio volumio[1235]: info: Setting Device type: x86 Apr 15 07:52:22 volumio volumio[1235]: info: CoreStateMachine::resetVolumioState Apr 15 07:52:22 volumio volumio[1235]: info: CoreStateMachine::getcurrentVolume Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::volumioRetrievevolume Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:22 volumio ntpd[1581]: Soliciting pool server 47.254.196.78 Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Apr 15 07:52:22 volumio volumio[1235]: info: CoreStateMachine::getcurrentVolume Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::volumioRetrievevolume Apr 15 07:52:22 volumio volumio[1235]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Apr 15 07:52:22 volumio volumio[1235]: info: Completed loading Core Plugins Apr 15 07:52:22 volumio volumio[1235]: info: Preparing to generate the ALSA configuration file Apr 15 07:52:22 volumio volumio[1235]: info: Cannot read play queue from file Apr 15 07:52:22 volumio volumio[1235]: info: Volumio Network Manager: Network status updated: 1 Apr 15 07:52:22 volumio volumio[1235]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Apr 15 07:52:22 volumio volumio[1235]: wlan0 Interface doesn't support scanning : Operation not supported Apr 15 07:52:22 volumio volumio[1235]: info: Cannot use regular scanning, forcing with ap-force Apr 15 07:52:22 volumio sudo[1997]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Apr 15 07:52:22 volumio sudo[1997]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:22 volumio sudo[1997]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:22 volumio volumio[1235]: command failed: Operation not supported (-95) Apr 15 07:52:22 volumio volumio[1235]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Apr 15 07:52:22 volumio volumio[1235]: command failed: Operation not supported (-95) Apr 15 07:52:22 volumio volumio[1235]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Apr 15 07:52:22 volumio volumio[1235]: info: VolumeController:: Volume=41 Mute =false Apr 15 07:52:22 volumio volumio[1235]: info: CoreStateMachine::pushState Apr 15 07:52:22 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::volumioPushState Apr 15 07:52:22 volumio volumio[1235]: info: CoreStateMachine::updateTrackBlock Apr 15 07:52:22 volumio volumio[1235]: info: CorePlayQueue::getTrackBlock Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::volumioRetrievevolume Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 07:52:22 volumio volumio[1235]: info: Discovery: Getting this device information Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Apr 15 07:52:22 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 07:52:22 volumio volumio[1235]: info: VolumeController:: Volume=41 Mute =false Apr 15 07:52:22 volumio volumio[1235]: info: CoreStateMachine::pushState Apr 15 07:52:22 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::volumioPushState Apr 15 07:52:22 volumio volumio[1235]: info: CoreStateMachine::updateTrackBlock Apr 15 07:52:22 volumio volumio[1235]: info: CorePlayQueue::getTrackBlock Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::volumioRetrievevolume Apr 15 07:52:22 volumio volumio[1235]: info: Asound.conf file written Apr 15 07:52:22 volumio sudo[2009]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 15 07:52:22 volumio sudo[2009]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:22 volumio sudo[2009]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:22 volumio volumio[1235]: No state is present for card PCH Apr 15 07:52:22 volumio volumio[1235]: Found hardware: "HDA-Intel" "Realtek ALC233" "HDA:10ec0235,80862074,00100002 HDA:8086280b,80860101,00100000" "0x8086" "0x2074" Apr 15 07:52:22 volumio volumio[1235]: Hardware is initialized using a generic method Apr 15 07:52:22 volumio volumio[1235]: No state is present for card PCH Apr 15 07:52:22 volumio volumio[1235]: No state is present for card UAC2 Apr 15 07:52:22 volumio volumio[1235]: Found hardware: "USB-Audio" "USB Mixer" "USB249c:9326" "" "" Apr 15 07:52:22 volumio volumio[1235]: Hardware is initialized using a generic method Apr 15 07:52:22 volumio volumio[1235]: No state is present for card UAC2 Apr 15 07:52:22 volumio volumio[1235]: info: Output device has changed, restarting MPD Apr 15 07:52:22 volumio volumio[1235]: info: Output device has changed, restarting Shairport Sync Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:22 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:22 volumio sudo[2014]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 15 07:52:22 volumio sudo[2014]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:22 volumio sudo[2016]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 15 07:52:22 volumio sudo[2016]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:22 volumio systemd[1]: Stopping Music Player Daemon... Apr 15 07:52:24 volumio volumio[1235]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 15 07:52:24 volumio volumio[1235]: info: ___________ START PLUGINS ___________ Apr 15 07:52:24 volumio volumio[1235]: info: Setting Hotspot Unique name on first start: Volumio-0898D Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getConfigParam Apr 15 07:52:24 volumio volumio[1235]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getConfigParam] in plugin network Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , saveHotspotSettings Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::Reload Ui Apr 15 07:52:24 volumio volumio[1235]: info: ControllerMpd::onStart: Initializing MPD Apr 15 07:52:24 volumio volumio[1235]: info: Creating MPD Configuration file Apr 15 07:52:24 volumio sudo[2023]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 15 07:52:24 volumio sudo[2023]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 07:52:24 volumio volumio[1235]: info: [1744703544384] CoreMusicLibrary::Adding element Media Servers Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 07:52:24 volumio sudo[2025]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 15 07:52:24 volumio sudo[2025]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:24 volumio volumio[1235]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:24 volumio volumio[1235]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 07:52:24 volumio volumio[1235]: info: [1744703544524] CoreMusicLibrary::Adding element Last_100 Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 15 07:52:24 volumio volumio[1235]: info: [1744703544524] CoreMusicLibrary::Adding element Webradio Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 07:52:24 volumio volumio[1235]: info: Initializing BBC Radios Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:24 volumio volumio[1235]: info: Volumio Calling Home Apr 15 07:52:24 volumio sudo[2014]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:24 volumio sudo[2023]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:24 volumio volumio[1235]: info: MPD Permissions set Apr 15 07:52:24 volumio volumio[1235]: info: MPD Permissions set Apr 15 07:52:24 volumio volumio[1235]: info: VolumeController:: Volume=41 Mute =false Apr 15 07:52:24 volumio volumio[1235]: info: CoreStateMachine::pushState Apr 15 07:52:24 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::volumioPushState Apr 15 07:52:24 volumio volumio[1235]: verbose: New Socket.io Connection to 192.168.1.164:3000 from 192.168.1.226 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 1 Apr 15 07:52:24 volumio volumio[1235]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Apr 15 07:52:24 volumio volumio[1235]: info: VolumeController:: Volume=41 Mute =false Apr 15 07:52:24 volumio volumio[1235]: info: CoreStateMachine::pushState Apr 15 07:52:24 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::volumioPushState Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Apr 15 07:52:24 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 15 07:52:26 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:26 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:26 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:26 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:26 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:26 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:26 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:26 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:26 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:26 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 15 07:52:26 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:26 volumio systemd[1]: firststart.service: Succeeded. Apr 15 07:52:26 volumio volumio[1235]: info: Discovery: adding 8d6f9a3c-50d8-4583-bed8-85d4a5ebab89 Apr 15 07:52:26 volumio volumio[1235]: info: Discovery: Found device Volumio Apr 15 07:52:26 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Apr 15 07:52:26 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:26 volumio volumio[1235]: info: Discovery: this is already registered, 8d6f9a3c-50d8-4583-bed8-85d4a5ebab89 Apr 15 07:52:26 volumio volumio[1235]: info: Discovery: Found device Volumio Apr 15 07:52:26 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Apr 15 07:52:26 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:26 volumio volumio[1235]: info: Volumio called home Apr 15 07:52:26 volumio sudo[2064]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/hostapd/hostapd.conf Apr 15 07:52:26 volumio sudo[2064]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:26 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:26 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Apr 15 07:52:26 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:26 volumio sudo[2064]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:26 volumio volumio[1235]: info: Starting Shairport Sync Apr 15 07:52:26 volumio volumio[1235]: info: Starting Shairport Sync Apr 15 07:52:26 volumio volumio[1235]: info: Starting Shairport Sync Apr 15 07:52:26 volumio volumio[1235]: info: Permissions for /etc/hostapd/hostapd.conf Apr 15 07:52:26 volumio sudo[2068]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 15 07:52:26 volumio sudo[2070]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 15 07:52:26 volumio sudo[2068]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:26 volumio sudo[2070]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:26 volumio sudo[2072]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 15 07:52:26 volumio sudo[2072]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:26 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart Apr 15 07:52:26 volumio volumio[1235]: info: Discovery: Restarting Advertising due to device name change Apr 15 07:52:26 volumio sudo[2077]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service Apr 15 07:52:26 volumio sudo[2077]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:27 volumio systemd[1]: mpd.service: Succeeded. Apr 15 07:52:27 volumio systemd[1]: Stopped Music Player Daemon. Apr 15 07:52:27 volumio systemd[1]: Starting Music Player Daemon... Apr 15 07:52:27 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 15 07:52:27 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 15 07:52:27 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 15 07:52:27 volumio systemd[1]: Starting Wireless Services... Apr 15 07:52:27 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 15 07:52:27 volumio sudo[2072]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:27 volumio sudo[2070]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:27 volumio sudo[2068]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:27 volumio volumio[1235]: info: Shairport-Sync Started Apr 15 07:52:27 volumio volumio[1235]: Error adding Membership: Error: addMembership EINVAL Apr 15 07:52:27 volumio volumio[1235]: info: Shairport-Sync Started Apr 15 07:52:27 volumio volumio[1235]: info: Shairport-Sync Started Apr 15 07:52:27 volumio sudo[2079]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 15 07:52:27 volumio sudo[2079]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:27 volumio sudo[2079]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:27 volumio wireless.js[2080]: Cleaning previous... Apr 15 07:52:27 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Apr 15 07:52:27 volumio dnsmasq[1337]: exiting on receipt of SIGTERM Apr 15 07:52:27 volumio systemd[1]: dnsmasq.service: Succeeded. Apr 15 07:52:27 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Apr 15 07:52:27 volumio systemd[1]: Stopping Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Apr 15 07:52:27 volumio dhcpcd[1022]: wlan0: carrier lost Apr 15 07:52:27 volumio mpd[2091]: Apr 15 07:52 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 15 07:52:27 volumio systemd[1]: Started Music Player Daemon. Apr 15 07:52:27 volumio sudo[2016]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:27 volumio sudo[2025]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:27 volumio dhcpcd[1022]: wlan0: deleting route to 169.254.0.0/16 Apr 15 07:52:27 volumio avahi-daemon[919]: Withdrawing address record for 169.254.69.19 on wlan0. Apr 15 07:52:27 volumio volumio[1235]: info: Completed starting Core Plugins Apr 15 07:52:27 volumio volumio[1235]: info: ------------------------------------------- Apr 15 07:52:27 volumio volumio[1235]: info: ----- MyVolumio plugins startup ---- Apr 15 07:52:27 volumio volumio[1235]: info: ------------------------------------------- Apr 15 07:52:27 volumio volumio[1235]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 15 07:52:27 volumio volumio[1235]: error: MPD error: The expression evaluated to a falsy value: Apr 15 07:52:27 volumio volumio[1235]: assert.ok(self.idling) Apr 15 07:52:27 volumio volumio[1235]: error: The expression evaluated to a falsy value: Apr 15 07:52:27 volumio volumio[1235]: assert.ok(self.idling) Apr 15 07:52:27 volumio volumio[1235]: info: MPD running with PID2091 Apr 15 07:52:27 volumio volumio[1235]: ,establishing connection Apr 15 07:52:27 volumio volumio[1235]: error: updateQueue error: null Apr 15 07:52:27 volumio volumio[1235]: error: updateQueue error: null Apr 15 07:52:27 volumio avahi-daemon[919]: Interface wlan0.IPv4 no longer relevant for mDNS. Apr 15 07:52:27 volumio avahi-daemon[919]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Apr 15 07:52:27 volumio avahi-daemon[919]: Withdrawing address record for 192.168.211.1 on wlan0. Apr 15 07:52:27 volumio avahi-daemon[919]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Apr 15 07:52:27 volumio avahi-daemon[919]: New relevant interface wlan0.IPv4 for mDNS. Apr 15 07:52:27 volumio avahi-daemon[919]: Registering new address record for 192.168.211.1 on wlan0.IPv4. Apr 15 07:52:27 volumio volumio[1235]: info: Discovery: A device disappeared from network Apr 15 07:52:27 volumio systemd[1]: hostapd.service: Succeeded. Apr 15 07:52:27 volumio volumio[1235]: info: Discovery: Device volumio disappeared from network Apr 15 07:52:27 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Apr 15 07:52:27 volumio sudo[2150]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 15 07:52:27 volumio sudo[2150]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:27 volumio avahi-daemon[919]: Withdrawing address record for 192.168.211.1 on wlan0. Apr 15 07:52:27 volumio avahi-daemon[919]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Apr 15 07:52:27 volumio avahi-daemon[919]: Interface wlan0.IPv4 no longer relevant for mDNS. Apr 15 07:52:27 volumio sudo[2150]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:27 volumio sudo[2152]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 15 07:52:27 volumio sudo[2152]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:27 volumio sudo[2152]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:27 volumio wireless.js[2080]: Stopped aP Apr 15 07:52:27 volumio sudo[2159]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 15 07:52:27 volumio sudo[2159]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:27 volumio volumio[1235]: info: Discovery: A device disappeared from network Apr 15 07:52:27 volumio sudo[2159]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:27 volumio sudo[2166]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Apr 15 07:52:27 volumio sudo[2166]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:27 volumio sudo[2166]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:27 volumio sudo[2182]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 15 07:52:27 volumio sudo[2182]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:27 volumio sudo[2182]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:27 volumio sudo[2184]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Apr 15 07:52:27 volumio sudo[2184]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:27 volumio sudo[2189]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 07:52:27 volumio sudo[2189]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:27 volumio sudo[2189]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:27 volumio sudo[2191]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 07:52:27 volumio sudo[2191]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:27 volumio sudo[2191]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:28 volumio sudo[2195]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 15 07:52:28 volumio sudo[2195]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:28 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Apr 15 07:52:28 volumio sudo[2195]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:28 volumio volumio[1235]: info: Upmpdcli Daemon Started Apr 15 07:52:28 volumio volumio[2197]: Generating RSA private key, 4096 bit long modulus (2 primes) Apr 15 07:52:29 volumio volumio[2197]: ......................................................................................................................++++ Apr 15 07:52:29 volumio volumio[2197]: .......................................................................................................................................++++ Apr 15 07:52:29 volumio volumio[2197]: e is 65537 (0x010001) Apr 15 07:52:29 volumio volumio[2197]: writing RSA key Apr 15 07:52:29 volumio volumio-remote-updater[922]: [2025-04-15 07:52:29] [connect] Successful connection Apr 15 07:52:29 volumio volumio-remote-updater[922]: [2025-04-15 07:52:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1744703549 101 Apr 15 07:52:29 volumio volumio[1235]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 3 Apr 15 07:52:29 volumio ntpd[1581]: Deleting interface #5 wlan0, 192.168.211.1#123, interface stats: received=0, sent=0, dropped=0, active_time=13 secs Apr 15 07:52:29 volumio ntpd[1581]: Deleting interface #6 wlan0, 169.254.69.19#123, interface stats: received=0, sent=0, dropped=0, active_time=8 secs Apr 15 07:52:30 volumio systemd[1]: systemd-fsckd.service: Succeeded. Apr 15 07:52:31 volumio sudo[2184]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:31 volumio wireless.js[2080]: SETTING APPROPRIATE REG DOMAIN: US Apr 15 07:52:31 volumio sudo[2246]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 15 07:52:31 volumio sudo[2246]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:31 volumio sudo[2246]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:31 volumio sudo[2248]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set US Apr 15 07:52:31 volumio sudo[2248]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:31 volumio sudo[2248]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:31 volumio wireless.js[2080]: SUCCESSFULLY SET NEW REGDOMAIN: US Apr 15 07:52:31 volumio sudo[2255]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 15 07:52:31 volumio sudo[2255]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:31 volumio sudo[2255]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:31 volumio sudo[2257]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 15 07:52:31 volumio sudo[2257]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:31 volumio sudo[2257]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:31 volumio avahi-daemon[919]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Apr 15 07:52:31 volumio avahi-daemon[919]: New relevant interface wlan0.IPv4 for mDNS. Apr 15 07:52:31 volumio avahi-daemon[919]: Registering new address record for 192.168.211.1 on wlan0.IPv4. Apr 15 07:52:31 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Apr 15 07:52:31 volumio hostapd[2263]: Configuration file: /etc/hostapd/hostapd.conf Apr 15 07:52:31 volumio avahi-daemon[919]: Interface wlan0.IPv4 no longer relevant for mDNS. Apr 15 07:52:31 volumio avahi-daemon[919]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Apr 15 07:52:32 volumio avahi-daemon[919]: Withdrawing address record for 192.168.211.1 on wlan0. Apr 15 07:52:32 volumio avahi-daemon[919]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Apr 15 07:52:32 volumio avahi-daemon[919]: New relevant interface wlan0.IPv4 for mDNS. Apr 15 07:52:32 volumio avahi-daemon[919]: Registering new address record for 192.168.211.1 on wlan0.IPv4. Apr 15 07:52:32 volumio hostapd[2263]: Using interface wlan0 with hwaddr 50:76:af:3e:13:27 and ssid "Volumio-0898D" Apr 15 07:52:32 volumio dhcpcd[1022]: wlan0: carrier acquired Apr 15 07:52:32 volumio hostapd[2263]: wlan0: interface state UNINITIALIZED->ENABLED Apr 15 07:52:32 volumio hostapd[2263]: wlan0: AP-ENABLED Apr 15 07:52:32 volumio systemd[1]: Started Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Apr 15 07:52:32 volumio dhcpcd[1022]: wlan0: IAID af:3e:13:27 Apr 15 07:52:32 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Apr 15 07:52:32 volumio dnsmasq[2267]: dnsmasq: syntax check OK. Apr 15 07:52:32 volumio iwconfig[2269]: Error for wireless request "Set Power Management" (8B2C) : Apr 15 07:52:32 volumio iwconfig[2269]: SET failed on device wlan0 ; Invalid argument. Apr 15 07:52:32 volumio systemd[1]: wireless.service: Succeeded. Apr 15 07:52:32 volumio systemd[1]: Started Wireless Services. Apr 15 07:52:32 volumio sudo[2077]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:32 volumio dnsmasq[2275]: started, version 2.80 cachesize 150 Apr 15 07:52:32 volumio dnsmasq[2275]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Apr 15 07:52:32 volumio dnsmasq-dhcp[2275]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Apr 15 07:52:32 volumio dnsmasq[2275]: reading /etc/resolv.conf Apr 15 07:52:32 volumio dnsmasq[2275]: using nameserver 192.168.1.254#53 Apr 15 07:52:32 volumio dnsmasq[2275]: using nameserver 208.67.222.222#53 Apr 15 07:52:32 volumio dnsmasq[2275]: using nameserver 208.67.220.220#53 Apr 15 07:52:32 volumio dnsmasq[2275]: read /etc/hosts - 5 addresses Apr 15 07:52:32 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Apr 15 07:52:32 volumio volumio[1235]: info: Discovery: Started advertising with name: Volumio Apr 15 07:52:32 volumio dhcpcd[1022]: wlan0: soliciting an IPv6 router Apr 15 07:52:32 volumio dhcpcd[1022]: wlan0: soliciting a DHCP lease Apr 15 07:52:32 volumio volumio[1235]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 15 07:52:33 volumio volumio[1235]: info: Discovery: adding 8d6f9a3c-50d8-4583-bed8-85d4a5ebab89 Apr 15 07:52:33 volumio volumio[1235]: info: Discovery: Found device Volumio Apr 15 07:52:33 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Apr 15 07:52:33 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:33 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 07:52:33 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 07:52:33 volumio volumio[1235]: info: Discovery: Getting this device information Apr 15 07:52:33 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Apr 15 07:52:33 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:33 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 07:52:33 volumio systemd[1]: systemd-hostnamed.service: Succeeded. Apr 15 07:52:33 volumio volumio[1235]: info: Discovery: this is already registered, 8d6f9a3c-50d8-4583-bed8-85d4a5ebab89 Apr 15 07:52:33 volumio volumio[1235]: info: Discovery: Found device Volumio Apr 15 07:52:33 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Apr 15 07:52:33 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:33 volumio ntpd[1581]: Listen normally on 7 wlan0 192.168.211.1:123 Apr 15 07:52:33 volumio ntpd[1581]: new interface(s) found: waking up resolver Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 15 07:52:36 volumio volumio[1235]: info: Adding plugin bluetooth to MyMusic Plugins Apr 15 07:52:36 volumio volumio[1235]: info: Adding plugin multiroom to MyMusic Plugins Apr 15 07:52:36 volumio volumio[1235]: info: Adding plugin metavolumio to MyMusic Plugins Apr 15 07:52:36 volumio volumio[1235]: info: Adding plugin cd_controller to MyMusic Plugins Apr 15 07:52:36 volumio volumio[1235]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 15 07:52:36 volumio volumio[1235]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 15 07:52:36 volumio volumio[1235]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 15 07:52:37 volumio dhcpcd[1022]: wlan0: probing for an IPv4LL address Apr 15 07:52:39 volumio volumio[1235]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 15 07:52:39 volumio volumio[1235]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 15 07:52:39 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:39 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:39 volumio volumio[1235]: info: Starting MyVolumio Remote Streaming Endpoints Apr 15 07:52:39 volumio volumio[1235]: info: MyVolumio not started Apr 15 07:52:39 volumio volumio[1235]: info: Initializing device activation check Apr 15 07:52:39 volumio volumio[1235]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 15 07:52:39 volumio volumio[1235]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 15 07:52:39 volumio volumio[1235]: info: Starting Streaming Service Transparent Proxy Apr 15 07:52:39 volumio volumio[1235]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 15 07:52:39 volumio volumio[1235]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 15 07:52:39 volumio volumio[1235]: info: Streaming services startup Apr 15 07:52:39 volumio volumio[1235]: info: Starting Streaming Daemon Apr 15 07:52:39 volumio sudo[2340]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 15 07:52:39 volumio sudo[2340]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:39 volumio volumio[1235]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 15 07:52:39 volumio sudo[2340]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:39 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: wizard , reportWirelessConnection Apr 15 07:52:39 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessInfo Apr 15 07:52:39 volumio volumio[1235]: error: Cannot start Volumio Streaming Daemon Apr 15 07:52:39 volumio volumio[1235]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 15 07:52:39 volumio volumio[1235]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 15 07:52:39 volumio sudo[2348]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 07:52:39 volumio sudo[2348]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:39 volumio sudo[2348]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:39 volumio volumio[1235]: STREAMING PROXY: Starting server on port 3245 Apr 15 07:52:39 volumio volumio[1235]: Node JS runtime: 14 Apr 15 07:52:40 volumio sudo[2405]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 07:52:40 volumio sudo[2405]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:40 volumio sudo[2405]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:40 volumio sudo[2408]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 07:52:40 volumio sudo[2408]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:40 volumio sudo[2408]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:41 volumio volumio[1235]: verbose: New Socket.io Connection to 192.168.1.164 from 192.168.1.226 UA: Mozilla/5.0 (Linux; Android 14; SM-X910 Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.38 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Apr 15 07:52:41 volumio volumio[1235]: info: CoreCommandRouter::volumioGetVisibleSources Apr 15 07:52:41 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 07:52:42 volumio dhcpcd[1022]: wlan0: using IPv4LL address 169.254.69.19 Apr 15 07:52:42 volumio avahi-daemon[919]: Registering new address record for 169.254.69.19 on wlan0.IPv4. Apr 15 07:52:42 volumio dhcpcd[1022]: wlan0: adding route to 169.254.0.0/16 Apr 15 07:52:42 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart Apr 15 07:52:42 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , onNetworkingRestart Apr 15 07:52:42 volumio volumio[1235]: info: Refreshing Cached IP Addresses Apr 15 07:52:42 volumio sudo[2470]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli Apr 15 07:52:42 volumio sudo[2470]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:42 volumio sudo[2472]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 07:52:42 volumio sudo[2472]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:42 volumio sudo[2470]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:42 volumio sudo[2472]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:42 volumio sudo[2476]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 07:52:42 volumio sudo[2476]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:42 volumio systemd[1]: upmpdcli.service: Succeeded. Apr 15 07:52:42 volumio sudo[2476]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:42 volumio volumio[1235]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Apr 15 07:52:42 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 15 07:52:43 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Apr 15 07:52:43 volumio volumio[1235]: info: MyVolumio login type: Token Apr 15 07:52:43 volumio volumio[1235]: info: CoreCommandRouter::volumioGetVisibleSources Apr 15 07:52:43 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 07:52:43 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: wizard , getWizardSteps Apr 15 07:52:43 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , showActivationCode Apr 15 07:52:43 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Apr 15 07:52:43 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Apr 15 07:52:43 volumio volumio[1235]: info: Received Get System Info Apr 15 07:52:43 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 07:52:43 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 07:52:43 volumio volumio[1235]: info: Discovery: Getting this device information Apr 15 07:52:43 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Apr 15 07:52:43 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:43 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 07:52:43 volumio volumio-remote-updater[922]: No test mode Apr 15 07:52:43 volumio volumio-remote-updater[922]: No alpha test mode Apr 15 07:52:43 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 15 07:52:43 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 15 07:52:43 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:52:43 volumio volumio[1235]: info: Retrieving Cloud Streaming UI Apr 15 07:52:43 volumio volumio[1235]: info: Getting Tidal Cloud Configuration Apr 15 07:52:43 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:52:43 volumio volumio[1235]: info: Getting Qobuz Cloud Configuration Apr 15 07:52:43 volumio volumio[1235]: info: Asking plugin for UI Config Apr 15 07:52:43 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:52:43 volumio volumio[1235]: info: Getting Spotify Cloud Configuration Apr 15 07:52:43 volumio volumio[1235]: info: Asking plugin for UI Config Apr 15 07:52:43 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:52:43 volumio volumio[1235]: info: Saving Spotify Acccount Apr 15 07:52:43 volumio volumio[1235]: info: Got Tidal Cloud Configuration Apr 15 07:52:43 volumio volumio[1235]: info: Got it Apr 15 07:52:43 volumio volumio[1235]: info: Got it Apr 15 07:52:43 volumio volumio[1235]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Apr 15 07:52:43 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:52:43 volumio volumio[1235]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Apr 15 07:52:43 volumio ntpd[1581]: Listen normally on 8 wlan0 169.254.69.19:123 Apr 15 07:52:43 volumio ntpd[1581]: new interface(s) found: waking up resolver Apr 15 07:52:44 volumio volumio[1235]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 15 07:52:44 volumio volumio[1235]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 15 07:52:44 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 15 07:52:44 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 15 07:52:44 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 15 07:52:44 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 15 07:52:44 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Apr 15 07:52:44 volumio volumio[1235]: info: Loading i18n strings for locale en Apr 15 07:52:44 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Apr 15 07:52:44 volumio volumio[1235]: info: Setting timezone to UTC Apr 15 07:52:44 volumio sudo[2496]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Apr 15 07:52:44 volumio sudo[2496]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:44 volumio sudo[2496]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:44 volumio sudo[2499]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/UTC /etc/localtime Apr 15 07:52:44 volumio sudo[2499]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:44 volumio sudo[2499]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:44 volumio sudo[2502]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Apr 15 07:52:44 volumio sudo[2502]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:45 volumio sudo[2502]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:45 volumio sudo[2505]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone UTC Apr 15 07:52:45 volumio sudo[2505]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:45 volumio systemd-timedated[1704]: Failed to set time zone: Permission denied Apr 15 07:52:45 volumio sudo[2505]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:45 volumio volumio[1235]: Failed to set time zone: Access denied Apr 15 07:52:45 volumio volumio[1235]: info: Could not set timezone, retrying Apr 15 07:52:45 volumio volumio[1235]: Updating browse sources language Apr 15 07:52:45 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 07:52:45 volumio volumio[1235]: info: Fetching Streaming Services browse cache Apr 15 07:52:46 volumio sudo[2508]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone UTC Apr 15 07:52:46 volumio sudo[2508]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:46 volumio sudo[2508]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:46 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 15 07:52:46 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 07:52:46 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 07:52:46 volumio volumio[1235]: info: Discovery: Getting this device information Apr 15 07:52:46 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Apr 15 07:52:46 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:46 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 07:52:47 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 15 07:52:48 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 15 07:52:51 volumio volumio[1235]: info: MyVolumio token set successfully Apr 15 07:52:51 volumio volumio[1235]: info: MYVOLUMIO: Adding device Apr 15 07:52:51 volumio volumio[1235]: info: MYVOLUMIO: Evaluating Server Apr 15 07:52:51 volumio volumio[1235]: info: MyVolumio Plan changed: premium Apr 15 07:52:51 volumio volumio[1235]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Apr 15 07:52:51 volumio volumio[1235]: info: Removing browser output: myVolumio user plan is not superstar Apr 15 07:52:51 volumio volumio[1235]: info: Removing audio output: Apr 15 07:52:51 volumio volumio[1235]: info: MYVOLUMIO: Adding device Apr 15 07:52:51 volumio volumio[1235]: info: MYVOLUMIO: Evaluating Server Apr 15 07:52:51 volumio volumio[1235]: info: Remote config written successfully Apr 15 07:52:51 volumio volumio[1235]: info: Starting Tunnel 1 Apr 15 07:52:51 volumio volumio[1235]: info: Starting Tunnel Connection Checker Apr 15 07:52:51 volumio volumio[1235]: info: Completed starting MyVolumio Plugin Apr 15 07:52:51 volumio volumio[1235]: info: MYVolumio Device enabled Apr 15 07:52:51 volumio volumio[1235]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Apr 15 07:52:51 volumio volumio[1235]: info: MyVolumio status changed Apr 15 07:52:51 volumio volumio[1235]: info: Streaming services startup Apr 15 07:52:51 volumio volumio[1235]: info: Starting Streaming Daemon Apr 15 07:52:51 volumio volumio[1235]: error: [MyVolumio PluginManager] Could not read cache file: ENOENT: no such file or directory, open '/data/myvolumio/cache.data' Apr 15 07:52:51 volumio sudo[2562]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 15 07:52:51 volumio sudo[2562]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:51 volumio sudo[2562]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:51 volumio volumio[1235]: error: Cannot start Volumio Streaming Daemon Apr 15 07:52:51 volumio volumio[1235]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 15 07:52:51 volumio volumio[1235]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 15 07:52:51 volumio volumio[1235]: info: Setting Geolocation for MyVolumio to as1 Apr 15 07:52:51 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:51 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:52 volumio volumio[1235]: info: Setting Geolocation for MyVolumio to as1 Apr 15 07:52:52 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:52 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:52 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:52 volumio sudo[2565]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 07:52:52 volumio sudo[2565]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:52 volumio sudo[2565]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:52 volumio sudo[2567]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 07:52:52 volumio sudo[2567]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:52 volumio sudo[2567]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:52 volumio sudo[2571]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 15 07:52:52 volumio sudo[2571]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:52 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Apr 15 07:52:52 volumio sudo[2571]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:52 volumio volumio[1235]: info: Upmpdcli Daemon Started Apr 15 07:52:52 volumio volumio[2573]: writing RSA key Apr 15 07:52:52 volumio volumio[1235]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Apr 15 07:52:52 volumio volumio[1235]: info: [1744703572610] Starting BluetoothController Apr 15 07:52:52 volumio volumio[1235]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Apr 15 07:52:52 volumio sudo[2775]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Apr 15 07:52:52 volumio sudo[2775]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:52 volumio sudo[2775]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:52 volumio volumio[1235]: info: MRS: MultiRoom plugin initialized Apr 15 07:52:52 volumio volumio[1235]: info: MRS: STOPPING SNAPCLIENT Apr 15 07:52:52 volumio volumio[1235]: info: MRS: Snap server stop Apr 15 07:52:52 volumio sudo[2791]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Apr 15 07:52:52 volumio sudo[2791]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:52 volumio volumio[1235]: info: MRS: STOPPING volumioStreaming Apr 15 07:52:52 volumio sudo[2794]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Apr 15 07:52:52 volumio sudo[2794]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:52 volumio sudo[2791]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:52 volumio sudo[2797]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Apr 15 07:52:52 volumio sudo[2797]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:52 volumio sudo[2794]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:52 volumio volumio[1235]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Apr 15 07:52:52 volumio sudo[2800]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Apr 15 07:52:52 volumio sudo[2800]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:52 volumio sudo[2800]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:52 volumio sudo[2797]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:52 volumio volumio[1235]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Apr 15 07:52:52 volumio volumio[1235]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Apr 15 07:52:52 volumio volumio[1235]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Apr 15 07:52:52 volumio volumio[1235]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Apr 15 07:52:52 volumio volumio[1235]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Apr 15 07:52:53 volumio volumio[1235]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Apr 15 07:52:53 volumio volumio[1235]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Apr 15 07:52:53 volumio volumio[1235]: info: Preparing to generate the ALSA configuration file Apr 15 07:52:53 volumio volumio[1235]: info: Updating MyVolumio device info Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Apr 15 07:52:53 volumio volumio[1235]: info: Successfully Added MyVolumio device Apr 15 07:52:53 volumio volumio[1235]: info: Successfully Added MyVolumio device Apr 15 07:52:53 volumio volumio[1235]: info: MRS: Removed streaming files Apr 15 07:52:53 volumio volumio[1235]: info: MRS: volumioStreaming STOPPED Apr 15 07:52:53 volumio volumio[1235]: info: MRS: SNAPSERVER STOPPED Apr 15 07:52:53 volumio volumio[1235]: info: MRS: SNAPCLIENT STOPPED Apr 15 07:52:53 volumio volumio[1235]: info: Asound.conf file unchanged, so no further update is needed Apr 15 07:52:53 volumio volumio[1235]: info: Output device has changed, restarting MPD Apr 15 07:52:53 volumio sudo[2803]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 15 07:52:53 volumio sudo[2803]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:53 volumio volumio[1235]: info: Output device has changed, restarting Shairport Sync Apr 15 07:52:53 volumio sudo[2803]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:53 volumio sudo[2806]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 15 07:52:53 volumio sudo[2806]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:53 volumio systemd[1]: Stopping Music Player Daemon... Apr 15 07:52:53 volumio volumio[1235]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 15 07:52:53 volumio systemd[1]: mpd.service: Succeeded. Apr 15 07:52:53 volumio volumio[1235]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 15 07:52:53 volumio systemd[1]: Stopped Music Player Daemon. Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 15 07:52:53 volumio volumio[1235]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Apr 15 07:52:53 volumio volumio[1235]: info: MRS: Pushing multiroomSync output for this device Apr 15 07:52:53 volumio volumio[1235]: info: MRS: Pushing multiroomSync output Apr 15 07:52:53 volumio volumio[1235]: info: Adding audio output: Apr 15 07:52:53 volumio volumio[1235]: info: Adding audio output: Apr 15 07:52:53 volumio sudo[2815]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Volumio Apr 15 07:52:53 volumio sudo[2815]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:53 volumio volumio[1235]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Apr 15 07:52:53 volumio volumio[1235]: info: Adding METAVOLUMIO REST API Endpoints Apr 15 07:52:53 volumio volumio[1235]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Apr 15 07:52:53 volumio volumio[1235]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Apr 15 07:52:53 volumio volumio[1235]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Apr 15 07:52:53 volumio volumio[1235]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Apr 15 07:52:53 volumio volumio[1235]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Apr 15 07:52:53 volumio volumio[1235]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Apr 15 07:52:53 volumio volumio[1235]: info: Preparing CD Folders Apr 15 07:52:53 volumio volumio[1235]: info: Adding CD REST API Endpoints Apr 15 07:52:53 volumio volumio[1235]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Apr 15 07:52:53 volumio volumio[1235]: info: Starting UDEV Watcher for CD Apr 15 07:52:53 volumio volumio[1235]: info: Detecting CD presence with UDEV Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Apr 15 07:52:53 volumio volumio[1235]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Apr 15 07:52:53 volumio volumio[1235]: info: Adding inputs REST Endpoints Apr 15 07:52:53 volumio volumio[1235]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Apr 15 07:52:53 volumio volumio[1235]: info: Scanning Audio Inputs Apr 15 07:52:53 volumio systemd[1]: Starting Music Player Daemon... Apr 15 07:52:53 volumio volumio[1235]: info: Checking against Known Cards name Apr 15 07:52:53 volumio volumio[1235]: info: Checking against Known Cards name Apr 15 07:52:53 volumio volumio[1235]: info: Adding Server instance for streaming Apr 15 07:52:53 volumio volumio[1235]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Apr 15 07:52:53 volumio volumio[1235]: error: Hi Res Audio Failed Login: Missing Login Data Apr 15 07:52:53 volumio volumio[1235]: info: Adding HIGHRESAUDIO REST API Endpoints Apr 15 07:52:53 volumio volumio[1235]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Apr 15 07:52:53 volumio volumio[1235]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Apr 15 07:52:53 volumio volumio[1235]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Apr 15 07:52:53 volumio volumio[1235]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Apr 15 07:52:53 volumio sudo[2811]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 15 07:52:53 volumio sudo[2811]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:53 volumio sudo[2823]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 15 07:52:53 volumio sudo[2823]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:53 volumio volumio[1235]: info: Stopping AccessToken refresher cron Apr 15 07:52:53 volumio sudo[2811]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:53 volumio sudo[2823]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:53 volumio volumio[1235]: info: AccessToken refresher cron started Apr 15 07:52:53 volumio volumio[1235]: info: Stopping AccessToken refresher cron for QOBUZ Apr 15 07:52:53 volumio volumio[1235]: info: AccessToken refresher cron started for QOBUZ Apr 15 07:52:53 volumio volumio[1235]: info: Adding TIDAL REST API Endpoints Apr 15 07:52:53 volumio volumio[1235]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Apr 15 07:52:53 volumio volumio[1235]: info: Adding QOBUZ REST API Endpoints Apr 15 07:52:53 volumio volumio[1235]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Apr 15 07:52:53 volumio volumio[1235]: info: MPD Permissions set Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: Starting Shairport Sync Apr 15 07:52:53 volumio volumio[1235]: info: Preparing to generate the ALSA configuration file Apr 15 07:52:53 volumio sudo[2836]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 15 07:52:53 volumio sudo[2836]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:53 volumio volumio[1235]: info: Asound.conf file unchanged, so no further update is needed Apr 15 07:52:53 volumio volumio[1235]: info: Output device has changed, restarting MPD Apr 15 07:52:53 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 15 07:52:53 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 15 07:52:53 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 15 07:52:53 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 15 07:52:53 volumio sudo[2836]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:53 volumio sudo[2839]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 15 07:52:53 volumio sudo[2839]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:53 volumio sudo[2839]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:53 volumio volumio[1235]: info: Output device has changed, restarting Shairport Sync Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:53 volumio sudo[2843]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 15 07:52:53 volumio sudo[2843]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:53 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 15 07:52:53 volumio systemd[1]: mpd.service: Succeeded. Apr 15 07:52:53 volumio systemd[1]: Stopped Music Player Daemon. Apr 15 07:52:53 volumio systemd[1]: Starting Music Player Daemon... Apr 15 07:52:53 volumio volumio[1235]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 15 07:52:53 volumio volumio[1235]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: Preparing to generate the ALSA configuration file Apr 15 07:52:53 volumio volumio[1235]: info: MRS: Found cast device: BRAVIA-4K-UR2-2d269633744d6b197d6ebbf75a9dcd67 Apr 15 07:52:53 volumio volumio[1235]: info: Adding audio output: Apr 15 07:52:53 volumio volumio[1235]: info: MPD Permissions set Apr 15 07:52:53 volumio volumio[1235]: info: Shairport-Sync Started Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio sudo[2815]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 15 07:52:53 volumio sudo[2850]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 15 07:52:53 volumio sudo[2850]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:53 volumio sudo[2850]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: Asound.conf file unchanged, so no further update is needed Apr 15 07:52:53 volumio volumio[1235]: info: Output device has changed, restarting MPD Apr 15 07:52:53 volumio sudo[2863]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 15 07:52:53 volumio sudo[2863]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:53 volumio volumio[1235]: info: Output device has changed, restarting Shairport Sync Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:53 volumio sudo[2863]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:53 volumio sudo[2866]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 15 07:52:53 volumio sudo[2866]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:53 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 15 07:52:53 volumio systemd[1]: mpd.service: Succeeded. Apr 15 07:52:53 volumio systemd[1]: Stopped Music Player Daemon. Apr 15 07:52:53 volumio systemd[1]: Starting Music Player Daemon... Apr 15 07:52:53 volumio volumio[1235]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 15 07:52:53 volumio volumio[1235]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: Updating MyVolumio device info Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: MPD Permissions set Apr 15 07:52:53 volumio volumio[1235]: info: Bluetooth name changed to Volumio Apr 15 07:52:53 volumio volumio[1235]: info: Starting Shairport Sync Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio sudo[2875]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 15 07:52:53 volumio sudo[2875]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:53 volumio sudo[2871]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 15 07:52:53 volumio sudo[2871]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:53 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 15 07:52:53 volumio sudo[2871]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:53 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 15 07:52:53 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 15 07:52:53 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 15 07:52:53 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:53 volumio sudo[2875]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:53 volumio volumio[1235]: info: Shairport-Sync Started Apr 15 07:52:53 volumio volumio[1235]: info: Starting Shairport Sync Apr 15 07:52:53 volumio sudo[2888]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 15 07:52:53 volumio sudo[2888]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:53 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 15 07:52:53 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 15 07:52:53 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 15 07:52:53 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 15 07:52:53 volumio sudo[2888]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:53 volumio volumio[1235]: info: Shairport-Sync Started Apr 15 07:52:53 volumio mpd[2883]: Apr 15 07:52 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 15 07:52:53 volumio systemd[1]: Started Music Player Daemon. Apr 15 07:52:53 volumio sudo[2806]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:53 volumio sudo[2843]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:53 volumio sudo[2866]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:53 volumio volumio[1235]: error: MPD error: The expression evaluated to a falsy value: Apr 15 07:52:53 volumio volumio[1235]: assert.ok(self.idling) Apr 15 07:52:53 volumio volumio[1235]: error: The expression evaluated to a falsy value: Apr 15 07:52:53 volumio volumio[1235]: assert.ok(self.idling) Apr 15 07:52:53 volumio volumio[1235]: error: MPD error: The expression evaluated to a falsy value: Apr 15 07:52:53 volumio volumio[1235]: assert.ok(self.idling) Apr 15 07:52:53 volumio volumio[1235]: error: The expression evaluated to a falsy value: Apr 15 07:52:53 volumio volumio[1235]: assert.ok(self.idling) Apr 15 07:52:53 volumio volumio[1235]: error: updateQueue error: null Apr 15 07:52:53 volumio volumio[1235]: info: Successfully Updated MyVolumio device Apr 15 07:52:53 volumio volumio[1235]: info: Successfully Updated MyVolumio device Apr 15 07:52:54 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 15 07:52:54 volumio volumio[1235]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Apr 15 07:52:54 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Apr 15 07:52:54 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:55 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 07:52:55 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:55 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 15 07:52:55 volumio volumio-remote-updater[922]: No test mode Apr 15 07:52:55 volumio volumio-remote-updater[922]: No alpha test mode Apr 15 07:52:55 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 15 07:52:55 volumio volumio[1235]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 15 07:52:55 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 15 07:52:56 volumio sudo[2907]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Apr 15 07:52:56 volumio sudo[2907]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:56 volumio systemd[1]: Started Volumio Bluetooth Module. Apr 15 07:52:56 volumio sudo[2907]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:56 volumio volumio[1235]: info: Volumio BT Module successfully started Apr 15 07:52:56 volumio sudo[2910]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Apr 15 07:52:56 volumio sudo[2910]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:56 volumio volumiobt[2909]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Apr 15 07:52:56 volumio sudo[2910]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:56 volumio volumio[1235]: info: TidalConnect service stoped! Apr 15 07:52:56 volumio volumio[1235]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Apr 15 07:52:56 volumio volumio[1235]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Apr 15 07:52:56 volumio sudo[2922]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Apr 15 07:52:56 volumio sudo[2922]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:56 volumio systemd[1]: Started Volumio Tidal Connect Service. Apr 15 07:52:56 volumio sudo[2922]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:56 volumio volumio[1235]: info: Executing endpoint tc_getconfig Apr 15 07:52:56 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Apr 15 07:52:56 volumio vtcs[2924]: STARTING TidalConnect services, version: 1.5.0.45 Apr 15 07:52:56 volumio vtcs[2924]: STARTED TidalConnect services. Apr 15 07:52:56 volumio volumio[1235]: info: Executing endpoint tc_connect Apr 15 07:52:56 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Apr 15 07:52:56 volumio volumio[1235]: info: Connecting to TidalConnect Apr 15 07:52:56 volumio volumio[1235]: info: CoreCommandRouter::servicePushState Apr 15 07:52:56 volumio volumio[1235]: info: CoreStateMachine::pushState Apr 15 07:52:56 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:56 volumio volumio[1235]: info: CoreCommandRouter::volumioPushState Apr 15 07:52:56 volumio volumio[1235]: info: MRS: Pushing multiroomSync output update for this device Apr 15 07:52:56 volumio volumio[1235]: info: MRS: Pushing multiroomSync output Apr 15 07:52:56 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:56 volumio volumio[1235]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Apr 15 07:52:56 volumio volumio[1235]: verbose: CURRENT POSITION 0 Apr 15 07:52:56 volumio volumio[1235]: info: CoreStateMachine::syncState stateService stop Apr 15 07:52:56 volumio volumio[1235]: info: CoreStateMachine::syncState currentStatus stop Apr 15 07:52:56 volumio volumio[1235]: info: CoreStateMachine::pushState Apr 15 07:52:56 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:56 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 07:52:56 volumio volumio[1235]: info: CoreCommandRouter::volumioPushState Apr 15 07:52:56 volumio volumio[1235]: info: MRS: Pushing multiroomSync output update for this device Apr 15 07:52:56 volumio volumio[1235]: info: MRS: Pushing multiroomSync output Apr 15 07:52:56 volumio volumio[1235]: info: No code Apr 15 07:52:56 volumio volumio[1235]: info: CoreStateMachine::pushState Apr 15 07:52:56 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:56 volumio volumio[1235]: info: CoreCommandRouter::volumioPushState Apr 15 07:52:56 volumio volumio[1235]: info: MRS: Pushing multiroomSync output update for this device Apr 15 07:52:56 volumio volumio[1235]: info: MRS: Pushing multiroomSync output Apr 15 07:52:56 volumio volumio[1235]: info: CoreCommandRouter::servicePushState Apr 15 07:52:56 volumio volumio[1235]: info: CoreStateMachine::pushState Apr 15 07:52:56 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:56 volumio volumio[1235]: info: CoreCommandRouter::volumioPushState Apr 15 07:52:56 volumio volumio[1235]: info: MRS: Pushing multiroomSync output update for this device Apr 15 07:52:56 volumio volumio[1235]: info: MRS: Pushing multiroomSync output Apr 15 07:52:56 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:56 volumio volumio[1235]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Apr 15 07:52:56 volumio volumio[1235]: verbose: CURRENT POSITION 0 Apr 15 07:52:56 volumio volumio[1235]: info: CoreStateMachine::syncState stateService stop Apr 15 07:52:56 volumio volumio[1235]: info: CoreStateMachine::syncState currentStatus stop Apr 15 07:52:56 volumio volumio[1235]: info: CoreStateMachine::pushState Apr 15 07:52:56 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:56 volumio volumio[1235]: info: CoreCommandRouter::volumioPushState Apr 15 07:52:56 volumio volumio[1235]: info: MRS: Pushing multiroomSync output update for this device Apr 15 07:52:56 volumio volumio[1235]: info: MRS: Pushing multiroomSync output Apr 15 07:52:56 volumio volumio[1235]: info: No code Apr 15 07:52:56 volumio volumio[1235]: info: CoreStateMachine::pushState Apr 15 07:52:56 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:56 volumio volumio[1235]: info: CoreCommandRouter::volumioPushState Apr 15 07:52:56 volumio volumio[1235]: info: MRS: Pushing multiroomSync output update for this device Apr 15 07:52:56 volumio volumio[1235]: info: MRS: Pushing multiroomSync output Apr 15 07:52:56 volumio sudo[2948]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Apr 15 07:52:56 volumio sudo[2948]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:56 volumio systemd[1]: Started MyVolumio SSH Tunnel. Apr 15 07:52:56 volumio sudo[2948]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:56 volumio volumio[1235]: info: Remote SSH Started Apr 15 07:52:56 volumio autossh[2951]: port set to 0, monitoring disabled Apr 15 07:52:56 volumio autossh[2951]: starting ssh (count 1) Apr 15 07:52:56 volumio autossh[2951]: ssh child pid is 2954 Apr 15 07:52:56 volumio volumio[1235]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 15 07:52:57 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Apr 15 07:52:57 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:57 volumio sudo[2955]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Apr 15 07:52:57 volumio sudo[2955]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:52:57 volumio volumiobt[2909]: pulseaudio: no process found Apr 15 07:52:57 volumio sudo[2955]: pam_unix(sudo:session): session closed for user root Apr 15 07:52:57 volumio volumiossh-tunnel[2950]: Warning: Permanently added '[as1.myvolumio.org]:2222,[128.199.166.162]:2222' (RSA) to the list of known hosts. Apr 15 07:52:57 volumio dbus-daemon[931]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.31' (uid=1000 pid=2959 comm="/usr/bin/pulseaudio --high-priority=true ") Apr 15 07:52:57 volumio systemd[1]: Starting RealtimeKit Scheduling Policy Service... Apr 15 07:52:57 volumio volumio[1235]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 15 07:52:57 volumio dbus-daemon[931]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Apr 15 07:52:57 volumio systemd[1]: Started RealtimeKit Scheduling Policy Service. Apr 15 07:52:57 volumio rtkit-daemon[2960]: Successfully called chroot. Apr 15 07:52:57 volumio rtkit-daemon[2960]: Successfully dropped privileges. Apr 15 07:52:57 volumio rtkit-daemon[2960]: Successfully limited resources. Apr 15 07:52:57 volumio rtkit-daemon[2960]: Running. Apr 15 07:52:57 volumio rtkit-daemon[2960]: Canary thread running. Apr 15 07:52:57 volumio rtkit-daemon[2960]: Watchdog thread running. Apr 15 07:52:57 volumio dbus-daemon[931]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.32' (uid=0 pid=2960 comm="/usr/lib/rtkit/rtkit-daemon ") Apr 15 07:52:57 volumio systemd[1]: Starting Authorization Manager... Apr 15 07:52:57 volumio volumio[1235]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 15 07:52:57 volumio polkitd[2963]: started daemon version 0.105 using authority implementation `local' version `0.105' Apr 15 07:52:57 volumio dbus-daemon[931]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Apr 15 07:52:57 volumio systemd[1]: Started Authorization Manager. Apr 15 07:52:57 volumio pulseaudio[2959]: Failed to open cookie file '/home/volumio/.config/pulse/cookie': No such file or directory Apr 15 07:52:57 volumio pulseaudio[2959]: Failed to load authentication key '/home/volumio/.config/pulse/cookie': No such file or directory Apr 15 07:52:57 volumio pulseaudio[2959]: Failed to open cookie file '/home/volumio/.pulse-cookie': No such file or directory Apr 15 07:52:57 volumio pulseaudio[2959]: Failed to load authentication key '/home/volumio/.pulse-cookie': No such file or directory Apr 15 07:52:57 volumio pulseaudio[2959]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Apr 15 07:52:57 volumio pulseaudio[2959]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Apr 15 07:52:57 volumio bluetoothd[926]: Endpoint registered: sender=:1.52 path=/MediaEndpoint/A2DPSource Apr 15 07:52:57 volumio bluetoothd[926]: Endpoint registered: sender=:1.52 path=/MediaEndpoint/A2DPSink Apr 15 07:52:57 volumio volumiobt[2909]: Applying permissions Apr 15 07:52:57 volumio volumiobt[2909]: Setting BT discoverable and pairable Apr 15 07:52:57 volumio pulseaudio[2959]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files Apr 15 07:52:57 volumio kernel: Bluetooth: RFCOMM TTY layer initialized Apr 15 07:52:57 volumio kernel: Bluetooth: RFCOMM socket layer initialized Apr 15 07:52:57 volumio kernel: Bluetooth: RFCOMM ver 1.11 Apr 15 07:52:57 volumio volumiobt[2909]: Agent registered Apr 15 07:52:57 volumio volumiobt[2909]: [bluetooth]# -e power on Apr 15 07:52:57 volumio volumiobt[2909]: Invalid command in menu main: -e Apr 15 07:52:57 volumio volumiobt[2909]: Apr 15 07:52:57 volumio volumiobt[2909]: Use "help" for a list of available commands in a menu. Apr 15 07:52:57 volumio volumiobt[2909]: Use "menu " if you want to enter any submenu. Apr 15 07:52:57 volumio volumiobt[2909]: Use "back" if you want to return to menu main. Apr 15 07:52:57 volumio volumiobt[2909]: [bluetooth]# agent on Apr 15 07:52:57 volumio volumiobt[2909]: Agent is already registered Apr 15 07:52:57 volumio volumiobt[2909]: [bluetooth]# discoverable on Apr 15 07:52:57 volumio volumiobt[2909]: [bluetooth]# pairable on Apr 15 07:52:57 volumio volumiobt[2909]: [bluetooth]# agent NoInputNoOutput Apr 15 07:52:57 volumio volumiobt[2909]: Agent is already registered Apr 15 07:52:57 volumio volumiobt[2909]: [bluetooth]# default-agent Apr 15 07:52:57 volumio volumiobt[2909]: [bluetooth]# quit Apr 15 07:52:57 volumio volumiobt[2909]: [59B blob data] Apr 15 07:52:58 volumio volumio[1235]: info: MRS: Getting audio outputs on start Apr 15 07:52:58 volumio volumio[1235]: info: MRS: Requesting all other devices output Apr 15 07:52:59 volumio volumio[1235]: info: TidalConnect service started! Apr 15 07:52:59 volumio volumio[1235]: [Metrics] CommandRouter: 41s 708.59ms Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::volumiosetStartupVolume Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::Close All Modals sent Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::Close All Modals sent Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:52:59 volumio volumio[1235]: info: Retrieving Cloud Streaming UI Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:52:59 volumio volumio[1235]: info: Retrieving Cloud Streaming UI Apr 15 07:52:59 volumio volumio[1235]: info: Getting Tidal Cloud Configuration Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:52:59 volumio volumio[1235]: info: Getting Qobuz Cloud Configuration Apr 15 07:52:59 volumio volumio[1235]: info: Asking plugin for UI Config Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:52:59 volumio volumio[1235]: info: Getting Spotify Cloud Configuration Apr 15 07:52:59 volumio volumio[1235]: info: Asking plugin for UI Config Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:52:59 volumio volumio[1235]: info: Saving Spotify Acccount Apr 15 07:52:59 volumio volumio[1235]: info: Got it Apr 15 07:52:59 volumio volumio[1235]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Apr 15 07:52:59 volumio volumio[1235]: info: Getting Tidal Cloud Configuration Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:52:59 volumio volumio[1235]: info: Getting Qobuz Cloud Configuration Apr 15 07:52:59 volumio volumio[1235]: info: Asking plugin for UI Config Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:52:59 volumio volumio[1235]: info: Getting Spotify Cloud Configuration Apr 15 07:52:59 volumio volumio[1235]: info: Asking plugin for UI Config Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:52:59 volumio volumio[1235]: info: Saving Spotify Acccount Apr 15 07:52:59 volumio volumio[1235]: info: Got it Apr 15 07:52:59 volumio volumio[1235]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::volumioGetBrowseSources Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 07:52:59 volumio volumio[1235]: info: Got it Apr 15 07:52:59 volumio volumio[1235]: info: Got Tidal Cloud Configuration Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:52:59 volumio volumio[1235]: info: Got Tidal Cloud Configuration Apr 15 07:52:59 volumio volumio[1235]: info: Got it Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 15 07:52:59 volumio volumio[1235]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 15 07:52:59 volumio volumio[1235]: info: Received Get System Version Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 07:52:59 volumio volumio[1235]: info: Received Get System Info Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 07:52:59 volumio volumio[1235]: info: Discovery: Getting this device information Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Apr 15 07:52:59 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:52:59 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 15 07:53:00 volumio volumio[1235]: No protocol specified Apr 15 07:53:00 volumio volumio[1235]: xcb_connection_has_error() returned true Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 15 07:53:00 volumio volumio[1235]: info: Version has changed, forcing UI Reload Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::Reload Ui Apr 15 07:53:00 volumio sudo[2993]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 07:53:00 volumio sudo[2993]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:53:00 volumio sudo[2993]: pam_unix(sudo:session): session closed for user root Apr 15 07:53:00 volumio sudo[2996]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 07:53:00 volumio sudo[2996]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:53:00 volumio sudo[2996]: pam_unix(sudo:session): session closed for user root Apr 15 07:53:00 volumio volumio[1235]: verbose: New Socket.io Connection to 192.168.1.164 from 192.168.1.226 UA: Mozilla/5.0 (Linux; Android 14; SM-X910 Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.38 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::volumioGetVisibleSources Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: wizard , getWizardSteps Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , showActivationCode Apr 15 07:53:00 volumio volumio[1235]: No protocol specified Apr 15 07:53:00 volumio volumio[1235]: xcb_connection_has_error() returned true Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Apr 15 07:53:00 volumio volumio[1235]: info: Received Get System Info Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 07:53:00 volumio volumio[1235]: info: Discovery: Getting this device information Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Apr 15 07:53:00 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 07:53:00 volumio volumio-remote-updater[922]: No test mode Apr 15 07:53:00 volumio volumio-remote-updater[922]: No alpha test mode Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 15 07:53:00 volumio volumio[1235]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:53:00 volumio volumio[1235]: info: Retrieving Cloud Streaming UI Apr 15 07:53:00 volumio volumio[1235]: info: Getting Tidal Cloud Configuration Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:53:00 volumio volumio[1235]: info: Getting Qobuz Cloud Configuration Apr 15 07:53:00 volumio volumio[1235]: info: Asking plugin for UI Config Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:53:00 volumio volumio[1235]: info: Getting Spotify Cloud Configuration Apr 15 07:53:00 volumio volumio[1235]: info: Asking plugin for UI Config Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:53:00 volumio volumio[1235]: info: Saving Spotify Acccount Apr 15 07:53:00 volumio volumio[1235]: info: Got it Apr 15 07:53:00 volumio volumio[1235]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Apr 15 07:53:00 volumio volumio[1235]: info: Got it Apr 15 07:53:00 volumio volumio[1235]: info: Got Tidal Cloud Configuration Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::volumioGetVisibleSources Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: wizard , getWizardSteps Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , showActivationCode Apr 15 07:53:00 volumio volumio[1235]: No protocol specified Apr 15 07:53:00 volumio volumio[1235]: xcb_connection_has_error() returned true Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Apr 15 07:53:00 volumio volumio[1235]: info: Received Get System Info Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 07:53:00 volumio volumio[1235]: info: Discovery: Getting this device information Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Apr 15 07:53:00 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:53:00 volumio volumio[1235]: info: Retrieving Cloud Streaming UI Apr 15 07:53:00 volumio volumio[1235]: info: Getting Tidal Cloud Configuration Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:53:00 volumio volumio[1235]: info: Getting Qobuz Cloud Configuration Apr 15 07:53:00 volumio volumio[1235]: info: Asking plugin for UI Config Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:53:00 volumio volumio[1235]: info: Getting Spotify Cloud Configuration Apr 15 07:53:00 volumio volumio[1235]: info: Asking plugin for UI Config Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:53:00 volumio volumio[1235]: info: Saving Spotify Acccount Apr 15 07:53:00 volumio volumio[1235]: info: Got it Apr 15 07:53:00 volumio volumio[1235]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Apr 15 07:53:00 volumio volumio[1235]: info: Got Tidal Cloud Configuration Apr 15 07:53:00 volumio volumio[1235]: info: Got it Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 07:53:00 volumio volumio-remote-updater[922]: No test mode Apr 15 07:53:00 volumio volumio-remote-updater[922]: No alpha test mode Apr 15 07:53:00 volumio volumio[1235]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 15 07:53:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 15 07:53:01 volumio volumio[1235]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 15 07:53:01 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 15 07:53:01 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Apr 15 07:53:01 volumio volumio[1235]: info: Loading i18n strings for locale en Apr 15 07:53:01 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Apr 15 07:53:01 volumio volumio[1235]: info: Setting timezone to Asia/Kuala_Lumpur Apr 15 07:53:01 volumio sudo[3007]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Apr 15 07:53:01 volumio sudo[3007]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:53:01 volumio sudo[3007]: pam_unix(sudo:session): session closed for user root Apr 15 07:53:01 volumio sudo[3010]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Asia/Kuala_Lumpur /etc/localtime Apr 15 07:53:01 volumio sudo[3010]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:53:01 volumio sudo[3010]: pam_unix(sudo:session): session closed for user root Apr 15 07:53:01 volumio sudo[3013]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Apr 15 07:53:01 volumio sudo[3013]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:53:02 volumio sudo[3013]: pam_unix(sudo:session): session closed for user root Apr 15 07:53:02 volumio sudo[3029]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Asia/Kuala_Lumpur Apr 15 07:53:02 volumio sudo[3029]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:53:02 volumio systemd-timedated[1704]: Failed to set time zone: Permission denied Apr 15 07:53:02 volumio sudo[3029]: pam_unix(sudo:session): session closed for user root Apr 15 07:53:02 volumio volumio[1235]: Failed to set time zone: Access denied Apr 15 07:53:02 volumio volumio[1235]: info: Could not set timezone, retrying Apr 15 07:53:02 volumio volumio[1235]: info: Fetching Streaming Services browse cache Apr 15 07:53:02 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 15 07:53:02 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Apr 15 07:53:02 volumio volumio[1235]: info: Loading i18n strings for locale en Apr 15 07:53:02 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Apr 15 07:53:02 volumio volumio[1235]: info: Setting timezone to UTC Apr 15 07:53:02 volumio sudo[3066]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Apr 15 07:53:02 volumio sudo[3066]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:53:02 volumio sudo[3066]: pam_unix(sudo:session): session closed for user root Apr 15 07:53:02 volumio sudo[3069]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/UTC /etc/localtime Apr 15 07:53:02 volumio sudo[3069]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:53:02 volumio sudo[3069]: pam_unix(sudo:session): session closed for user root Apr 15 07:53:02 volumio sudo[3072]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Apr 15 07:53:02 volumio sudo[3072]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:53:02 volumio sudo[3072]: pam_unix(sudo:session): session closed for user root Apr 15 07:53:02 volumio sudo[3075]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone UTC Apr 15 07:53:02 volumio sudo[3075]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:53:02 volumio systemd-timedated[1704]: Failed to set time zone: Permission denied Apr 15 07:53:02 volumio sudo[3075]: pam_unix(sudo:session): session closed for user root Apr 15 07:53:02 volumio volumio[1235]: Failed to set time zone: Access denied Apr 15 07:53:02 volumio volumio[1235]: info: Could not set timezone, retrying Apr 15 07:53:02 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 15 07:53:02 volumio volumio[1235]: Updating browse sources language Apr 15 07:53:02 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 07:53:02 volumio volumio[1235]: Updating browse sources language Apr 15 07:53:02 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 07:53:02 volumio volumio[1235]: info: Fetching Streaming Services browse cache Apr 15 07:53:03 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 15 07:53:03 volumio sudo[3078]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Asia/Kuala_Lumpur Apr 15 07:53:03 volumio sudo[3078]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 07:53:03 volumio systemd-timedated[1704]: Failed to set time zone: Permission denied Apr 15 07:53:03 volumio sudo[3078]: pam_unix(sudo:session): session closed for user root Apr 15 07:53:03 volumio volumio[1235]: Failed to set time zone: Access denied Apr 15 07:53:03 volumio volumio[1235]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 07:53:03 volumio volumio[1235]: Error: Command failed: /usr/bin/sudo /usr/bin/timedatectl set-timezone 'Asia/Kuala_Lumpur' Apr 15 07:53:03 volumio volumio[1235]: Failed to set time zone: Access denied Apr 15 07:53:03 volumio volumio[1235]: at checkExecSyncError (child_process.js:790:11) Apr 15 07:53:03 volumio volumio[1235]: at execSync (child_process.js:863:15) Apr 15 07:53:03 volumio volumio[1235]: at Timeout._onTimeout (/volumio/app/plugins/system_controller/system/index.js:1575:9) Apr 15 07:53:03 volumio volumio[1235]: at listOnTimeout (internal/timers.js:557:17) Apr 15 07:53:03 volumio volumio[1235]: at processTimers (internal/timers.js:500:7) { Apr 15 07:53:03 volumio volumio[1235]: status: 1, Apr 15 07:53:03 volumio volumio[1235]: signal: null, Apr 15 07:53:03 volumio volumio[1235]: output: [ null, '', 'Failed to set time zone: Access denied\n' ], Apr 15 07:53:03 volumio volumio[1235]: pid: 3077, Apr 15 07:53:03 volumio volumio[1235]: stdout: '', Apr 15 07:53:03 volumio volumio[1235]: stderr: 'Failed to set time zone: Access denied\n' Apr 15 07:53:03 volumio volumio[1235]: } Apr 15 07:53:03 volumio volumio[1235]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 07:53:03 volumio sudo[3089]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-15 07:52 Apr 15 07:53:03 volumio sudo[3089]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 07:27:48 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="4bc1ecb08f34ad14b420d6678a2aef1b"