-- Logs begin at Mon 2025-09-01 14:32:55 +07, end at Mon 2025-09-01 14:34:58 +07. -- Sep 01 14:33:00 volumio dhcpcd[794]: eth0: carrier acquired Sep 01 14:33:00 volumio dhcpcd[767]: eth0: carrier acquired Sep 01 14:33:00 volumio sh[713]: eth0: carrier acquired Sep 01 14:33:00 volumio kernel: r8169 0000:01:00.0 eth0: Link is Up - 1Gbps/Full - flow control rx/tx Sep 01 14:33:00 volumio dhcpcd[794]: eth0: carrier acquired Sep 01 14:33:00 volumio sh[713]: eth0: IAID ef:40:b2:32 Sep 01 14:33:00 volumio dhcpcd[794]: eth0: IAID ef:40:b2:32 Sep 01 14:33:00 volumio dhcpcd[767]: eth0: IAID ef:40:b2:32 Sep 01 14:33:00 volumio dhcpcd[794]: eth0: IAID ef:40:b2:32 Sep 01 14:33:00 volumio dhcpcd[794]: eth0: soliciting an IPv6 router Sep 01 14:33:00 volumio dhcpcd[794]: eth0: soliciting an IPv6 router Sep 01 14:33:00 volumio dhcpcd[794]: eth0: soliciting a DHCP lease Sep 01 14:33:00 volumio dhcpcd[794]: eth0: soliciting a DHCP lease Sep 01 14:33:00 volumio sh[713]: eth0: soliciting an IPv6 router Sep 01 14:33:00 volumio dhcpcd[767]: eth0: soliciting an IPv6 router Sep 01 14:33:00 volumio ifplugd(eth0)[936]: Link beat detected. Sep 01 14:33:00 volumio ifplugd(eth0)[936]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Sep 01 14:33:00 volumio ifplugd(eth0)[936]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Sep 01 14:33:00 volumio sh[713]: eth0: soliciting a DHCP lease Sep 01 14:33:00 volumio dhcpcd[767]: eth0: soliciting a DHCP lease Sep 01 14:33:00 volumio ntpd[925]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Sep 01 14:33:01 volumio sh[713]: eth0: offered 192.168.31.203 from 192.168.31.1 Sep 01 14:33:01 volumio dhcpcd[767]: eth0: offered 192.168.31.203 from 192.168.31.1 Sep 01 14:33:01 volumio sh[713]: eth0: probing address 192.168.31.203/24 Sep 01 14:33:01 volumio dhcpcd[767]: eth0: probing address 192.168.31.203/24 Sep 01 14:33:01 volumio systemd[1]: systemd-rfkill.service: Succeeded. Sep 01 14:33:01 volumio volumio-time-update[755]: volumio-time-update-util: Fetching time from Volumio... Sep 01 14:33:01 volumio volumio-time-update[755]: volumio-time-update-util: Date not found in response Sep 01 14:33:01 volumio volumio-time-update[755]: volumio-time-update-util: Retrying in 5 seconds... Sep 01 14:33:02 volumio volumio-remote-updater[781]: [2025-09-01 07:33:02] [info] asio async_connect error: system:111 (Connection refused) Sep 01 14:33:02 volumio volumio-remote-updater[781]: [2025-09-01 07:33:02] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Sep 01 14:33:02 volumio volumio-remote-updater[781]: [2025-09-01 07:33:02] [error] handle_connect error: Underlying Transport Error Sep 01 14:33:02 volumio sudo[1058]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:02 volumio wireless.js[779]: SETTING APPROPRIATE REG DOMAIN: CN Sep 01 14:33:02 volumio sudo[1089]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Sep 01 14:33:02 volumio sudo[1089]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:02 volumio sudo[1089]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:02 volumio sudo[1091]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set CN Sep 01 14:33:02 volumio sudo[1091]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:02 volumio sudo[1091]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:02 volumio wireless.js[779]: SUCCESSFULLY SET NEW REGDOMAIN: CN Sep 01 14:33:02 volumio sudo[1098]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Sep 01 14:33:02 volumio sudo[1098]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:02 volumio sudo[1098]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:02 volumio sudo[1100]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Sep 01 14:33:02 volumio sudo[1100]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:02 volumio sudo[1100]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:03 volumio avahi-daemon[800]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Sep 01 14:33:03 volumio avahi-daemon[800]: New relevant interface wlan0.IPv4 for mDNS. Sep 01 14:33:03 volumio avahi-daemon[800]: Registering new address record for 192.168.211.1 on wlan0.IPv4. Sep 01 14:33:03 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Sep 01 14:33:03 volumio hostapd[1106]: Configuration file: /etc/hostapd/hostapd.conf Sep 01 14:33:03 volumio hostapd[1106]: Using interface wlan0 with hwaddr c0:4b:24:9f:71:be and ssid "Volumio" Sep 01 14:33:03 volumio dhcpcd[794]: eth0: offered 192.168.31.203 from 192.168.31.1 Sep 01 14:33:03 volumio dhcpcd[794]: eth0: offered 192.168.31.203 from 192.168.31.1 Sep 01 14:33:03 volumio dhcpcd[794]: wlan0: carrier acquired Sep 01 14:33:03 volumio dhcpcd[794]: wlan0: carrier acquired Sep 01 14:33:03 volumio hostapd[1106]: wlan0: interface state UNINITIALIZED->ENABLED Sep 01 14:33:03 volumio hostapd[1106]: wlan0: AP-ENABLED Sep 01 14:33:03 volumio systemd[1]: Started Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Sep 01 14:33:03 volumio dhcpcd[794]: wlan0: IAID 24:9f:71:be Sep 01 14:33:03 volumio dhcpcd[794]: wlan0: IAID 24:9f:71:be Sep 01 14:33:03 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Sep 01 14:33:03 volumio iwconfig[1126]: Error for wireless request "Set Power Management" (8B2C) : Sep 01 14:33:03 volumio iwconfig[1126]: SET failed on device wlan0 ; Invalid argument. Sep 01 14:33:03 volumio systemd[1]: wireless.service: Succeeded. Sep 01 14:33:03 volumio systemd[1]: Started Wireless Services. Sep 01 14:33:03 volumio systemd[1]: Started Volumio Backend Module. Sep 01 14:33:03 volumio systemd[1]: Started First Start. Sep 01 14:33:03 volumio dnsmasq[1124]: dnsmasq: syntax check OK. Sep 01 14:33:03 volumio dhcpcd[794]: eth0: probing address 192.168.31.203/24 Sep 01 14:33:03 volumio dhcpcd[794]: eth0: probing address 192.168.31.203/24 Sep 01 14:33:03 volumio systemd[1]: Started Intel SST and HDA soundcard init service. Sep 01 14:33:03 volumio systemd[1]: Started Start Volumio Kiosk. Sep 01 14:33:03 volumio firststart.sh[1128]: Volumio first start configuration script Sep 01 14:33:03 volumio firststart.sh[1128]: Configuring unconfigured packages Sep 01 14:33:03 volumio systemd[1]: Started Volumio Cpu Tweaker. Sep 01 14:33:03 volumio volumio-cpu-tweak[1137]: Setting RT Priority for mpd Sep 01 14:33:03 volumio volumio-cpu-tweak[1137]: Setting MPD Affinity Sep 01 14:33:03 volumio volumio-cpu-tweak[1137]: pid 996's current affinity mask: f Sep 01 14:33:03 volumio volumio-cpu-tweak[1137]: pid 996's new affinity mask: 3 Sep 01 14:33:03 volumio volumio-cpu-tweak[1137]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Sep 01 14:33:03 volumio systemd[1]: volumio_cpu_tweak.service: Succeeded. Sep 01 14:33:03 volumio dnsmasq[1181]: started, version 2.80 cachesize 150 Sep 01 14:33:03 volumio dnsmasq[1181]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Sep 01 14:33:03 volumio dnsmasq-dhcp[1181]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Sep 01 14:33:03 volumio dnsmasq[1181]: reading /etc/resolv.conf Sep 01 14:33:03 volumio dnsmasq[1181]: using nameserver 208.67.222.222#53 Sep 01 14:33:03 volumio dnsmasq[1181]: using nameserver 208.67.220.220#53 Sep 01 14:33:03 volumio dnsmasq[1181]: read /etc/hosts - 5 addresses Sep 01 14:33:03 volumio startx[1130]: xauth: file /root/.Xauthority does not exist Sep 01 14:33:03 volumio firststart.sh[1128]: Creating /var/log/samba/cores folder Sep 01 14:33:03 volumio firststart.sh[1128]: Removing default SSH host keys Sep 01 14:33:03 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Sep 01 14:33:03 volumio firststart.sh[1128]: removed '/etc/ssh/ssh_host_ecdsa_key' Sep 01 14:33:03 volumio firststart.sh[1128]: removed '/etc/ssh/ssh_host_ecdsa_key.pub' Sep 01 14:33:03 volumio firststart.sh[1128]: removed '/etc/ssh/ssh_host_ed25519_key' Sep 01 14:33:03 volumio firststart.sh[1128]: removed '/etc/ssh/ssh_host_ed25519_key.pub' Sep 01 14:33:03 volumio firststart.sh[1128]: removed '/etc/ssh/ssh_host_rsa_key' Sep 01 14:33:03 volumio firststart.sh[1128]: removed '/etc/ssh/ssh_host_rsa_key.pub' Sep 01 14:33:03 volumio systemd[1]: Reached target Host and Network Name Lookups. Sep 01 14:33:03 volumio firststart.sh[1128]: Generating SSH host keys Sep 01 14:33:03 volumio startx[1130]: X.Org X Server 1.20.4 Sep 01 14:33:03 volumio startx[1130]: X Protocol Version 11, Revision 0 Sep 01 14:33:03 volumio startx[1130]: Build Operating System: Linux 5.10.0-10-amd64 x86_64 Debian Sep 01 14:33:03 volumio startx[1130]: Current Operating System: Linux volumio 6.6.32-volumio #2 SMP PREEMPT_DYNAMIC Wed May 29 23:04:42 CEST 2024 x86_64 Sep 01 14:33:03 volumio startx[1130]: Kernel command line: BOOT_IMAGE=/vmlinuz initramfs.clear splash plymouth.ignore-serial-consoles quiet loglevel=0 biosdevname=0 imgpart=UUID=0878c9ac-e917-42a0-b697-302005152be7 bootpart=UUID=7804-D6B0 datapart=UUID=aab11ed3-18b0-4d95-aaf3-307e6f397e6c 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 Sep 01 14:33:03 volumio startx[1130]: Build Date: 18 December 2021 09:05:36AM Sep 01 14:33:03 volumio startx[1130]: xorg-server 2:1.20.4-1+deb10u4 (https://www.debian.org/support) Sep 01 14:33:03 volumio startx[1130]: Current version of pixman: 0.36.0 Sep 01 14:33:03 volumio startx[1130]: Before reporting problems, check http://wiki.x.org Sep 01 14:33:03 volumio startx[1130]: to make sure that you have the latest version. Sep 01 14:33:03 volumio startx[1130]: Markers: (--) probed, (**) from config file, (==) default setting, Sep 01 14:33:03 volumio startx[1130]: (++) from command line, (!!) notice, (II) informational, Sep 01 14:33:03 volumio startx[1130]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Sep 01 14:33:03 volumio startx[1130]: (==) Log file: "/var/log/Xorg.0.log", Time: Mon Sep 1 07:33:03 2025 Sep 01 14:33:03 volumio startx[1130]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Sep 01 14:33:04 volumio dhcpcd[794]: wlan0: soliciting a DHCP lease Sep 01 14:33:04 volumio dhcpcd[794]: wlan0: soliciting a DHCP lease Sep 01 14:33:04 volumio startx[1130]: pci id for fd 14: 8086:46d1, driver (null) Sep 01 14:33:04 volumio systemd[1]: soundcard-init.service: Succeeded. Sep 01 14:33:04 volumio dhcpcd[794]: wlan0: soliciting an IPv6 router Sep 01 14:33:04 volumio dhcpcd[794]: wlan0: soliciting an IPv6 router Sep 01 14:33:04 volumio firststart.sh[1128]: debconf: unable to initialize frontend: Dialog Sep 01 14:33:04 volumio firststart.sh[1128]: debconf: (TERM is not set, so the dialog frontend is not usable.) Sep 01 14:33:04 volumio firststart.sh[1128]: debconf: falling back to frontend: Readline Sep 01 14:33:04 volumio firststart.sh[1128]: debconf: unable to initialize frontend: Readline Sep 01 14:33:04 volumio firststart.sh[1128]: debconf: (This frontend requires a controlling tty.) Sep 01 14:33:04 volumio firststart.sh[1128]: debconf: falling back to frontend: Teletype Sep 01 14:33:04 volumio kernel: broken atomic modeset userspace detected, disabling atomic Sep 01 14:33:04 volumio volumio[1127]: info: ------------------------------------------- Sep 01 14:33:04 volumio volumio[1127]: info: ----- Volumio3 ---- Sep 01 14:33:04 volumio volumio[1127]: info: ------------------------------------------- Sep 01 14:33:04 volumio volumio[1127]: info: ----- System startup ---- Sep 01 14:33:04 volumio volumio[1127]: info: ------------------------------------------- Sep 01 14:33:04 volumio firststart.sh[1128]: Creating SSH2 RSA key; this may take some time ... Sep 01 14:33:04 volumio firststart.sh[1128]: 2048 SHA256:KYoy9jwKqvUm/T+m1DNKGLM9cgG9TRV83sxqvB4kvrs root@volumio (RSA) Sep 01 14:33:04 volumio firststart.sh[1128]: Creating SSH2 DSA key; this may take some time ... Sep 01 14:33:04 volumio firststart.sh[1128]: 1024 SHA256:y5BysIzHW924z/MphVTKJ5g8tV04oegZwFsPSVXbIjk root@volumio (DSA) Sep 01 14:33:04 volumio firststart.sh[1128]: Creating SSH2 ECDSA key; this may take some time ... Sep 01 14:33:04 volumio firststart.sh[1128]: 256 SHA256:quqDjvi5M/5LgZMQFoBw0j8Zi/8REybyXHfdOkNFPLs root@volumio (ECDSA) Sep 01 14:33:04 volumio startx[1130]: (II) modeset(0): Initializing kms color map for depth 24, 8 bpc. Sep 01 14:33:04 volumio ntpd[925]: Listen normally on 3 wlan0 192.168.211.1:123 Sep 01 14:33:04 volumio ntpd[925]: new interface(s) found: waking up resolver Sep 01 14:33:04 volumio volumio[1127]: info: File /data/configuration/plugins.json does not exist. Copying from Volumio Sep 01 14:33:04 volumio volumio[1127]: info: MYVOLUMIO Environment detected Sep 01 14:33:04 volumio volumio[1127]: info: Plugin folders cleanup Sep 01 14:33:04 volumio volumio[1127]: info: Scanning into folder /volumio/app/plugins/ Sep 01 14:33:04 volumio volumio[1127]: info: Scanning category audio_interface Sep 01 14:33:04 volumio volumio[1127]: info: Scanning category miscellanea Sep 01 14:33:05 volumio volumio[1127]: info: Scanning category music_service Sep 01 14:33:05 volumio volumio[1127]: info: Scanning category plugins.json Sep 01 14:33:05 volumio volumio[1127]: info: Scanning category system_controller Sep 01 14:33:05 volumio volumio[1127]: info: Scanning category user_interface Sep 01 14:33:05 volumio volumio[1127]: info: Scanning into folder /data/plugins/ Sep 01 14:33:05 volumio volumio[1127]: info: Plugin folders cleanup completed Sep 01 14:33:05 volumio volumio[1127]: info: ------------------------------------------- Sep 01 14:33:05 volumio volumio[1127]: info: ----- Core plugins startup ---- Sep 01 14:33:05 volumio volumio[1127]: info: ------------------------------------------- Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugins from folder /volumio/app/plugins/ Sep 01 14:33:05 volumio volumio[1127]: info: Adding plugin upnp to MyMusic Plugins Sep 01 14:33:05 volumio volumio[1127]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 01 14:33:05 volumio volumio[1127]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugins from folder /data/plugins/ Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "system"... Sep 01 14:33:05 volumio volumio[1127]: info: No id defined. Creating one Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "appearance"... Sep 01 14:33:05 volumio systemd[1]: Reloading. Sep 01 14:33:05 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. Sep 01 14:33:05 volumio systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. Sep 01 14:33:05 volumio systemd[1]: ifup@eth0.service: Current command vanished from the unit file, execution of the command list won't be resumed. Sep 01 14:33:05 volumio firststart.sh[1128]: rescue-ssh.target is a disabled or a static unit, not starting it. Sep 01 14:33:05 volumio firststart.sh[1128]: insserv: warning: current start runlevel(s) (empty) of script `ssh' overrides LSB defaults (2 3 4 5). Sep 01 14:33:05 volumio firststart.sh[1128]: insserv: warning: current stop runlevel(s) (2 3 4 5) of script `ssh' overrides LSB defaults (empty). Sep 01 14:33:05 volumio systemd[1]: Reloading. Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "network"... Sep 01 14:33:05 volumio volumio[1127]: info: Refreshing Cached IP Addresses Sep 01 14:33:05 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. Sep 01 14:33:05 volumio sudo[1531]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 14:33:05 volumio sudo[1531]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:05 volumio sudo[1531]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:05 volumio sudo[1533]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 14:33:05 volumio sudo[1533]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:05 volumio sudo[1533]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "services"... Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "alsa_controller"... Sep 01 14:33:05 volumio sudo[1542]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 01 14:33:05 volumio sudo[1542]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:05 volumio sudo[1542]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:05 volumio volumio[1127]: warn: The ALSA output card is not set, defaulting to card [object Object] Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 01 14:33:05 volumio volumio[1127]: info: Found match in Cards Database: setting mixer for card HDMI Sep 01 14:33:05 volumio volumio[1127]: info: Setting mixer IEC958 for card HDMI Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::volumioUpdateVolumeSettings Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::volumioUpdateVolumeSettings Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::volumioUpdateVolumeSettings Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "wizard"... Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "networkfs"... Sep 01 14:33:05 volumio volumio[1127]: info: Starting Udev Watcher for removable devices Sep 01 14:33:05 volumio volumio[1127]: info: Ignoring mount for partition: boot Sep 01 14:33:05 volumio volumio[1127]: info: Ignoring mount for partition: volumio Sep 01 14:33:05 volumio volumio[1127]: info: Ignoring mount for partition: volumio_data Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "volumio_command_line_client"... Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "upnp"... Sep 01 14:33:05 volumio volumio[1127]: info: [1756711985555] Starting Upmpd Daemon Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "my_music"... Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "mpd"... Sep 01 14:33:05 volumio firststart.sh[1128]: Enabling SSH for first boot Sep 01 14:33:05 volumio systemd[1]: Starting OpenBSD Secure Shell server... Sep 01 14:33:05 volumio sshd[1578]: Server listening on 0.0.0.0 port 22. Sep 01 14:33:05 volumio sshd[1578]: Server listening on :: port 22. Sep 01 14:33:05 volumio systemd[1]: Started OpenBSD Secure Shell server. Sep 01 14:33:05 volumio firststart.sh[1128]: Disabling firststart service Sep 01 14:33:05 volumio firststart.sh[1128]: Removed /etc/systemd/system/multi-user.target.wants/firststart.service. Sep 01 14:33:05 volumio systemd[1]: Reloading. Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "upnp_browser"... Sep 01 14:33:05 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. Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "alarm-clock"... Sep 01 14:33:05 volumio firststart.sh[1128]: Finalizing Sep 01 14:33:05 volumio systemd[1]: firststart.service: Succeeded. Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "airplay_emulation"... Sep 01 14:33:05 volumio volumio[1127]: info: Starting Shairport Sync Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "last_100"... Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "webradio"... Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "i2s_dacs"... Sep 01 14:33:05 volumio volumio[1127]: info: I2S DAC not set, start Auto-detection Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "volumiodiscovery"... Sep 01 14:33:05 volumio volumio[1127]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 14:33:05 volumio node[1127]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 14:33:05 volumio node[1127]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 14:33:05 volumio volumio[1127]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 14:33:05 volumio volumio[1127]: *** WARNING *** For more information see Sep 01 14:33:05 volumio volumio[1127]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 01 14:33:05 volumio volumio[1127]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 14:33:05 volumio volumio[1127]: *** WARNING *** For more information see Sep 01 14:33:05 volumio node[1127]: *** WARNING *** For more information see Sep 01 14:33:05 volumio node[1127]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 01 14:33:05 volumio node[1127]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 14:33:05 volumio node[1127]: *** WARNING *** For more information see Sep 01 14:33:05 volumio volumio[1127]: info: Discovery: Started advertising with name: Volumio Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "outputs"... Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "albumart"... Sep 01 14:33:05 volumio volumio[1127]: info: Plugin example_plugin is not enabled Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "inputs"... Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "updater_comm"... Sep 01 14:33:05 volumio volumio[1127]: Forking 3 albumart workers Sep 01 14:33:05 volumio volumio[1127]: info: Plugin mpdemulation is not enabled Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "rest_api"... Sep 01 14:33:05 volumio volumio[1127]: info: Loading plugin "websocket"... Sep 01 14:33:05 volumio volumio[1127]: info: Starting Socket.io Server version 2.3.0 Sep 01 14:33:05 volumio volumio[1127]: info: Loading i18n strings for locale en Sep 01 14:33:05 volumio volumio[1127]: Updating browse sources language Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::initPlayerControls Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 14:33:05 volumio volumio[1127]: Express server listening on port 3000 Sep 01 14:33:05 volumio volumio[1127]: [Metrics] WebUI: 1s 490.27ms Sep 01 14:33:05 volumio volumio[1127]: info: Setting Device type: x86 Sep 01 14:33:05 volumio volumio[1127]: info: CoreStateMachine::resetVolumioState Sep 01 14:33:05 volumio volumio[1127]: info: CoreStateMachine::getcurrentVolume Sep 01 14:33:05 volumio volumio[1127]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 14:33:06 volumio volumio[1127]: Starting albumart workers Sep 01 14:33:06 volumio volumio[1127]: Starting albumart workers Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: Starting albumart workers Sep 01 14:33:06 volumio volumio[1127]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Sep 01 14:33:06 volumio volumio[1127]: info: Completed loading Core Plugins Sep 01 14:33:06 volumio volumio[1127]: info: Preparing to generate the ALSA configuration file Sep 01 14:33:06 volumio volumio[1127]: info: Cannot read play queue from file Sep 01 14:33:06 volumio volumio[1127]: info: Volumio Network Manager: Network status updated: 0 Sep 01 14:33:06 volumio volumio[1127]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Sep 01 14:33:06 volumio volumio[1127]: wlan0 Interface doesn't support scanning : Operation not supported Sep 01 14:33:06 volumio volumio[1127]: info: Cannot use regular scanning, forcing with ap-force Sep 01 14:33:06 volumio sudo[1626]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Sep 01 14:33:06 volumio sudo[1626]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:06 volumio sudo[1626]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:06 volumio volumio[1127]: command failed: Operation not supported (-95) Sep 01 14:33:06 volumio volumio[1127]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Sep 01 14:33:06 volumio volumio[1127]: command failed: Operation not supported (-95) Sep 01 14:33:06 volumio volumio[1127]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Sep 01 14:33:06 volumio volumio[1127]: Unable to parse: Sep 01 14:33:06 volumio volumio[1127]: Simple mixer control 'IEC958',0 Sep 01 14:33:06 volumio volumio[1127]: Capabilities: pswitch pswitch-joined Sep 01 14:33:06 volumio volumio[1127]: Playback channels: Mono Sep 01 14:33:06 volumio volumio[1127]: Mono: Playback [on] Sep 01 14:33:06 volumio volumio[1127]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Sep 01 14:33:06 volumio volumio[1127]: info: Asound.conf file written Sep 01 14:33:06 volumio sudo[1635]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Sep 01 14:33:06 volumio sudo[1635]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:06 volumio sudo[1635]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:06 volumio volumio[1127]: No state is present for card PCH Sep 01 14:33:06 volumio volumio[1127]: Found hardware: "HDA-Intel" "Intel Alderlake-P HDMI" "HDA:8086281c,80860101,00100000" "0x8086" "0x7270" Sep 01 14:33:06 volumio volumio[1127]: Hardware is initialized using a generic method Sep 01 14:33:06 volumio volumio[1127]: No state is present for card PCH Sep 01 14:33:06 volumio volumio[1127]: No state is present for card AUDIO Sep 01 14:33:06 volumio volumio[1127]: Found hardware: "USB-Audio" "USB Mixer" "USB0746:b000" "" "" Sep 01 14:33:06 volumio volumio[1127]: Hardware is initialized using a generic method Sep 01 14:33:06 volumio volumio[1127]: No state is present for card AUDIO Sep 01 14:33:06 volumio volumio[1127]: No state is present for card HID Sep 01 14:33:06 volumio volumio[1127]: Found hardware: "USB-Audio" "USB Mixer" "USB0573:1573" "" "" Sep 01 14:33:06 volumio volumio[1127]: Hardware is initialized using a generic method Sep 01 14:33:06 volumio volumio[1127]: No state is present for card HID Sep 01 14:33:06 volumio volumio[1127]: info: Output device has changed, restarting MPD Sep 01 14:33:06 volumio sudo[1656]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 14:33:06 volumio sudo[1656]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:06 volumio volumio[1127]: info: Output device has changed, restarting Shairport Sync Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:33:06 volumio sudo[1663]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 14:33:06 volumio sudo[1663]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:06 volumio sudo[1656]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:06 volumio systemd[1]: Stopping Music Player Daemon... Sep 01 14:33:06 volumio volumio[1127]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 14:33:06 volumio volumio[1127]: info: ___________ START PLUGINS ___________ Sep 01 14:33:06 volumio volumio[1127]: info: Setting Hotspot Unique name on first start: Volumio-1ED42 Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getConfigParam] in plugin network Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , saveHotspotSettings Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::Reload Ui Sep 01 14:33:06 volumio volumio[1127]: info: ControllerMpd::onStart: Initializing MPD Sep 01 14:33:06 volumio volumio[1127]: info: Creating MPD Configuration file Sep 01 14:33:06 volumio sudo[1673]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 14:33:06 volumio volumio[1127]: info: [1756711986137] CoreMusicLibrary::Adding element Media Servers Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 14:33:06 volumio sudo[1673]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:06 volumio sudo[1673]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:06 volumio sudo[1675]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 14:33:06 volumio sudo[1675]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:33:06 volumio systemd[1]: mpd.service: Succeeded. Sep 01 14:33:06 volumio systemd[1]: Stopped Music Player Daemon. Sep 01 14:33:06 volumio volumio[1127]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 14:33:06 volumio volumio[1127]: info: [1756711986164] CoreMusicLibrary::Adding element Last_100 Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 14:33:06 volumio volumio[1127]: info: [1756711986165] CoreMusicLibrary::Adding element Webradio Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 14:33:06 volumio volumio[1127]: info: Initializing BBC Radios Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: Volumio Calling Home Sep 01 14:33:06 volumio systemd[1]: Starting Music Player Daemon... Sep 01 14:33:06 volumio sudo[1684]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 01 14:33:06 volumio sudo[1684]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:06 volumio sudo[1684]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:06 volumio volumio[1127]: Unable to parse: Sep 01 14:33:06 volumio volumio[1127]: Simple mixer control 'IEC958',0 Sep 01 14:33:06 volumio volumio[1127]: Capabilities: pswitch pswitch-joined Sep 01 14:33:06 volumio volumio[1127]: Playback channels: Mono Sep 01 14:33:06 volumio volumio[1127]: Mono: Playback [on] Sep 01 14:33:06 volumio volumio[1127]: info: VolumeController:: Volume=undefined Mute =false Sep 01 14:33:06 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:33:06 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:33:06 volumio volumio[1127]: info: CoreStateMachine::updateTrackBlock Sep 01 14:33:06 volumio volumio[1127]: info: CorePlayQueue::getTrackBlock Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 14:33:06 volumio volumio[1127]: info: MPD Permissions set Sep 01 14:33:06 volumio volumio[1127]: info: MPD Permissions set Sep 01 14:33:06 volumio volumio[1127]: Unable to parse: Sep 01 14:33:06 volumio volumio[1127]: Simple mixer control 'IEC958',0 Sep 01 14:33:06 volumio volumio[1127]: Capabilities: pswitch pswitch-joined Sep 01 14:33:06 volumio volumio[1127]: Playback channels: Mono Sep 01 14:33:06 volumio volumio[1127]: Mono: Playback [on] Sep 01 14:33:06 volumio volumio[1127]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Sep 01 14:33:06 volumio volumio[1127]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:06 volumio volumio[1127]: Unable to parse: Sep 01 14:33:06 volumio volumio[1127]: Simple mixer control 'IEC958',0 Sep 01 14:33:06 volumio volumio[1127]: Capabilities: pswitch pswitch-joined Sep 01 14:33:06 volumio volumio[1127]: Playback channels: Mono Sep 01 14:33:06 volumio volumio[1127]: Mono: Playback [on] Sep 01 14:33:06 volumio volumio[1127]: info: VolumeController:: Volume=undefined Mute =false Sep 01 14:33:06 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:33:06 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:33:06 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:33:06 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:33:06 volumio volumio[1127]: info: Starting Shairport Sync Sep 01 14:33:06 volumio volumio[1127]: info: Starting Shairport Sync Sep 01 14:33:06 volumio sudo[1715]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 14:33:06 volumio sudo[1715]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:06 volumio volumio[1127]: info: Starting Shairport Sync Sep 01 14:33:06 volumio sudo[1717]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 14:33:06 volumio sudo[1717]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:06 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 01 14:33:06 volumio systemd[1]: shairport-sync.service: Succeeded. Sep 01 14:33:06 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 01 14:33:06 volumio sudo[1721]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 14:33:06 volumio sudo[1721]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:06 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 01 14:33:06 volumio mpd[1699]: Sep 01 07:33 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 01 14:33:06 volumio sudo[1715]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:06 volumio systemd[1]: Started Music Player Daemon. Sep 01 14:33:06 volumio sudo[1675]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:06 volumio volumio[1127]: info: Shairport-Sync Started Sep 01 14:33:06 volumio sudo[1663]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:06 volumio volumio[1127]: Error adding Membership: Error: addMembership EINVAL Sep 01 14:33:06 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 01 14:33:06 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Sep 01 14:33:06 volumio systemd[1]: shairport-sync.service: Succeeded. Sep 01 14:33:06 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 01 14:33:06 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 01 14:33:06 volumio sudo[1717]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:06 volumio sudo[1721]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:06 volumio volumio[1127]: info: Completed starting Core Plugins Sep 01 14:33:06 volumio volumio[1127]: info: ------------------------------------------- Sep 01 14:33:06 volumio volumio[1127]: info: ----- MyVolumio plugins startup ---- Sep 01 14:33:06 volumio volumio[1127]: info: ------------------------------------------- Sep 01 14:33:06 volumio volumio[1127]: info: [MyVolumio PluginManager] Fetching plans data.... Sep 01 14:33:06 volumio volumio[1127]: info: MPD running with PID1699 Sep 01 14:33:06 volumio volumio[1127]: ,establishing connection Sep 01 14:33:06 volumio volumio[1127]: info: Shairport-Sync Started Sep 01 14:33:06 volumio volumio[1127]: info: Shairport-Sync Started Sep 01 14:33:06 volumio volumio[1127]: error: MPD error: The expression evaluated to a falsy value: Sep 01 14:33:06 volumio volumio[1127]: assert.ok(self.idling) Sep 01 14:33:06 volumio volumio[1127]: error: The expression evaluated to a falsy value: Sep 01 14:33:06 volumio volumio[1127]: assert.ok(self.idling) Sep 01 14:33:06 volumio volumio[1127]: error: MPD error: The expression evaluated to a falsy value: Sep 01 14:33:06 volumio volumio[1127]: assert.ok(self.idling) Sep 01 14:33:06 volumio volumio[1127]: error: The expression evaluated to a falsy value: Sep 01 14:33:06 volumio volumio[1127]: assert.ok(self.idling) Sep 01 14:33:06 volumio volumio[1127]: error: updateQueue error: null Sep 01 14:33:06 volumio volumio[1127]: info: Discovery: adding 3d9a42c9-01c9-41f9-9ac6-b53af82b9fb4 Sep 01 14:33:06 volumio volumio[1127]: info: Discovery: Found device Volumio Sep 01 14:33:06 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:33:06 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:33:06 volumio volumio-time-update[755]: volumio-time-update-util: Fetching time from Volumio... Sep 01 14:33:06 volumio volumio-time-update[755]: volumio-time-update-util: Date not found in response Sep 01 14:33:06 volumio volumio-time-update[755]: volumio-time-update-util: Retrying in 5 seconds... Sep 01 14:33:06 volumio sh[713]: eth0: leased 192.168.31.203 for 43200 seconds Sep 01 14:33:06 volumio dhcpcd[767]: eth0: leased 192.168.31.203 for 43200 seconds Sep 01 14:33:06 volumio sh[713]: eth0: adding route to 192.168.31.0/24 Sep 01 14:33:06 volumio sh[713]: eth0: adding default route via 192.168.31.1 Sep 01 14:33:06 volumio dhcpcd[767]: eth0: adding route to 192.168.31.0/24 Sep 01 14:33:06 volumio dhcpcd[767]: eth0: adding default route via 192.168.31.1 Sep 01 14:33:06 volumio avahi-daemon[800]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.31.203. Sep 01 14:33:06 volumio avahi-daemon[800]: New relevant interface eth0.IPv4 for mDNS. Sep 01 14:33:06 volumio avahi-daemon[800]: Registering new address record for 192.168.31.203 on eth0.IPv4. Sep 01 14:33:06 volumio dnsmasq[1181]: reading /etc/resolv.conf Sep 01 14:33:06 volumio dnsmasq[1181]: using nameserver 192.168.31.1#53 Sep 01 14:33:06 volumio dnsmasq[1181]: using nameserver 208.67.222.222#53 Sep 01 14:33:06 volumio dnsmasq[1181]: using nameserver 208.67.220.220#53 Sep 01 14:33:06 volumio ntpd[925]: ntpd exiting on signal 15 (Terminated) Sep 01 14:33:06 volumio systemd[1]: Stopping Network Time Service... Sep 01 14:33:06 volumio systemd[1]: ntp.service: Succeeded. Sep 01 14:33:06 volumio systemd[1]: Stopped Network Time Service. Sep 01 14:33:06 volumio systemd[1]: Starting Network Time Service... Sep 01 14:33:06 volumio ntpd[1769]: ntpd 4.2.8p12@1.3728-o (1): Starting Sep 01 14:33:06 volumio ntpd[1769]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Sep 01 14:33:06 volumio systemd[1]: Started Network Time Service. Sep 01 14:33:06 volumio ntpd[1775]: proto: precision = 0.043 usec (-24) Sep 01 14:33:06 volumio sh[713]: forked to background, child pid 1776 Sep 01 14:33:06 volumio dhcpcd[767]: forked to background, child pid 1776 Sep 01 14:33:06 volumio ntpd[1775]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Sep 01 14:33:06 volumio ntpd[1775]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Sep 01 14:33:06 volumio ntpd[1775]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 979 days ago Sep 01 14:33:06 volumio ntpd[1775]: Listen and drop on 0 v6wildcard [::]:123 Sep 01 14:33:06 volumio ntpd[1775]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Sep 01 14:33:06 volumio ntpd[1775]: Listen normally on 2 lo 127.0.0.1:123 Sep 01 14:33:06 volumio ntpd[1775]: Listen normally on 3 eth0 192.168.31.203:123 Sep 01 14:33:06 volumio ntpd[1775]: Listen normally on 4 wlan0 192.168.211.1:123 Sep 01 14:33:06 volumio ntpd[1775]: Listening on routing socket on fd #21 for interface updates Sep 01 14:33:06 volumio ntpd[1775]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Sep 01 14:33:06 volumio ntpd[1775]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Sep 01 14:33:06 volumio ifplugd(eth0)[936]: client: ifup: interface eth0 already configured Sep 01 14:33:06 volumio sh[713]: eth0=eth0 Sep 01 14:33:07 volumio ifplugd(eth0)[936]: Program executed successfully. Sep 01 14:33:07 volumio nmbd[903]: [2025/09/01 07:33:07.123988, 0] ../lib/util/become_daemon.c:138(daemon_ready) Sep 01 14:33:07 volumio nmbd[903]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Sep 01 14:33:07 volumio systemd[1]: Started Samba NMB Daemon. Sep 01 14:33:07 volumio sudo[1807]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/hostapd/hostapd.conf Sep 01 14:33:07 volumio sudo[1807]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:07 volumio volumio[1127]: info: Permissions for /etc/hostapd/hostapd.conf Sep 01 14:33:07 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart Sep 01 14:33:07 volumio volumio[1127]: info: Discovery: Restarting Advertising due to device name change Sep 01 14:33:07 volumio sudo[1807]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:07 volumio systemd[1]: Starting Samba Winbind Daemon... Sep 01 14:33:07 volumio sudo[1810]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service Sep 01 14:33:07 volumio sudo[1810]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:07 volumio systemd[1]: Starting Wireless Services... Sep 01 14:33:07 volumio winbindd[1804]: [2025/09/01 07:33:07.213272, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Sep 01 14:33:07 volumio winbindd[1804]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Sep 01 14:33:07 volumio winbindd[1804]: [2025/09/01 07:33:07.220846, 0] ../lib/util/become_daemon.c:138(daemon_ready) Sep 01 14:33:07 volumio systemd[1]: Started Samba Winbind Daemon. Sep 01 14:33:07 volumio winbindd[1804]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Sep 01 14:33:07 volumio wireless.js[1812]: Cleaning previous... Sep 01 14:33:07 volumio systemd[1]: Starting Samba SMB Daemon... Sep 01 14:33:07 volumio systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server... Sep 01 14:33:07 volumio dnsmasq[1181]: exiting on receipt of SIGTERM Sep 01 14:33:07 volumio systemd[1]: dnsmasq.service: Succeeded. Sep 01 14:33:07 volumio systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server. Sep 01 14:33:07 volumio systemd[1]: Stopping Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Sep 01 14:33:07 volumio dhcpcd[794]: wlan0: carrier lost Sep 01 14:33:07 volumio dhcpcd[794]: wlan0: carrier lost Sep 01 14:33:07 volumio smbd[1829]: [2025/09/01 07:33:07.369843, 0] ../lib/util/become_daemon.c:138(daemon_ready) Sep 01 14:33:07 volumio smbd[1829]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Sep 01 14:33:07 volumio systemd[1]: Started Samba SMB Daemon. Sep 01 14:33:07 volumio systemd[1]: hostapd.service: Succeeded. Sep 01 14:33:07 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Sep 01 14:33:07 volumio sudo[1869]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Sep 01 14:33:07 volumio sudo[1869]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:07 volumio avahi-daemon[800]: Withdrawing address record for 192.168.211.1 on wlan0. Sep 01 14:33:07 volumio avahi-daemon[800]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Sep 01 14:33:07 volumio sudo[1869]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:07 volumio avahi-daemon[800]: Interface wlan0.IPv4 no longer relevant for mDNS. Sep 01 14:33:07 volumio volumio[1127]: info: Discovery: A device disappeared from network Sep 01 14:33:07 volumio volumio[1127]: info: Discovery: Device volumio disappeared from network Sep 01 14:33:07 volumio sudo[1871]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Sep 01 14:33:07 volumio sudo[1871]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:07 volumio sudo[1871]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:07 volumio wireless.js[1812]: Stopped aP Sep 01 14:33:07 volumio sudo[1878]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Sep 01 14:33:07 volumio sudo[1878]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:08 volumio ntpd[1775]: Soliciting pool server 223.255.185.2 Sep 01 14:33:08 volumio sudo[1878]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:08 volumio sudo[1880]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Sep 01 14:33:08 volumio sudo[1880]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:08 volumio sudo[1880]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:08 volumio sudo[1887]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Sep 01 14:33:08 volumio sudo[1887]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:08 volumio sudo[1887]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:08 volumio sudo[1889]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Sep 01 14:33:08 volumio sudo[1889]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:08 volumio volumio[1127]: info: Discovery: A device disappeared from network Sep 01 14:33:08 volumio ntpd[1775]: Soliciting pool server 115.165.161.155 Sep 01 14:33:09 volumio dhcpcd[794]: eth0: leased 192.168.31.203 for 43200 seconds Sep 01 14:33:09 volumio dhcpcd[794]: eth0: leased 192.168.31.203 for 43200 seconds Sep 01 14:33:09 volumio dhcpcd[794]: eth0: adding route to 192.168.31.0/24 Sep 01 14:33:09 volumio dhcpcd[794]: eth0: adding default route via 192.168.31.1 Sep 01 14:33:09 volumio dhcpcd[794]: eth0: adding route to 192.168.31.0/24 Sep 01 14:33:09 volumio dhcpcd[794]: eth0: adding default route via 192.168.31.1 Sep 01 14:33:09 volumio ntpd[1775]: ntpd exiting on signal 15 (Terminated) Sep 01 14:33:09 volumio systemd[1]: Stopping Network Time Service... Sep 01 14:33:09 volumio systemd[1]: ntp.service: Succeeded. Sep 01 14:33:09 volumio systemd[1]: Stopped Network Time Service. Sep 01 14:33:09 volumio systemd[1]: Starting Network Time Service... Sep 01 14:33:09 volumio ntpd[1925]: ntpd 4.2.8p12@1.3728-o (1): Starting Sep 01 14:33:09 volumio ntpd[1925]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Sep 01 14:33:09 volumio systemd[1]: Started Network Time Service. Sep 01 14:33:09 volumio ntpd[1931]: proto: precision = 0.043 usec (-24) Sep 01 14:33:09 volumio ntpd[1931]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Sep 01 14:33:09 volumio dhcpcd[794]: forked to background, child pid 1932 Sep 01 14:33:09 volumio dhcpcd[794]: forked to background, child pid 1932 Sep 01 14:33:09 volumio ntpd[1931]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Sep 01 14:33:09 volumio ntpd[1931]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 979 days ago Sep 01 14:33:09 volumio ntpd[1931]: Listen and drop on 0 v6wildcard [::]:123 Sep 01 14:33:09 volumio ntpd[1931]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Sep 01 14:33:09 volumio systemd[1]: Started DHCP Client Daemon. Sep 01 14:33:09 volumio ntpd[1931]: Listen normally on 2 lo 127.0.0.1:123 Sep 01 14:33:09 volumio ntpd[1931]: Listen normally on 3 eth0 192.168.31.203:123 Sep 01 14:33:09 volumio ntpd[1931]: Listening on routing socket on fd #20 for interface updates Sep 01 14:33:09 volumio ntpd[1931]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Sep 01 14:33:09 volumio ntpd[1931]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.127639, 0] ../source3/libsmb/nmblib.c:917(send_udp) Sep 01 14:33:09 volumio nmbd[903]: Packet send failed to 192.168.211.255(137) ERRNO=Network is unreachable Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.127899, 0] ../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Sep 01 14:33:09 volumio nmbd[903]: retransmit_or_expire_response_records: Failed to resend packet id 7592 to IP 192.168.211.255 on subnet 192.168.211.1 Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.127975, 0] ../source3/libsmb/nmblib.c:917(send_udp) Sep 01 14:33:09 volumio nmbd[903]: Packet send failed to 192.168.211.255(137) ERRNO=Network is unreachable Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.128035, 0] ../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Sep 01 14:33:09 volumio nmbd[903]: retransmit_or_expire_response_records: Failed to resend packet id 7593 to IP 192.168.211.255 on subnet 192.168.211.1 Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.128093, 0] ../source3/libsmb/nmblib.c:917(send_udp) Sep 01 14:33:09 volumio nmbd[903]: Packet send failed to 192.168.211.255(137) ERRNO=Network is unreachable Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.128146, 0] ../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Sep 01 14:33:09 volumio nmbd[903]: retransmit_or_expire_response_records: Failed to resend packet id 7594 to IP 192.168.211.255 on subnet 192.168.211.1 Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.128203, 0] ../source3/libsmb/nmblib.c:917(send_udp) Sep 01 14:33:09 volumio nmbd[903]: Packet send failed to 192.168.211.255(137) ERRNO=Network is unreachable Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.128257, 0] ../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Sep 01 14:33:09 volumio nmbd[903]: retransmit_or_expire_response_records: Failed to resend packet id 7595 to IP 192.168.211.255 on subnet 192.168.211.1 Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.128309, 0] ../source3/libsmb/nmblib.c:917(send_udp) Sep 01 14:33:09 volumio nmbd[903]: Packet send failed to 192.168.211.255(137) ERRNO=Network is unreachable Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.128362, 0] ../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Sep 01 14:33:09 volumio nmbd[903]: retransmit_or_expire_response_records: Failed to resend packet id 7596 to IP 192.168.211.255 on subnet 192.168.211.1 Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.128744, 0] ../source3/libsmb/nmblib.c:917(send_udp) Sep 01 14:33:09 volumio nmbd[903]: Packet send failed to 192.168.211.255(137) ERRNO=Network is unreachable Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.128851, 0] ../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Sep 01 14:33:09 volumio nmbd[903]: retransmit_or_expire_response_records: Failed to resend packet id 7592 to IP 192.168.211.255 on subnet 192.168.211.1 Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.128913, 0] ../source3/libsmb/nmblib.c:917(send_udp) Sep 01 14:33:09 volumio nmbd[903]: Packet send failed to 192.168.211.255(137) ERRNO=Network is unreachable Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.128933, 0] ../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Sep 01 14:33:09 volumio nmbd[903]: retransmit_or_expire_response_records: Failed to resend packet id 7593 to IP 192.168.211.255 on subnet 192.168.211.1 Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.128946, 0] ../source3/libsmb/nmblib.c:917(send_udp) Sep 01 14:33:09 volumio nmbd[903]: Packet send failed to 192.168.211.255(137) ERRNO=Network is unreachable Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.128958, 0] ../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Sep 01 14:33:09 volumio nmbd[903]: retransmit_or_expire_response_records: Failed to resend packet id 7594 to IP 192.168.211.255 on subnet 192.168.211.1 Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.128971, 0] ../source3/libsmb/nmblib.c:917(send_udp) Sep 01 14:33:09 volumio nmbd[903]: Packet send failed to 192.168.211.255(137) ERRNO=Network is unreachable Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.128984, 0] ../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Sep 01 14:33:09 volumio nmbd[903]: retransmit_or_expire_response_records: Failed to resend packet id 7595 to IP 192.168.211.255 on subnet 192.168.211.1 Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.128997, 0] ../source3/libsmb/nmblib.c:917(send_udp) Sep 01 14:33:09 volumio nmbd[903]: Packet send failed to 192.168.211.255(137) ERRNO=Network is unreachable Sep 01 14:33:09 volumio nmbd[903]: [2025/09/01 07:33:09.129017, 0] ../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Sep 01 14:33:09 volumio nmbd[903]: retransmit_or_expire_response_records: Failed to resend packet id 7596 to IP 192.168.211.255 on subnet 192.168.211.1 Sep 01 14:33:09 volumio volumio[1127]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Sep 01 14:33:09 volumio volumio[1127]: info: CoreStateMachine::getcurrentVolume Sep 01 14:33:09 volumio volumio[1127]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 14:33:09 volumio volumio[1127]: Unable to parse: Sep 01 14:33:09 volumio volumio[1127]: Simple mixer control 'IEC958',0 Sep 01 14:33:09 volumio volumio[1127]: Capabilities: pswitch pswitch-joined Sep 01 14:33:09 volumio volumio[1127]: Playback channels: Mono Sep 01 14:33:09 volumio volumio[1127]: Mono: Playback [on] Sep 01 14:33:09 volumio volumio[1127]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Sep 01 14:33:09 volumio volumio[1127]: Unable to parse: Sep 01 14:33:09 volumio volumio[1127]: Simple mixer control 'IEC958',0 Sep 01 14:33:09 volumio volumio[1127]: Capabilities: pswitch pswitch-joined Sep 01 14:33:09 volumio volumio[1127]: Playback channels: Mono Sep 01 14:33:09 volumio volumio[1127]: Mono: Playback [on] Sep 01 14:33:09 volumio volumio[1127]: info: VolumeController:: Volume=undefined Mute =false Sep 01 14:33:09 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:33:09 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:33:09 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:33:09 volumio volumio[1127]: info: CoreStateMachine::updateTrackBlock Sep 01 14:33:09 volumio volumio[1127]: info: CorePlayQueue::getTrackBlock Sep 01 14:33:09 volumio volumio[1127]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 14:33:09 volumio volumio[1127]: Unable to parse: Sep 01 14:33:09 volumio volumio[1127]: Simple mixer control 'IEC958',0 Sep 01 14:33:09 volumio volumio[1127]: Capabilities: pswitch pswitch-joined Sep 01 14:33:09 volumio volumio[1127]: Playback channels: Mono Sep 01 14:33:09 volumio volumio[1127]: Mono: Playback [on] Sep 01 14:33:09 volumio volumio[1127]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Sep 01 14:33:09 volumio volumio[1127]: Unable to parse: Sep 01 14:33:09 volumio volumio[1127]: Simple mixer control 'IEC958',0 Sep 01 14:33:09 volumio volumio[1127]: Capabilities: pswitch pswitch-joined Sep 01 14:33:09 volumio volumio[1127]: Playback channels: Mono Sep 01 14:33:09 volumio volumio[1127]: Mono: Playback [on] Sep 01 14:33:09 volumio volumio[1127]: info: VolumeController:: Volume=undefined Mute =false Sep 01 14:33:09 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:33:09 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:33:09 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:33:09 volumio volumio-remote-updater[781]: [2025-09-01 07:33:09] [connect] Successful connection Sep 01 14:33:09 volumio volumio-remote-updater[781]: [2025-09-01 07:33:09] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1756711989 101 Sep 01 14:33:09 volumio volumio[1127]: 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: 2 Sep 01 14:33:10 volumio ntpd[1931]: Soliciting pool server 47.243.51.23 Sep 01 14:33:10 volumio sudo[1889]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:10 volumio sudo[1941]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Sep 01 14:33:10 volumio sudo[1941]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:10 volumio sudo[1941]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:10 volumio sudo[1943]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Sep 01 14:33:10 volumio sudo[1943]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:10 volumio sudo[1943]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:11 volumio avahi-daemon[800]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Sep 01 14:33:11 volumio avahi-daemon[800]: New relevant interface wlan0.IPv4 for mDNS. Sep 01 14:33:11 volumio avahi-daemon[800]: Registering new address record for 192.168.211.1 on wlan0.IPv4. Sep 01 14:33:11 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Sep 01 14:33:11 volumio hostapd[1949]: Configuration file: /etc/hostapd/hostapd.conf Sep 01 14:33:11 volumio hostapd[1949]: Using interface wlan0 with hwaddr c0:4b:24:9f:71:be and ssid "Volumio-1ED42" Sep 01 14:33:11 volumio ntpd[1931]: Soliciting pool server 115.165.161.155 Sep 01 14:33:11 volumio volumio[1127]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Sep 01 14:33:11 volumio dhcpcd[1932]: wlan0: carrier acquired Sep 01 14:33:11 volumio hostapd[1949]: wlan0: interface state UNINITIALIZED->ENABLED Sep 01 14:33:11 volumio hostapd[1949]: wlan0: AP-ENABLED Sep 01 14:33:11 volumio systemd[1]: Started Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Sep 01 14:33:11 volumio dhcpcd[1932]: wlan0: IAID 24:9f:71:be Sep 01 14:33:11 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Sep 01 14:33:11 volumio dnsmasq[1952]: dnsmasq: syntax check OK. Sep 01 14:33:11 volumio iwconfig[1954]: Error for wireless request "Set Power Management" (8B2C) : Sep 01 14:33:11 volumio iwconfig[1954]: SET failed on device wlan0 ; Invalid argument. Sep 01 14:33:11 volumio systemd[1]: wireless.service: Succeeded. Sep 01 14:33:11 volumio systemd[1]: Started Wireless Services. Sep 01 14:33:11 volumio sudo[1810]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:11 volumio dnsmasq[1960]: started, version 2.80 cachesize 150 Sep 01 14:33:11 volumio dnsmasq[1960]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Sep 01 14:33:11 volumio dnsmasq-dhcp[1960]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Sep 01 14:33:11 volumio dnsmasq[1960]: reading /etc/resolv.conf Sep 01 14:33:11 volumio dnsmasq[1960]: using nameserver 192.168.31.1#53 Sep 01 14:33:11 volumio dnsmasq[1960]: using nameserver 208.67.222.222#53 Sep 01 14:33:11 volumio dnsmasq[1960]: using nameserver 208.67.220.220#53 Sep 01 14:33:11 volumio dnsmasq[1960]: read /etc/hosts - 5 addresses Sep 01 14:33:11 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Sep 01 14:33:11 volumio volumio-time-update[755]: volumio-time-update-util: Fetching time from Volumio... Sep 01 14:33:11 volumio volumio[1127]: info: Discovery: Browse raised the following error Error: dns service error: unknown Sep 01 14:33:11 volumio dhcpcd[1932]: wlan0: soliciting an IPv6 router Sep 01 14:33:12 volumio ntpd[1931]: Soliciting pool server 17.253.84.253 Sep 01 14:33:12 volumio volumio[1127]: info: Discovery: Started advertising with name: Volumio Sep 01 14:33:12 volumio volumio-time-update[755]: volumio-time-update-util: Setting system time to: 2025-09-01 07:33:12 Sep 01 14:33:12 volumio sudo[1972]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-09-01 07:33:12 Sep 01 14:33:12 volumio sudo[1972]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:12 volumio dbus-daemon[783]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.15' (uid=0 pid=1973 comm="timedatectl set-time 2025-09-01 07:33:12 ") Sep 01 14:33:12 volumio dhcpcd[1932]: wlan0: soliciting a DHCP lease Sep 01 14:33:12 volumio systemd[1]: Starting Time & Date Service... Sep 01 14:33:12 volumio dbus-daemon[783]: [system] Successfully activated service 'org.freedesktop.timedate1' Sep 01 14:33:12 volumio systemd[1]: Started Time & Date Service. Sep 01 14:33:12 volumio systemd-timedated[1974]: Changed local time to Mon Sep 1 07:33:12 2025 Sep 01 14:33:12 volumio sudo[1972]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:12 volumio volumio-time-update[755]: volumio-time-update-util: System time updated successfully. Sep 01 14:33:12 volumio systemd[1]: Started Volumio Time Update Utility. Sep 01 14:33:12 volumio systemd[1]: Reached target Multi-User System. Sep 01 14:33:12 volumio systemd[1]: Reached target Graphical Interface. Sep 01 14:33:12 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Sep 01 14:33:12 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Sep 01 14:33:12 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Sep 01 14:33:12 volumio systemd[1]: Startup finished in 6.397s (firmware) + 643ms (loader) + 5.251s (kernel) + 16.890s (userspace) = 29.183s. Sep 01 14:33:12 volumio ntpd[1931]: Listen normally on 4 wlan0 192.168.211.1:123 Sep 01 14:33:12 volumio ntpd[1931]: new interface(s) found: waking up resolver Sep 01 14:33:12 volumio ntpd[1931]: Soliciting pool server 8.217.190.48 Sep 01 14:33:13 volumio volumio[1127]: info: Discovery: adding 3d9a42c9-01c9-41f9-9ac6-b53af82b9fb4 Sep 01 14:33:13 volumio volumio[1127]: info: Discovery: Found device Volumio Sep 01 14:33:13 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:33:13 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:33:13 volumio volumio[1127]: info: Discovery: this is already registered, 3d9a42c9-01c9-41f9-9ac6-b53af82b9fb4 Sep 01 14:33:13 volumio volumio[1127]: info: Discovery: Found device Volumio Sep 01 14:33:13 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:33:13 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Sep 01 14:33:14 volumio volumio[1127]: info: Adding plugin bluetooth to MyMusic Plugins Sep 01 14:33:14 volumio volumio[1127]: info: Adding plugin multiroom to MyMusic Plugins Sep 01 14:33:14 volumio volumio[1127]: info: Adding plugin metavolumio to MyMusic Plugins Sep 01 14:33:14 volumio volumio[1127]: info: Adding plugin cd_controller to MyMusic Plugins Sep 01 14:33:14 volumio volumio[1127]: info: Adding plugin qobuzconnect to MyMusic Plugins Sep 01 14:33:14 volumio volumio[1127]: info: Adding plugin smart_inputs to MyMusic Plugins Sep 01 14:33:14 volumio volumio[1127]: info: Adding plugin tidalconnect to MyMusic Plugins Sep 01 14:33:14 volumio volumio[1127]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Sep 01 14:33:15 volumio volumio[1127]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Sep 01 14:33:15 volumio volumio[1127]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Sep 01 14:33:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:33:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:33:15 volumio volumio[1127]: info: Starting MyVolumio Remote Streaming Endpoints Sep 01 14:33:15 volumio volumio[1127]: info: MyVolumio not started Sep 01 14:33:15 volumio volumio[1127]: info: Initializing device activation check Sep 01 14:33:15 volumio volumio[1127]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Sep 01 14:33:15 volumio volumio[1127]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Sep 01 14:33:15 volumio volumio[1127]: info: Starting Streaming Service Transparent Proxy Sep 01 14:33:15 volumio volumio[1127]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Sep 01 14:33:15 volumio volumio[1127]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Sep 01 14:33:15 volumio volumio[1127]: info: Streaming services startup Sep 01 14:33:15 volumio volumio[1127]: info: Starting Streaming Daemon Sep 01 14:33:15 volumio sudo[2000]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 14:33:15 volumio sudo[2000]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:15 volumio sudo[2000]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:15 volumio volumio[1127]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Sep 01 14:33:15 volumio sudo[2008]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 14:33:15 volumio sudo[2008]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:15 volumio sudo[2008]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:15 volumio sudo[2011]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 14:33:15 volumio sudo[2011]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:15 volumio volumio[1127]: info: Volumio Network Manager: Network status updated: 1 Sep 01 14:33:15 volumio sudo[2011]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:15 volumio volumio[1127]: error: Cannot start Volumio Streaming Daemon Sep 01 14:33:15 volumio volumio[1127]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 14:33:15 volumio volumio[1127]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 14:33:15 volumio sudo[2014]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Sep 01 14:33:15 volumio sudo[2014]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:15 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Sep 01 14:33:15 volumio sudo[2014]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:15 volumio volumio[1127]: info: Upmpdcli Daemon Started Sep 01 14:33:15 volumio volumio[2016]: Generating RSA private key, 4096 bit long modulus (2 primes) Sep 01 14:33:15 volumio volumio[1127]: STREAMING PROXY: Starting server on port 3245 Sep 01 14:33:15 volumio volumio[1127]: Node JS runtime: 14 Sep 01 14:33:15 volumio volumio[2016]: ..............................................................++++ Sep 01 14:33:15 volumio volumio[1127]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=3.832&uuid=1ed4240fdd24eb545b39cccfed9b04ac" http://updates.volumio.org/downloader-v1/track-device Sep 01 14:33:15 volumio volumio[1127]: % Total % Received % Xferd Average Speed Time Time Time Current Sep 01 14:33:15 volumio volumio[1127]: Dload Upload Total Spent Left Speed Sep 01 14:33:15 volumio volumio[1127]: [132B blob data] Sep 01 14:33:15 volumio volumio[1127]: retrying in 5 seconds, trial 0 Sep 01 14:33:15 volumio volumio[1127]: info: Volumio Calling Home Sep 01 14:33:16 volumio volumio[2016]: .....................................++++ Sep 01 14:33:16 volumio volumio[2016]: e is 65537 (0x010001) Sep 01 14:33:16 volumio volumio[2016]: writing RSA key Sep 01 14:33:16 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: wizard , reportWirelessConnection Sep 01 14:33:16 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessInfo Sep 01 14:33:16 volumio sudo[2065]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 14:33:16 volumio sudo[2065]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:16 volumio sudo[2065]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:16 volumio volumio[1127]: info: Volumio called home Sep 01 14:33:16 volumio dhcpcd[1932]: wlan0: probing for an IPv4LL address Sep 01 14:33:21 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart Sep 01 14:33:21 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , onNetworkingRestart Sep 01 14:33:21 volumio volumio[1127]: info: Refreshing Cached IP Addresses Sep 01 14:33:21 volumio sudo[2111]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli Sep 01 14:33:21 volumio sudo[2111]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:21 volumio sudo[2111]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:21 volumio sudo[2114]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 14:33:21 volumio sudo[2114]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:21 volumio sudo[2114]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:21 volumio sudo[2117]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 14:33:21 volumio sudo[2117]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:21 volumio systemd[1]: upmpdcli.service: Succeeded. Sep 01 14:33:21 volumio sudo[2117]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:21 volumio dhcpcd[1932]: wlan0: using IPv4LL address 169.254.40.147 Sep 01 14:33:21 volumio avahi-daemon[800]: Registering new address record for 169.254.40.147 on wlan0.IPv4. Sep 01 14:33:21 volumio dhcpcd[1932]: wlan0: adding route to 169.254.0.0/16 Sep 01 14:33:22 volumio volumio[1127]: 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: 3 Sep 01 14:33:22 volumio volumio[1127]: info: CoreCommandRouter::volumioGetVisibleSources Sep 01 14:33:22 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 14:33:22 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: wizard , getWizardSteps Sep 01 14:33:22 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , showActivationCode Sep 01 14:33:22 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Sep 01 14:33:22 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Sep 01 14:33:22 volumio volumio[1127]: info: Received Get System Info Sep 01 14:33:22 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 14:33:22 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 14:33:22 volumio volumio[1127]: info: Discovery: Getting this device information Sep 01 14:33:22 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:33:22 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:33:22 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 14:33:22 volumio volumio-remote-updater[781]: No test mode Sep 01 14:33:22 volumio volumio-remote-updater[781]: No alpha test mode Sep 01 14:33:22 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 01 14:33:22 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 14:33:22 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:22 volumio volumio[1127]: info: Retrieving Cloud Streaming UI Sep 01 14:33:22 volumio volumio[1127]: info: Getting Tidal Cloud Configuration Sep 01 14:33:22 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:22 volumio volumio[1127]: info: Getting Qobuz Cloud Configuration Sep 01 14:33:22 volumio volumio[1127]: info: Asking plugin for UI Config Sep 01 14:33:22 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:22 volumio volumio[1127]: info: Getting Spotify Cloud Configuration Sep 01 14:33:22 volumio volumio[1127]: info: Asking plugin for UI Config Sep 01 14:33:22 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:22 volumio volumio[1127]: info: Saving Spotify Acccount Sep 01 14:33:22 volumio volumio[1127]: info: Got Tidal Cloud Configuration Sep 01 14:33:22 volumio volumio[1127]: info: Got it Sep 01 14:33:22 volumio volumio[1127]: info: Got it Sep 01 14:33:22 volumio volumio[1127]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Sep 01 14:33:22 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:22 volumio volumio[1127]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Sep 01 14:33:22 volumio volumio[1127]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Sep 01 14:33:22 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Sep 01 14:33:23 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Sep 01 14:33:23 volumio volumio[1127]: info: Loading i18n strings for locale en Sep 01 14:33:23 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Sep 01 14:33:23 volumio volumio[1127]: info: Setting timezone to UTC Sep 01 14:33:23 volumio sudo[2234]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Sep 01 14:33:23 volumio sudo[2234]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:23 volumio sudo[2234]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:23 volumio sudo[2237]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/UTC /etc/localtime Sep 01 14:33:23 volumio sudo[2237]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:23 volumio sudo[2237]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:23 volumio sudo[2240]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Sep 01 14:33:23 volumio sudo[2240]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:23 volumio sudo[2240]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:23 volumio sudo[2243]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone UTC Sep 01 14:33:23 volumio sudo[2243]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:23 volumio systemd-timedated[1974]: Failed to set time zone: Permission denied Sep 01 14:33:23 volumio sudo[2243]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:23 volumio volumio[1127]: Failed to set time zone: Access denied Sep 01 14:33:23 volumio volumio[1127]: info: Could not set timezone, retrying Sep 01 14:33:23 volumio volumio[1127]: Updating browse sources language Sep 01 14:33:23 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 14:33:23 volumio ntpd[1931]: Listen normally on 5 wlan0 169.254.40.147:123 Sep 01 14:33:23 volumio ntpd[1931]: new interface(s) found: waking up resolver Sep 01 14:33:24 volumio volumio[1127]: info: Fetching Streaming Services browse cache Sep 01 14:33:24 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 14:33:24 volumio sudo[2417]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone UTC Sep 01 14:33:24 volumio sudo[2417]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:24 volumio sudo[2417]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:26 volumio systemd[1]: systemd-fsckd.service: Succeeded. Sep 01 14:33:26 volumio systemd[1]: systemd-hostnamed.service: Succeeded. Sep 01 14:33:30 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 14:33:30 volumio volumio[1127]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Sep 01 14:33:30 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:33:30 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:33:31 volumio sudo[2437]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 14:33:31 volumio sudo[2437]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:31 volumio sudo[2437]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:31 volumio sudo[2440]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 14:33:31 volumio sudo[2440]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:31 volumio sudo[2440]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:31 volumio sudo[2443]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Sep 01 14:33:31 volumio sudo[2443]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:31 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Sep 01 14:33:31 volumio sudo[2443]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:31 volumio volumio[1127]: info: Upmpdcli Daemon Started Sep 01 14:33:31 volumio volumio[2445]: writing RSA key Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::volumioGetBrowseSources Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 14:33:35 volumio volumio[1127]: error: MyVolumio Plugin failed to authenticate in a timely fashion Sep 01 14:33:35 volumio volumio[1127]: info: Completed starting MyVolumio Plugin Sep 01 14:33:35 volumio volumio[1127]: [Metrics] CommandRouter: 30s 970.94ms Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::volumiosetStartupVolume Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::Close All Modals sent Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::Close All Modals sent Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:35 volumio volumio[1127]: info: Retrieving Cloud Streaming UI Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:35 volumio volumio[1127]: info: Retrieving Cloud Streaming UI Sep 01 14:33:35 volumio volumio[1127]: info: Getting Tidal Cloud Configuration Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:35 volumio volumio[1127]: info: Getting Qobuz Cloud Configuration Sep 01 14:33:35 volumio volumio[1127]: info: Asking plugin for UI Config Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:35 volumio volumio[1127]: info: Getting Spotify Cloud Configuration Sep 01 14:33:35 volumio volumio[1127]: info: Asking plugin for UI Config Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:35 volumio volumio[1127]: info: Saving Spotify Acccount Sep 01 14:33:35 volumio volumio[1127]: info: Got Tidal Cloud Configuration Sep 01 14:33:35 volumio volumio[1127]: info: Got it Sep 01 14:33:35 volumio volumio[1127]: info: Got it Sep 01 14:33:35 volumio volumio[1127]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Sep 01 14:33:35 volumio volumio[1127]: info: Getting Tidal Cloud Configuration Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:35 volumio volumio[1127]: info: Getting Qobuz Cloud Configuration Sep 01 14:33:35 volumio volumio[1127]: info: Asking plugin for UI Config Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:35 volumio volumio[1127]: info: Getting Spotify Cloud Configuration Sep 01 14:33:35 volumio volumio[1127]: info: Asking plugin for UI Config Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:35 volumio volumio[1127]: info: Saving Spotify Acccount Sep 01 14:33:35 volumio volumio[1127]: info: Got Tidal Cloud Configuration Sep 01 14:33:35 volumio volumio[1127]: info: Got it Sep 01 14:33:35 volumio volumio[1127]: info: Got it Sep 01 14:33:35 volumio volumio[1127]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:35 volumio volumio[1127]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:35 volumio volumio[1127]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:33:35 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 01 14:33:36 volumio volumio-remote-updater[781]: No test mode Sep 01 14:33:36 volumio volumio-remote-updater[781]: No alpha test mode Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Sep 01 14:33:36 volumio volumio[1127]: info: Version has changed, forcing UI Reload Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::Reload Ui Sep 01 14:33:36 volumio volumio[1127]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Sep 01 14:33:36 volumio volumio[1127]: 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: 4 Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::volumioGetVisibleSources Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: wizard , getWizardSteps Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , showActivationCode Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Sep 01 14:33:36 volumio volumio[1127]: info: Received Get System Info Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 14:33:36 volumio volumio[1127]: info: Discovery: Getting this device information Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:33:36 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 14:33:36 volumio volumio-remote-updater[781]: No test mode Sep 01 14:33:36 volumio volumio-remote-updater[781]: No alpha test mode Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:36 volumio volumio[1127]: info: Retrieving Cloud Streaming UI Sep 01 14:33:36 volumio volumio[1127]: info: Getting Tidal Cloud Configuration Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:36 volumio volumio[1127]: info: Getting Qobuz Cloud Configuration Sep 01 14:33:36 volumio volumio[1127]: info: Asking plugin for UI Config Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:36 volumio volumio[1127]: info: Getting Spotify Cloud Configuration Sep 01 14:33:36 volumio volumio[1127]: info: Asking plugin for UI Config Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:36 volumio volumio[1127]: info: Saving Spotify Acccount Sep 01 14:33:36 volumio volumio[1127]: info: Got Tidal Cloud Configuration Sep 01 14:33:36 volumio volumio[1127]: info: Got it Sep 01 14:33:36 volumio volumio[1127]: info: Got it Sep 01 14:33:36 volumio volumio[1127]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Sep 01 14:33:36 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:36 volumio volumio[1127]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Sep 01 14:33:37 volumio volumio[1127]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Sep 01 14:33:37 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Sep 01 14:33:37 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Sep 01 14:33:37 volumio volumio[1127]: info: Loading i18n strings for locale en Sep 01 14:33:37 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Sep 01 14:33:37 volumio volumio[1127]: info: Setting timezone to UTC Sep 01 14:33:37 volumio sudo[2511]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Sep 01 14:33:37 volumio sudo[2511]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:37 volumio sudo[2511]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:37 volumio sudo[2514]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/UTC /etc/localtime Sep 01 14:33:37 volumio sudo[2514]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:37 volumio sudo[2514]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:37 volumio sudo[2517]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Sep 01 14:33:37 volumio sudo[2517]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:37 volumio sudo[2517]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:37 volumio sudo[2520]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone UTC Sep 01 14:33:37 volumio sudo[2520]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:37 volumio sudo[2520]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:37 volumio volumio[1127]: Updating browse sources language Sep 01 14:33:37 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 14:33:38 volumio volumio[1127]: info: Fetching Streaming Services browse cache Sep 01 14:33:38 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 14:33:42 volumio volumio[1127]: info: BOOT COMPLETED Sep 01 14:33:53 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Sep 01 14:33:53 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 01 14:33:53 volumio volumio-remote-updater[781]: No test mode Sep 01 14:33:53 volumio volumio-remote-updater[781]: No alpha test mode Sep 01 14:33:53 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Sep 01 14:33:54 volumio volumio[1127]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Sep 01 14:33:54 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Sep 01 14:33:54 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 14:33:54 volumio volumio[1127]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Sep 01 14:33:54 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Sep 01 14:33:54 volumio volumio[1127]: info: Received Get System Version Sep 01 14:33:54 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 14:33:54 volumio volumio[1127]: info: Received Get System Info Sep 01 14:33:54 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 14:33:54 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 14:33:54 volumio volumio[1127]: info: Discovery: Getting this device information Sep 01 14:33:54 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:33:54 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:33:54 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 14:33:58 volumio sudo[2602]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 14:33:58 volumio sudo[2602]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:58 volumio sudo[2602]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:58 volumio sudo[2605]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 14:33:58 volumio sudo[2605]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:58 volumio sudo[2605]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:58 volumio volumio[1127]: verbose: New Socket.io Connection to 192.168.31.203 from 192.168.31.196 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/139.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Sep 01 14:33:58 volumio volumio[1127]: info: CoreCommandRouter::volumioGetVisibleSources Sep 01 14:33:58 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 14:33:58 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: wizard , getWizardSteps Sep 01 14:33:58 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , showActivationCode Sep 01 14:33:58 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Sep 01 14:33:58 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Sep 01 14:33:58 volumio volumio[1127]: info: Received Get System Info Sep 01 14:33:58 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 14:33:58 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 14:33:58 volumio volumio[1127]: info: Discovery: Getting this device information Sep 01 14:33:58 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:33:58 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:33:58 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 14:33:58 volumio volumio-remote-updater[781]: No test mode Sep 01 14:33:58 volumio volumio-remote-updater[781]: No alpha test mode Sep 01 14:33:58 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 01 14:33:58 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 14:33:58 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:58 volumio volumio[1127]: info: Retrieving Cloud Streaming UI Sep 01 14:33:58 volumio volumio[1127]: info: Getting Tidal Cloud Configuration Sep 01 14:33:58 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:58 volumio volumio[1127]: info: Getting Qobuz Cloud Configuration Sep 01 14:33:58 volumio volumio[1127]: info: Asking plugin for UI Config Sep 01 14:33:58 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:58 volumio volumio[1127]: info: Getting Spotify Cloud Configuration Sep 01 14:33:58 volumio volumio[1127]: info: Asking plugin for UI Config Sep 01 14:33:58 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:58 volumio volumio[1127]: info: Saving Spotify Acccount Sep 01 14:33:58 volumio volumio[1127]: info: Got Tidal Cloud Configuration Sep 01 14:33:58 volumio volumio[1127]: info: Got it Sep 01 14:33:58 volumio volumio[1127]: info: Got it Sep 01 14:33:58 volumio volumio[1127]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Sep 01 14:33:58 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:33:58 volumio volumio[1127]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Sep 01 14:33:59 volumio volumio[1127]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Sep 01 14:33:59 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Sep 01 14:33:59 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Sep 01 14:33:59 volumio volumio[1127]: info: Loading i18n strings for locale vi Sep 01 14:33:59 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Sep 01 14:33:59 volumio volumio[1127]: info: Setting timezone to Asia/Saigon Sep 01 14:33:59 volumio sudo[2612]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Sep 01 14:33:59 volumio sudo[2612]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:59 volumio sudo[2612]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:59 volumio sudo[2615]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Asia/Saigon /etc/localtime Sep 01 14:33:59 volumio sudo[2615]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:59 volumio sudo[2615]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:59 volumio sudo[2618]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Sep 01 14:33:59 volumio sudo[2618]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:59 volumio sudo[2618]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:59 volumio sudo[2621]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Asia/Saigon Sep 01 14:33:59 volumio sudo[2621]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:33:59 volumio systemd-timedated[1974]: Failed to set time zone: Permission denied Sep 01 14:33:59 volumio sudo[2621]: pam_unix(sudo:session): session closed for user root Sep 01 14:33:59 volumio volumio[1127]: Failed to set time zone: Access denied Sep 01 14:33:59 volumio volumio[1127]: info: Could not set timezone, retrying Sep 01 14:33:59 volumio volumio[1127]: Updating browse sources language Sep 01 14:33:59 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 14:34:00 volumio volumio[1127]: info: Fetching Streaming Services browse cache Sep 01 14:34:00 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 14:34:00 volumio sudo[2624]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Asia/Saigon Sep 01 14:34:00 volumio sudo[2624]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:00 volumio sudo[2624]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:02 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Sep 01 14:34:02 volumio volumio[1127]: info: Loading i18n strings for locale vi Sep 01 14:34:02 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Sep 01 14:34:02 volumio volumio[1127]: info: Setting timezone to Asia/Saigon Sep 01 14:34:02 volumio sudo[2627]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Sep 01 14:34:02 volumio sudo[2627]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:02 volumio sudo[2627]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:02 volumio sudo[2630]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Asia/Saigon /etc/localtime Sep 01 14:34:02 volumio sudo[2630]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:02 volumio sudo[2630]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:02 volumio sudo[2633]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Sep 01 14:34:02 volumio sudo[2633]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:02 volumio sudo[2633]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:02 volumio sudo[2636]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Asia/Saigon Sep 01 14:34:02 volumio sudo[2636]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:02 volumio sudo[2636]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:02 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Sep 01 14:34:02 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Sep 01 14:34:02 volumio sudo[2639]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 01 14:34:02 volumio sudo[2639]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:02 volumio sudo[2639]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:02 volumio volumio[1127]: Updating browse sources language Sep 01 14:34:02 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 14:34:02 volumio volumio[1127]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Sep 01 14:34:02 volumio volumio[1127]: wlan0 Interface doesn't support scanning : Operation not supported Sep 01 14:34:02 volumio volumio[1127]: info: Cannot use regular scanning, forcing with ap-force Sep 01 14:34:02 volumio sudo[2642]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Sep 01 14:34:02 volumio sudo[2642]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:02 volumio sudo[2642]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:02 volumio volumio[1127]: command failed: Operation not supported (-95) Sep 01 14:34:02 volumio volumio[1127]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Sep 01 14:34:02 volumio volumio[1127]: command failed: Operation not supported (-95) Sep 01 14:34:02 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 14:34:02 volumio volumio[1127]: info: Fetching Streaming Services browse cache Sep 01 14:34:03 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Sep 01 14:34:03 volumio volumio[1127]: info: MyVolumio login type: Token Sep 01 14:34:04 volumio volumio[1127]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Sep 01 14:34:05 volumio volumio[1127]: info: MyVolumio token set successfully Sep 01 14:34:05 volumio volumio[1127]: info: MYVOLUMIO: Adding device Sep 01 14:34:05 volumio volumio[1127]: info: MYVOLUMIO: Evaluating Server Sep 01 14:34:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , saveGeneralSettings Sep 01 14:34:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAudioDevices Sep 01 14:34:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Sep 01 14:34:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:34:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 01 14:34:05 volumio volumio[1127]: info: MyVolumio status changed Sep 01 14:34:05 volumio volumio[1127]: info: Streaming services startup Sep 01 14:34:05 volumio volumio[1127]: info: Starting Streaming Daemon Sep 01 14:34:05 volumio volumio[1127]: info: Removing browser output: myVolumio user plan is not superstar Sep 01 14:34:05 volumio volumio[1127]: info: Removing audio output: Sep 01 14:34:05 volumio volumio[1127]: info: Stoppping Tunnel 1 Sep 01 14:34:05 volumio sudo[2678]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 14:34:05 volumio sudo[2678]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:05 volumio sudo[2678]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:05 volumio volumio[1127]: error: Cannot start Volumio Streaming Daemon Sep 01 14:34:05 volumio volumio[1127]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 14:34:05 volumio volumio[1127]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 14:34:05 volumio sudo[2681]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Sep 01 14:34:05 volumio sudo[2681]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:05 volumio sudo[2681]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:05 volumio volumio[1127]: info: Remote SSH Stopped Sep 01 14:34:05 volumio volumio[1127]: info: Setting Geolocation for MyVolumio to as1 Sep 01 14:34:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:34:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:34:05 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:34:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 14:34:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 14:34:06 volumio volumio[1127]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Sep 01 14:34:06 volumio volumio[1127]: info: Updating MyVolumio device info Sep 01 14:34:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:34:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:34:06 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:34:07 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 14:34:07 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Sep 01 14:34:07 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 01 14:34:07 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Sep 01 14:34:07 volumio volumio[1127]: info: Preparing to save Alsa Options, stopping services first Sep 01 14:34:07 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:07 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:07 volumio volumio[1127]: info: CoreCommandRouter::volumioPause Sep 01 14:34:07 volumio volumio[1127]: info: CoreStateMachine::pause Sep 01 14:34:07 volumio volumio[1127]: info: Saving Audio Output to: {"i2s":false,"output_device":{"value":"1","label":"PIONEER N-70AE N-50AE USB AUDIO"},"disallowPush":true} Sep 01 14:34:07 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 01 14:34:07 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 01 14:34:07 volumio volumio[1127]: info: Setting mixer PCM for card PIONEER N-70AE N-50AE USB AUDIO Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::volumioUpdateVolumeSettings Sep 01 14:34:08 volumio volumio[1127]: info: Updating Volume Controller Parameters: Device: 1 Name: PIONEER N-70AE N-50AE USB AUDIO Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Sep 01 14:34:08 volumio volumio[1127]: info: Disabling external Volume Control Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:34:08 volumio volumio[1127]: info: Preparing to generate the ALSA configuration file Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Sep 01 14:34:08 volumio sudo[2694]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 01 14:34:08 volumio sudo[2694]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:08 volumio sudo[2694]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:08 volumio volumio[1127]: Unable to parse: Sep 01 14:34:08 volumio volumio[1127]: Simple mixer control 'PCM',0 Sep 01 14:34:08 volumio volumio[1127]: Capabilities: pswitch pswitch-joined Sep 01 14:34:08 volumio volumio[1127]: Playback channels: Mono Sep 01 14:34:08 volumio volumio[1127]: Mono: Playback [on] Sep 01 14:34:08 volumio volumio[1127]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Sep 01 14:34:08 volumio sudo[2697]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 01 14:34:08 volumio sudo[2697]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:08 volumio sudo[2697]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:08 volumio volumio-remote-updater[781]: No test mode Sep 01 14:34:08 volumio volumio-remote-updater[781]: No alpha test mode Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Sep 01 14:34:08 volumio volumio[1127]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Sep 01 14:34:08 volumio volumio[1127]: wlan0 Interface doesn't support scanning : Operation not supported Sep 01 14:34:08 volumio volumio[1127]: info: Cannot use regular scanning, forcing with ap-force Sep 01 14:34:08 volumio sudo[2702]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Sep 01 14:34:08 volumio sudo[2702]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:08 volumio sudo[2702]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:08 volumio volumio[1127]: command failed: Operation not supported (-95) Sep 01 14:34:08 volumio volumio[1127]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Sep 01 14:34:08 volumio volumio[1127]: command failed: Operation not supported (-95) Sep 01 14:34:08 volumio volumio[1127]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Sep 01 14:34:08 volumio volumio[1127]: wlan0 Interface doesn't support scanning : Operation not supported Sep 01 14:34:08 volumio volumio[1127]: info: Cannot use regular scanning, forcing with ap-force Sep 01 14:34:08 volumio sudo[2705]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Sep 01 14:34:08 volumio sudo[2705]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:08 volumio sudo[2705]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:08 volumio volumio[1127]: command failed: Operation not supported (-95) Sep 01 14:34:08 volumio volumio[1127]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Sep 01 14:34:08 volumio volumio[1127]: command failed: Operation not supported (-95) Sep 01 14:34:08 volumio volumio[1127]: Unable to parse: Sep 01 14:34:08 volumio volumio[1127]: Simple mixer control 'PCM',0 Sep 01 14:34:08 volumio volumio[1127]: Capabilities: pswitch pswitch-joined Sep 01 14:34:08 volumio volumio[1127]: Playback channels: Mono Sep 01 14:34:08 volumio volumio[1127]: Mono: Playback [on] Sep 01 14:34:08 volumio volumio[1127]: info: VolumeController:: Volume=undefined Mute =false Sep 01 14:34:08 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:34:08 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 01 14:34:08 volumio volumio[1127]: info: Asound.conf file written Sep 01 14:34:08 volumio sudo[2712]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Sep 01 14:34:08 volumio sudo[2712]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:08 volumio sudo[2712]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:08 volumio volumio[1127]: No state is present for card PCH Sep 01 14:34:08 volumio volumio[1127]: Found hardware: "HDA-Intel" "Intel Alderlake-P HDMI" "HDA:8086281c,80860101,00100000" "0x8086" "0x7270" Sep 01 14:34:08 volumio volumio[1127]: Hardware is initialized using a generic method Sep 01 14:34:08 volumio volumio[1127]: No state is present for card PCH Sep 01 14:34:08 volumio volumio[1127]: No state is present for card AUDIO Sep 01 14:34:08 volumio volumio[1127]: Found hardware: "USB-Audio" "USB Mixer" "USB0746:b000" "" "" Sep 01 14:34:08 volumio volumio[1127]: Hardware is initialized using a generic method Sep 01 14:34:08 volumio volumio[1127]: No state is present for card AUDIO Sep 01 14:34:08 volumio volumio[1127]: No state is present for card HID Sep 01 14:34:08 volumio volumio[1127]: Found hardware: "USB-Audio" "USB Mixer" "USB0573:1573" "" "" Sep 01 14:34:08 volumio volumio[1127]: Hardware is initialized using a generic method Sep 01 14:34:08 volumio volumio[1127]: No state is present for card HID Sep 01 14:34:08 volumio volumio[1127]: info: Output device has changed, restarting MPD Sep 01 14:34:08 volumio sudo[2717]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 14:34:08 volumio sudo[2717]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:08 volumio sudo[2717]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:08 volumio volumio[1127]: info: Output device has changed, restarting Shairport Sync Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:34:08 volumio sudo[2720]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 14:34:08 volumio sudo[2720]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:08 volumio systemd[1]: Stopping Music Player Daemon... Sep 01 14:34:08 volumio volumio[1127]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 14:34:08 volumio systemd[1]: mpd.service: Succeeded. Sep 01 14:34:08 volumio systemd[1]: Stopped Music Player Daemon. Sep 01 14:34:08 volumio volumio[1127]: info: Output device has changed, restarting MPD Sep 01 14:34:08 volumio sudo[2727]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 14:34:08 volumio sudo[2727]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:08 volumio volumio[1127]: info: Output device has changed, restarting Shairport Sync Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 14:34:08 volumio systemd[1]: Starting Music Player Daemon... Sep 01 14:34:08 volumio sudo[2727]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:08 volumio sudo[2730]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 14:34:08 volumio sudo[2730]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:08 volumio volumio[1127]: info: MPD Permissions set Sep 01 14:34:08 volumio volumio[1127]: info: MPD Permissions set Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Sep 01 14:34:08 volumio systemd[1]: mpd.service: Succeeded. Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio systemd[1]: Stopped Music Player Daemon. Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio systemd[1]: Starting Music Player Daemon... Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio sudo[2735]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 01 14:34:08 volumio sudo[2735]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Sep 01 14:34:08 volumio sudo[2735]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:08 volumio volumio[1127]: info: Starting Shairport Sync Sep 01 14:34:08 volumio volumio[1127]: info: Starting Shairport Sync Sep 01 14:34:08 volumio sudo[2751]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 14:34:08 volumio sudo[2751]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:08 volumio sudo[2754]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 14:34:08 volumio sudo[2754]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:08 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 01 14:34:08 volumio systemd[1]: shairport-sync.service: Succeeded. Sep 01 14:34:08 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 01 14:34:08 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 01 14:34:08 volumio sudo[2751]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:08 volumio sudo[2754]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:08 volumio volumio[1127]: info: Shairport-Sync Started Sep 01 14:34:08 volumio volumio[1127]: info: Shairport-Sync Started Sep 01 14:34:08 volumio mpd[2747]: Sep 01 14:34 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 01 14:34:08 volumio systemd[1]: Started Music Player Daemon. Sep 01 14:34:08 volumio sudo[2720]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:08 volumio sudo[2730]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:08 volumio volumio[1127]: error: MPD error: The expression evaluated to a falsy value: Sep 01 14:34:08 volumio volumio[1127]: assert.ok(self.idling) Sep 01 14:34:08 volumio volumio[1127]: error: The expression evaluated to a falsy value: Sep 01 14:34:08 volumio volumio[1127]: assert.ok(self.idling) Sep 01 14:34:08 volumio volumio[1127]: error: updateQueue error: null Sep 01 14:34:08 volumio volumio[1127]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Sep 01 14:34:08 volumio volumio[1127]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Sep 01 14:34:08 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Sep 01 14:34:09 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:34:09 volumio volumio[1127]: info: Retrieving Cloud Streaming UI Sep 01 14:34:09 volumio volumio[1127]: info: Getting Tidal Cloud Configuration Sep 01 14:34:09 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:34:09 volumio volumio[1127]: info: Getting Qobuz Cloud Configuration Sep 01 14:34:09 volumio volumio[1127]: info: Asking plugin for UI Config Sep 01 14:34:09 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:34:09 volumio volumio[1127]: info: Getting Spotify Cloud Configuration Sep 01 14:34:09 volumio volumio[1127]: info: Asking plugin for UI Config Sep 01 14:34:09 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:34:09 volumio volumio[1127]: info: Saving Spotify Acccount Sep 01 14:34:09 volumio volumio[1127]: info: Got Tidal Cloud Configuration Sep 01 14:34:09 volumio volumio[1127]: info: Got it Sep 01 14:34:09 volumio volumio[1127]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Sep 01 14:34:09 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:34:09 volumio volumio[1127]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Sep 01 14:34:10 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: wizard , getDonation Sep 01 14:34:10 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , detectVolumioHardware Sep 01 14:34:10 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: wizard , getDonationsArray Sep 01 14:34:10 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: wizard , getDoneMessage Sep 01 14:34:10 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , detectVolumioHardware Sep 01 14:34:10 volumio volumio[1127]: info: MYVOLUMIO: Adding device Sep 01 14:34:10 volumio volumio[1127]: info: MYVOLUMIO: Evaluating Server Sep 01 14:34:11 volumio volumio[1127]: info: Setting Geolocation for MyVolumio to as1 Sep 01 14:34:11 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:34:12 volumio volumio[1127]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Sep 01 14:34:12 volumio volumio[1127]: info: CoreStateMachine::getcurrentVolume Sep 01 14:34:12 volumio volumio[1127]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 14:34:12 volumio volumio[1127]: Unable to parse: Sep 01 14:34:12 volumio volumio[1127]: Simple mixer control 'PCM',0 Sep 01 14:34:12 volumio volumio[1127]: Capabilities: pswitch pswitch-joined Sep 01 14:34:12 volumio volumio[1127]: Playback channels: Mono Sep 01 14:34:12 volumio volumio[1127]: Mono: Playback [on] Sep 01 14:34:12 volumio volumio[1127]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Sep 01 14:34:12 volumio volumio[1127]: Unable to parse: Sep 01 14:34:12 volumio volumio[1127]: Simple mixer control 'PCM',0 Sep 01 14:34:12 volumio volumio[1127]: Capabilities: pswitch pswitch-joined Sep 01 14:34:12 volumio volumio[1127]: Playback channels: Mono Sep 01 14:34:12 volumio volumio[1127]: Mono: Playback [on] Sep 01 14:34:12 volumio volumio[1127]: info: VolumeController:: Volume=undefined Mute =false Sep 01 14:34:12 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:34:12 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:12 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:34:12 volumio volumio[1127]: info: CoreStateMachine::updateTrackBlock Sep 01 14:34:12 volumio volumio[1127]: info: CorePlayQueue::getTrackBlock Sep 01 14:34:12 volumio volumio[1127]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 14:34:12 volumio volumio[1127]: Unable to parse: Sep 01 14:34:12 volumio volumio[1127]: Simple mixer control 'PCM',0 Sep 01 14:34:12 volumio volumio[1127]: Capabilities: pswitch pswitch-joined Sep 01 14:34:12 volumio volumio[1127]: Playback channels: Mono Sep 01 14:34:12 volumio volumio[1127]: Mono: Playback [on] Sep 01 14:34:12 volumio volumio[1127]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Sep 01 14:34:12 volumio volumio[1127]: Unable to parse: Sep 01 14:34:12 volumio volumio[1127]: Simple mixer control 'PCM',0 Sep 01 14:34:12 volumio volumio[1127]: Capabilities: pswitch pswitch-joined Sep 01 14:34:12 volumio volumio[1127]: Playback channels: Mono Sep 01 14:34:12 volumio volumio[1127]: Mono: Playback [on] Sep 01 14:34:12 volumio volumio[1127]: info: VolumeController:: Volume=undefined Mute =false Sep 01 14:34:12 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:34:12 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:12 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:34:12 volumio volumio[1127]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Sep 01 14:34:12 volumio volumio[1127]: info: Updating MyVolumio device info Sep 01 14:34:12 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:34:12 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 14:34:13 volumio volumio[1127]: info: CALLMETHOD: system_controller system saveUpdateSettings [object Object] Sep 01 14:34:13 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , saveUpdateSettings Sep 01 14:34:13 volumio volumio[1127]: error: Failed callmethod call: TypeError: Cannot read property 'value' of undefined Sep 01 14:34:13 volumio volumio[1127]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Sep 01 14:34:13 volumio ntpd[1931]: Soliciting pool server 209.58.185.100 Sep 01 14:34:13 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: wizard , setWizardAction Sep 01 14:34:13 volumio volumio[1127]: info: CoreCommandRouter::Reload Ui Sep 01 14:34:13 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , setShowWizard Sep 01 14:34:13 volumio volumio[1127]: info: Wizard terminated Successfully Sep 01 14:34:13 volumio volumio[1127]: info: CoreCommandRouter::volumiosetStartupVolume Sep 01 14:34:13 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 14:34:14 volumio sudo[2788]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 14:34:14 volumio sudo[2788]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:14 volumio sudo[2788]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:14 volumio sudo[2791]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 14:34:14 volumio sudo[2791]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:14 volumio sudo[2791]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:14 volumio volumio[1127]: 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: 4 Sep 01 14:34:14 volumio volumio[1127]: verbose: New Socket.io Connection to 192.168.31.203 from 192.168.31.196 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/139.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Sep 01 14:34:14 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 01 14:34:14 volumio volumio[1127]: info: CoreCommandRouter::volumioGetVisibleSources Sep 01 14:34:14 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 14:34:14 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:14 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:14 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 01 14:34:14 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 01 14:34:14 volumio volumio[1127]: info: Received Get System Info Sep 01 14:34:14 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 14:34:14 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 14:34:14 volumio volumio[1127]: info: Discovery: Getting this device information Sep 01 14:34:14 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:14 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:14 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 14:34:14 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:14 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:14 volumio volumio[1127]: info: Listing playlists Sep 01 14:34:14 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 01 14:34:14 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 14:34:14 volumio sudo[2795]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 14:34:14 volumio sudo[2795]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:14 volumio sudo[2795]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:14 volumio sudo[2798]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 14:34:14 volumio sudo[2798]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 14:34:14 volumio sudo[2798]: pam_unix(sudo:session): session closed for user root Sep 01 14:34:14 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Sep 01 14:34:14 volumio volumio[1127]: 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: 6 Sep 01 14:34:14 volumio volumio[1127]: verbose: New Socket.io Connection to 192.168.31.203 from 192.168.31.196 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/139.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::volumioGetVisibleSources Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:15 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 01 14:34:15 volumio volumio[1127]: info: Received Get System Info Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 14:34:15 volumio volumio[1127]: info: Discovery: Getting this device information Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:15 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:15 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:15 volumio volumio[1127]: info: Listing playlists Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::volumioGetVisibleSources Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:15 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 01 14:34:15 volumio volumio[1127]: info: Received Get System Info Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 14:34:15 volumio volumio[1127]: info: Discovery: Getting this device information Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:15 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:15 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:15 volumio volumio[1127]: info: Listing playlists Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:15 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:15 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:15 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:16 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Sep 01 14:34:16 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Sep 01 14:34:16 volumio ntpd[1931]: Soliciting pool server 162.159.200.1 Sep 01 14:34:16 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 14:34:16 volumio volumio[1127]: info: Received Get System Info Sep 01 14:34:16 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 14:34:16 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 14:34:16 volumio volumio[1127]: info: Discovery: Getting this device information Sep 01 14:34:16 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:16 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:16 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 14:34:16 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 01 14:34:16 volumio ntpd[1931]: Soliciting pool server 118.143.17.83 Sep 01 14:34:16 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 14:34:16 volumio volumio[1127]: info: Received Get System Info Sep 01 14:34:16 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 14:34:16 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 14:34:16 volumio volumio[1127]: info: Discovery: Getting this device information Sep 01 14:34:16 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:16 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:16 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 14:34:18 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 14:34:18 volumio volumio[1127]: info: Received Get System Info Sep 01 14:34:18 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 14:34:18 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 14:34:18 volumio volumio[1127]: info: Discovery: Getting this device information Sep 01 14:34:18 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:18 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:18 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 14:34:18 volumio ntpd[1931]: Soliciting pool server 118.143.17.83 Sep 01 14:34:18 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 14:34:18 volumio volumio[1127]: info: Received Get System Info Sep 01 14:34:18 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 14:34:18 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 14:34:18 volumio volumio[1127]: info: Discovery: Getting this device information Sep 01 14:34:18 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:18 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:18 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 14:34:19 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: wizard , setOnboardingWizardFalse Sep 01 14:34:19 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 14:34:19 volumio volumio[1127]: info: Received Get System Info Sep 01 14:34:19 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 14:34:19 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 14:34:19 volumio volumio[1127]: info: Discovery: Getting this device information Sep 01 14:34:19 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:19 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:19 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 14:34:20 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: wizard , setOnboardingWizardFalse Sep 01 14:34:24 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Sep 01 14:34:24 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Sep 01 14:34:26 volumio volumio[1127]: info: CoreCommandRouter::Close All Modals sent Sep 01 14:34:26 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , setTOSAccepted Sep 01 14:34:27 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:34:27 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Sep 01 14:34:27 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Sep 01 14:34:27 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Sep 01 14:34:27 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Sep 01 14:34:27 volumio volumio[1127]: info: Received Get System Version Sep 01 14:34:27 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 14:34:29 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Sep 01 14:34:29 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 01 14:34:30 volumio volumio-remote-updater[781]: No test mode Sep 01 14:34:30 volumio volumio-remote-updater[781]: No alpha test mode Sep 01 14:34:30 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Sep 01 14:34:30 volumio volumio[1127]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Sep 01 14:34:30 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Sep 01 14:34:32 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Sep 01 14:34:32 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 01 14:34:32 volumio systemd[1]: systemd-timedated.service: Succeeded. Sep 01 14:34:32 volumio volumio-remote-updater[781]: No test mode Sep 01 14:34:32 volumio volumio-remote-updater[781]: No alpha test mode Sep 01 14:34:32 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Sep 01 14:34:33 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 14:34:33 volumio volumio[1127]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Sep 01 14:34:33 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Sep 01 14:34:33 volumio volumio[1127]: info: Received Get System Version Sep 01 14:34:33 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 14:34:33 volumio volumio[1127]: info: Received Get System Info Sep 01 14:34:33 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 14:34:33 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 14:34:33 volumio volumio[1127]: info: Discovery: Getting this device information Sep 01 14:34:33 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:33 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:33 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 14:34:33 volumio volumio[1127]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Sep 01 14:34:33 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Sep 01 14:34:33 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 14:34:33 volumio volumio[1127]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Sep 01 14:34:33 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Sep 01 14:34:33 volumio volumio[1127]: info: Received Get System Version Sep 01 14:34:33 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 14:34:33 volumio volumio[1127]: info: Received Get System Info Sep 01 14:34:33 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 14:34:33 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 14:34:33 volumio volumio[1127]: info: Discovery: Getting this device information Sep 01 14:34:33 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:33 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:33 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 14:34:46 volumio volumio[1127]: info: CoreCommandRouter::volumioGetState Sep 01 14:34:46 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:47 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:34:47 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:34:47 volumio volumio[1127]: info: Retrieving Cloud Streaming UI Sep 01 14:34:47 volumio volumio[1127]: info: Getting Tidal Cloud Configuration Sep 01 14:34:47 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:34:47 volumio volumio[1127]: info: Getting Qobuz Cloud Configuration Sep 01 14:34:47 volumio volumio[1127]: info: Asking plugin for UI Config Sep 01 14:34:47 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:34:47 volumio volumio[1127]: info: Getting Spotify Cloud Configuration Sep 01 14:34:47 volumio volumio[1127]: info: Asking plugin for UI Config Sep 01 14:34:47 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:34:47 volumio volumio[1127]: info: Saving Spotify Acccount Sep 01 14:34:47 volumio volumio[1127]: info: Got Tidal Cloud Configuration Sep 01 14:34:47 volumio volumio[1127]: info: Got it Sep 01 14:34:47 volumio volumio[1127]: info: Got it Sep 01 14:34:47 volumio volumio[1127]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Sep 01 14:34:47 volumio volumio[1127]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 14:34:47 volumio volumio[1127]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Sep 01 14:34:47 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 01 14:34:47 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Sep 01 14:34:47 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Sep 01 14:34:47 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Sep 01 14:34:47 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 14:34:47 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 14:34:47 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 14:34:47 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 14:34:47 volumio volumio[1127]: info: CoreCommandRouter::volumioGetBrowseSources Sep 01 14:34:47 volumio volumio[1127]: info: CoreCommandRouter::volumioGetBrowseSources Sep 01 14:34:47 volumio volumio[1127]: info: CoreCommandRouter::volumioGetBrowseSources Sep 01 14:34:48 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 01 14:34:48 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Sep 01 14:34:51 volumio volumio[1127]: verbose: ControllerMpd::sendMpdCommand rescan Sep 01 14:34:51 volumio volumio[1127]: verbose: ControllerMpd::sendMpdCommand status Sep 01 14:34:51 volumio volumio[1127]: info: Sep 01 14:34:51 volumio volumio[1127]: ---------------------------- MPD announces state update: update Sep 01 14:34:51 volumio volumio[1127]: info: sendMpdCommand rescan took 2 milliseconds Sep 01 14:34:51 volumio volumio[1127]: info: ControllerMpd::getState Sep 01 14:34:51 volumio volumio[1127]: verbose: ControllerMpd::sendMpdCommand status Sep 01 14:34:51 volumio volumio[1127]: verbose: ControllerMpd::sendMpdCommand status Sep 01 14:34:51 volumio volumio[1127]: info: Sep 01 14:34:51 volumio volumio[1127]: ---------------------------- MPD announces state update: update Sep 01 14:34:51 volumio volumio[1127]: info: ControllerMpd::getState Sep 01 14:34:51 volumio volumio[1127]: verbose: ControllerMpd::sendMpdCommand status Sep 01 14:34:51 volumio volumio[1127]: verbose: ControllerMpd::sendMpdCommand status Sep 01 14:34:51 volumio volumio[1127]: info: Sep 01 14:34:51 volumio volumio[1127]: ---------------------------- MPD announces state update: update Sep 01 14:34:51 volumio volumio[1127]: info: ControllerMpd::getState Sep 01 14:34:51 volumio volumio[1127]: verbose: ControllerMpd::sendMpdCommand status Sep 01 14:34:51 volumio volumio[1127]: info: sendMpdCommand status took 2 milliseconds Sep 01 14:34:51 volumio volumio[1127]: info: sendMpdCommand status took 1 milliseconds Sep 01 14:34:51 volumio volumio[1127]: info: sendMpdCommand status took 1 milliseconds Sep 01 14:34:51 volumio volumio[1127]: info: sendMpdCommand status took 1 milliseconds Sep 01 14:34:51 volumio volumio[1127]: verbose: ControllerMpd::parseState Sep 01 14:34:51 volumio volumio[1127]: info: Command Router : Notfying DB Updatefalse Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::Close All Modals sent Sep 01 14:34:51 volumio volumio[1127]: verbose: ControllerMpd::parseState Sep 01 14:34:51 volumio volumio[1127]: verbose: ControllerMpd::parseState Sep 01 14:34:51 volumio volumio[1127]: info: Command Router : Notfying DB Updatefalse Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::Close All Modals sent Sep 01 14:34:51 volumio volumio[1127]: verbose: ControllerMpd::parseState Sep 01 14:34:51 volumio volumio[1127]: info: ControllerMpd::pushState Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::servicePushState Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:34:51 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:34:51 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:51 volumio volumio[1127]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 01 14:34:51 volumio volumio[1127]: verbose: CURRENT POSITION 0 Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::syncState stateService stop Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::syncState currentStatus stop Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:34:51 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:34:51 volumio volumio[1127]: info: No code Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:34:51 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:34:51 volumio volumio[1127]: info: ControllerMpd::pushState Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::servicePushState Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:34:51 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:34:51 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:51 volumio volumio[1127]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 01 14:34:51 volumio volumio[1127]: verbose: CURRENT POSITION 0 Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::syncState stateService stop Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::syncState currentStatus stop Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:34:51 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:34:51 volumio volumio[1127]: info: No code Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:34:51 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:34:51 volumio volumio[1127]: info: ------------------------------ 42ms Sep 01 14:34:51 volumio volumio[1127]: info: ------------------------------ 42ms Sep 01 14:34:51 volumio volumio[1127]: verbose: ControllerMpd::sendMpdCommand status Sep 01 14:34:51 volumio volumio[1127]: info: Sep 01 14:34:51 volumio volumio[1127]: ---------------------------- MPD announces state update: update Sep 01 14:34:51 volumio volumio[1127]: info: ControllerMpd::getState Sep 01 14:34:51 volumio volumio[1127]: verbose: ControllerMpd::sendMpdCommand status Sep 01 14:34:51 volumio volumio[1127]: info: sendMpdCommand status took 41 milliseconds Sep 01 14:34:51 volumio volumio[1127]: info: sendMpdCommand status took 42 milliseconds Sep 01 14:34:51 volumio volumio[1127]: info: sendMpdCommand status took 1 milliseconds Sep 01 14:34:51 volumio volumio[1127]: info: sendMpdCommand status took 1 milliseconds Sep 01 14:34:51 volumio volumio[1127]: verbose: ControllerMpd::parseState Sep 01 14:34:51 volumio volumio[1127]: info: Command Router : Notfying DB Updatefalse Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::Close All Modals sent Sep 01 14:34:51 volumio volumio[1127]: verbose: ControllerMpd::parseState Sep 01 14:34:51 volumio volumio[1127]: verbose: ControllerMpd::parseState Sep 01 14:34:51 volumio volumio[1127]: info: Command Router : Notfying DB Updatefalse Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::Close All Modals sent Sep 01 14:34:51 volumio volumio[1127]: verbose: ControllerMpd::parseState Sep 01 14:34:51 volumio volumio[1127]: info: ControllerMpd::pushState Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::servicePushState Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:34:51 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:34:51 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:51 volumio volumio[1127]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 01 14:34:51 volumio volumio[1127]: verbose: CURRENT POSITION 0 Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::syncState stateService stop Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::syncState currentStatus stop Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:34:51 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:34:51 volumio volumio[1127]: info: No code Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:34:51 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:34:51 volumio volumio[1127]: info: ControllerMpd::pushState Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::servicePushState Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:34:51 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:34:51 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:51 volumio volumio[1127]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 01 14:34:51 volumio volumio[1127]: verbose: CURRENT POSITION 0 Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::syncState stateService stop Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::syncState currentStatus stop Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:34:51 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:34:51 volumio volumio[1127]: info: No code Sep 01 14:34:51 volumio volumio[1127]: info: CoreStateMachine::pushState Sep 01 14:34:51 volumio volumio[1127]: info: CorePlayQueue::getTrack 0 Sep 01 14:34:51 volumio volumio[1127]: info: CoreCommandRouter::volumioPushState Sep 01 14:34:51 volumio volumio[1127]: info: ------------------------------ 75ms Sep 01 14:34:51 volumio volumio[1127]: info: ------------------------------ 35ms Sep 01 14:34:52 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 01 14:34:53 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Sep 01 14:34:53 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Sep 01 14:34:54 volumio volumio[1127]: info: Executing SMB command: smbclient --no-pass --debuglevel=0 -L Nas.local. -m SMB3_11 Sep 01 14:34:54 volumio volumio[1127]: info: Error browsing device Nas for shares: Command failed: smbclient --no-pass --debuglevel=0 -L Nas.local. -m SMB3_11 Sep 01 14:34:54 volumio volumio[1127]: Unable to initialize messaging context Sep 01 14:34:56 volumio volumio[1127]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 01 14:34:58 volumio volumio[1127]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 14:34:58 volumio volumio[1127]: Error: dns service error: unknown Sep 01 14:34:58 volumio volumio[1127]: at MDNSService.on_resolver_done (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:19:30) Sep 01 14:34:58 volumio volumio[1127]: at SocketWatcher.MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { Sep 01 14:34:58 volumio volumio[1127]: errorCode: -65537 Sep 01 14:34:58 volumio volumio[1127]: } Sep 01 14:34:58 volumio volumio[1127]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 14:34:58 volumio sudo[2995]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-01 14:33 Sep 01 14:34:58 volumio sudo[2995]: 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="669bb6cc406bb77b11c5184fedb8a4dfd19ba4ec" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 11:08:46 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="9ef0bfa9b61509be20c9051562554f31"