Sep 07 16:32:00 volumio-higole-x86 kernel: Generic FE-GE Realtek PHY r8169-0-100:00: attached PHY driver (mii_bus:phy_addr=r8169-0-100:00, irq=MAC)
Sep 07 16:32:00 volumio-higole-x86 bluetoothd[835]: profiles/audio/bap.c:bap_adapter_probe() BAP requires ISO Socket which is not enabled
Sep 07 16:32:00 volumio-higole-x86 bluetoothd[835]: bap: Operation not supported (95)
Sep 07 16:32:00 volumio-higole-x86 upmpdcli[851]: Could not open config: /tmp/upmpdcli.conf
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Sep 07 16:32:00 volumio-higole-x86 dhcpcd[817]: eth0: waiting for carrier
Sep 07 16:32:00 volumio-higole-x86 sh[797]: eth0: waiting for carrier
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Started rpcbind.service - RPC bind portmap service.
Sep 07 16:32:00 volumio-higole-x86 sh[797]: eth0: carrier acquired
Sep 07 16:32:00 volumio-higole-x86 dhcpcd[817]: eth0: carrier acquired
Sep 07 16:32:00 volumio-higole-x86 avahi-daemon[834]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Reached target remote-fs-pre.target - Preparation for Remote File Systems.
Sep 07 16:32:00 volumio-higole-x86 avahi-daemon[834]: New relevant interface lo.IPv4 for mDNS.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Reached target remote-fs.target - Remote File Systems.
Sep 07 16:32:00 volumio-higole-x86 avahi-daemon[834]: Network interface enumeration completed.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Reached target rpcbind.target - RPC Port Mapper.
Sep 07 16:32:00 volumio-higole-x86 avahi-daemon[834]: Registering new address record for 127.0.0.1 on lo.IPv4.
Sep 07 16:32:00 volumio-higole-x86 volumio-remote-updater[852]: [2025-09-07 16:32:00] [info] asio async_connect error: asio.system:111 (Connection refused)
Sep 07 16:32:00 volumio-higole-x86 volumio-remote-updater[852]: [2025-09-07 16:32:00] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected)
Sep 07 16:32:00 volumio-higole-x86 volumio-remote-updater[852]: [2025-09-07 16:32:00] [error] handle_connect error: Connection refused
Sep 07 16:32:00 volumio-higole-x86 sh[797]: eth0: IAID 5d:b8:8e:9a
Sep 07 16:32:00 volumio-higole-x86 kernel: r8169 0000:01:00.0 eth0: Link is Down
Sep 07 16:32:00 volumio-higole-x86 bluetoothd[835]: Adv Monitor Manager created with supported features:0x00000000, enabled features:0x00000000, max number of supported monitors:32, max number of supported patterns:16
Sep 07 16:32:00 volumio-higole-x86 dhcpcd[817]: eth0: IAID 5d:b8:8e:9a
Sep 07 16:32:00 volumio-higole-x86 sh[797]: eth0: adding address fe80::a146:9521:efd7:9198
Sep 07 16:32:00 volumio-higole-x86 dhcpcd[817]: eth0: adding address fe80::a146:9521:efd7:9198
Sep 07 16:32:00 volumio-higole-x86 dhcpcd[817]: ipv6_addaddr1: Permission denied
Sep 07 16:32:00 volumio-higole-x86 sh[797]: ipv6_addaddr1: Permission denied
Sep 07 16:32:00 volumio-higole-x86 bluealsa[930]: ../src/storage.c:90: Initializing persistent storage: /var/lib/bluealsa
Sep 07 16:32:00 volumio-higole-x86 bluealsa[930]: main.c:663: Starting main dispatching loop
Sep 07 16:32:00 volumio-higole-x86 bluealsa[930]: main.c:118: Acquired D-Bus service name: org.bluealsa
Sep 07 16:32:00 volumio-higole-x86 bluealsa[930]: bluealsa-dbus.c:358: Registering BlueALSA D-Bus manager: /org/bluealsa
Sep 07 16:32:00 volumio-higole-x86 dhcpcd[869]: wlan0: connected to Access Point:
Sep 07 16:32:00 volumio-higole-x86 bluealsa[930]: bluez.c:153: Registering media application: /org/bluez/hci0
Sep 07 16:32:00 volumio-higole-x86 bluealsa[930]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/source/1
Sep 07 16:32:00 volumio-higole-x86 bluealsa[930]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/source/2
Sep 07 16:32:00 volumio-higole-x86 bluealsa[930]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/1
Sep 07 16:32:00 volumio-higole-x86 bluealsa[930]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/2
Sep 07 16:32:00 volumio-higole-x86 dhcpcd[869]: eth0: IAID 5d:b8:8e:9a
Sep 07 16:32:00 volumio-higole-x86 dhcpcd[869]: eth0: adding address fe80::a146:9521:efd7:9198
Sep 07 16:32:00 volumio-higole-x86 dhcpcd[869]: ipv6_addaddr1: Permission denied
Sep 07 16:32:00 volumio-higole-x86 dhcpcd[869]: wlan0: IAID 2b:f7:76:9f
Sep 07 16:32:00 volumio-higole-x86 dhcpcd[869]: wlan0: adding address fe80::2265:1272:c764:a1d4
Sep 07 16:32:00 volumio-higole-x86 dhcpcd[869]: ipv6_addaddr1: Permission denied
Sep 07 16:32:00 volumio-higole-x86 sh[797]: eth0: carrier lost
Sep 07 16:32:00 volumio-higole-x86 dhcpcd[817]: eth0: carrier lost
Sep 07 16:32:00 volumio-higole-x86 dhcpcd[869]: wlan0: carrier lost
Sep 07 16:32:00 volumio-higole-x86 bluetoothd[835]: Endpoint registered: sender=:1.5 path=/org/bluez/hci0/A2DP/SBC/source/1
Sep 07 16:32:00 volumio-higole-x86 bluetoothd[835]: Endpoint registered: sender=:1.5 path=/org/bluez/hci0/A2DP/SBC/sink/2
Sep 07 16:32:00 volumio-higole-x86 bluetoothd[835]: Endpoint registered: sender=:1.5 path=/org/bluez/hci0/A2DP/SBC/source/2
Sep 07 16:32:00 volumio-higole-x86 bluetoothd[835]: Endpoint registered: sender=:1.5 path=/org/bluez/hci0/A2DP/SBC/sink/1
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Starting loadcpufreq.service - LSB: Load kernel modules needed to enable cpufreq scaling...
Sep 07 16:32:00 volumio-higole-x86 dhcpcd[869]: eth0: carrier lost
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: systemd-pcrphase.service - TPM2 PCR Barrier (User) was skipped because of an unmet condition check (ConditionPathExists=/sys/firmware/efi/efivars/StubPcrKernelImage-4a67b082-0a4c-41cf-b6c7-440b29bb8c4f).
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Started dhcpcd.service - DHCP Client Daemon on all interfaces.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Started bluealsa.service - BlueALSA service.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Reached target bluetooth.target - Bluetooth Support.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Reached target network.target - Network.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Reached target network-online.target - Network is Online.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Starting ifplugd.service - LSB: Brings up/down network automatically...
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Starting mpd.service - Music Player Daemon...
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Starting nmbd.service - Samba NMB Daemon...
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Starting ntpsec.service - Network Time Service...
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Starting rc-local.service - /etc/rc.local Compatibility...
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Starting rpc-statd-notify.service - Notify NFS peers of a restart...
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Starting samba-ad-dc.service - Samba AD Daemon...
Sep 07 16:32:00 volumio-higole-x86 sm-notify[1013]: Version 2.6.2 starting
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service...
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Sep 07 16:32:00 volumio-higole-x86 dbus-daemon[838]: [system] Successfully activated service 'org.freedesktop.hostname1'
Sep 07 16:32:00 volumio-higole-x86 dbus-daemon[838]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.7' (uid=0 pid=1022 comm="timedatectl show --property=NTPSynchronized --valu")
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Starting ssh.service - OpenBSD Secure Shell server...
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions...
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Started volumio-ipchange.service - Volumio IP Change Monitor.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Starting welcome.service - Show a welcome message on console...
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: e2scrub_reap.service: Deactivated successfully.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Finished e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Started rc-local.service - /etc/rc.local Compatibility.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Started rpc-statd-notify.service - Notify NFS peers of a restart.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: iptables.service: Deactivated successfully.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Started systemd-hostnamed.service - Hostname Service.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions.
Sep 07 16:32:00 volumio-higole-x86 ntpd[1025]: INIT: ntpd ntpsec-1.2.2: Starting
Sep 07 16:32:00 volumio-higole-x86 ntp-systemd-wrapper[1025]: 2025-09-07T16:32:00 ntpd[1025]: INIT: ntpd ntpsec-1.2.2: Starting
Sep 07 16:32:00 volumio-higole-x86 ntp-systemd-wrapper[1025]: 2025-09-07T16:32:00 ntpd[1025]: INIT: Command line: /usr/sbin/ntpd -p /run/ntpd.pid -c /etc/ntpsec/ntp.conf -g -N -u ntpsec:ntpsec
Sep 07 16:32:00 volumio-higole-x86 ntpd[1025]: INIT: Command line: /usr/sbin/ntpd -p /run/ntpd.pid -c /etc/ntpsec/ntp.conf -g -N -u ntpsec:ntpsec
Sep 07 16:32:00 volumio-higole-x86 welcome[1032]: Resolved ip:[0]
Sep 07 16:32:00 volumio-higole-x86 ntpd[1041]: INIT: precision = 0.090 usec (-23)
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Started ntpsec.service - Network Time Service.
Sep 07 16:32:00 volumio-higole-x86 ntpd[1041]: INIT: successfully locked into RAM
Sep 07 16:32:00 volumio-higole-x86 ntpd[1041]: CONFIG: readconfig: parsing file: /etc/ntpsec/ntp.conf
Sep 07 16:32:00 volumio-higole-x86 ntpd[1041]: CONFIG: restrict nopeer ignored
Sep 07 16:32:00 volumio-higole-x86 ntpd[1041]: CLOCK: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature
Sep 07 16:32:00 volumio-higole-x86 ntpd[1041]: CLOCK: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2025-12-28T00:00Z last=2017-01-01T00:00Z ofs=37
Sep 07 16:32:00 volumio-higole-x86 ntpd[1041]: INIT: Using SO_TIMESTAMPNS(ns)
Sep 07 16:32:00 volumio-higole-x86 ntpd[1041]: IO: Listen and drop on 0 v6wildcard [::]:123
Sep 07 16:32:00 volumio-higole-x86 ntpd[1041]: IO: Listen and drop on 1 v4wildcard 0.0.0.0:123
Sep 07 16:32:00 volumio-higole-x86 ntpd[1041]: IO: Listen normally on 2 lo 127.0.0.1:123
Sep 07 16:32:00 volumio-higole-x86 ntpd[1041]: IO: Listening on routing socket on fd #19 for interface updates
Sep 07 16:32:00 volumio-higole-x86 ifplugd(eth0)[1057]: ifplugd 0.28 initializing.
Sep 07 16:32:00 volumio-higole-x86 ifplugd(eth0)[1057]: Using interface eth0/88:83:5D:B8:8E:9A with driver (version: 6.12.35-volumio)
Sep 07 16:32:00 volumio-higole-x86 ifplugd(eth0)[1057]: Using detection mode: SIOCETHTOOL
Sep 07 16:32:00 volumio-higole-x86 ifplugd(eth0)[1057]: Initialization complete, link beat not detected.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Starting plymouth-quit-wait.service - Hold until boot process finishes up...
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen...
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Starting systemd-timedated.service - Time & Date Service...
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Received SIGRTMIN+21 from PID 360 (plymouthd).
Sep 07 16:32:00 volumio-higole-x86 ntpd[1041]: INIT: MRU 10922 entries, 13 hash bits, 65536 bytes
Sep 07 16:32:00 volumio-higole-x86 ntpd[1041]: INIT: Built with OpenSSL 3.0.9 30 May 2023, 30000090
Sep 07 16:32:00 volumio-higole-x86 ntpd[1041]: INIT: Running with OpenSSL 3.0.16 11 Feb 2025, 30000100
Sep 07 16:32:00 volumio-higole-x86 ntpd[1041]: NTSc: Using system default root certificates.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Finished welcome.service - Show a welcome message on console.
Sep 07 16:32:00 volumio-higole-x86 sshd[1062]: Server listening on 0.0.0.0 port 22.
Sep 07 16:32:00 volumio-higole-x86 sshd[1062]: Server listening on :: port 22.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Started ssh.service - OpenBSD Secure Shell server.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Received SIGRTMIN+21 from PID 360 (plymouthd).
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen.
Sep 07 16:32:00 volumio-higole-x86 dbus-daemon[838]: [system] Successfully activated service 'org.freedesktop.timedate1'
Sep 07 16:32:00 volumio-higole-x86 bash[1021]: Time is already synchronized.
Sep 07 16:32:00 volumio-higole-x86 ntpd[1041]: statistics directory /var/log/ntpsec/ does not exist or is unwriteable, error No such file or directory
Sep 07 16:32:00 volumio-higole-x86 ifplugd[1006]: Network Interface Plugging Daemon...start eth0...done.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Started getty@tty1.service - Getty on tty1.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Reached target getty.target - Login Prompts.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Started ifplugd.service - LSB: Brings up/down network automatically.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: setdatetime-helper.service: Deactivated successfully.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Started systemd-timedated.service - Time & Date Service.
Sep 07 16:32:00 volumio-higole-x86 loadcpufreq[971]: Loading cpufreq kernel modules...done (acpi-cpufreq).
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Started loadcpufreq.service - LSB: Load kernel modules needed to enable cpufreq scaling.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Starting cpufrequtils.service - LSB: set CPUFreq kernel parameters...
Sep 07 16:32:00 volumio-higole-x86 sudo[1008]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Sep 07 16:32:00 volumio-higole-x86 sudo[1008]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Sep 07 16:32:00 volumio-higole-x86 sudo[1099]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory
Sep 07 16:32:00 volumio-higole-x86 sudo[1008]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:00 volumio-higole-x86 cpufrequtils[1096]: CPUFreq Utilities: Setting ondemand CPUFreq governor...disabled, governor not available...done.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Started cpufrequtils.service - LSB: set CPUFreq kernel parameters.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: samba-ad-dc.service: Skipped due to 'exec-condition'.
Sep 07 16:32:00 volumio-higole-x86 systemd[1]: Condition check resulted in samba-ad-dc.service - Samba AD Daemon being skipped.
Sep 07 16:32:00 volumio-higole-x86 avahi-daemon[834]: Server startup complete. Host name is volumio-higole-x86.local. Local service cookie is 192852720.
Sep 07 16:32:01 volumio-higole-x86 sudo[1132]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0
Sep 07 16:32:01 volumio-higole-x86 sudo[1132]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Sep 07 16:32:01 volumio-higole-x86 sudo[1132]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:01 volumio-higole-x86 sudo[1134]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down
Sep 07 16:32:01 volumio-higole-x86 sudo[1134]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Sep 07 16:32:01 volumio-higole-x86 sudo[1134]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:01 volumio-higole-x86 nmbd[1130]: [2025/09/07 16:32:01.102717, 0] ../../source3/nmbd/nmbd.c:901(main)
Sep 07 16:32:01 volumio-higole-x86 nmbd[1130]: nmbd version 4.17.12-Debian started.
Sep 07 16:32:01 volumio-higole-x86 nmbd[1130]: Copyright Andrew Tridgell and the Samba Team 1992-2022
Sep 07 16:32:01 volumio-higole-x86 nmbd[1130]: [2025/09/07 16:32:01.112480, 0] ../../source3/nmbd/asyncdns.c:158(start_async_dns)
Sep 07 16:32:01 volumio-higole-x86 nmbd[1130]: started asyncdns process 1140
Sep 07 16:32:01 volumio-higole-x86 nmbd[1130]: [2025/09/07 16:32:01.112967, 0] ../../lib/util/become_daemon.c:150(daemon_status)
Sep 07 16:32:01 volumio-higole-x86 nmbd[1130]: daemon_status: daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ...
Sep 07 16:32:01 volumio-higole-x86 nmbd[1130]: [2025/09/07 16:32:01.112992, 0] ../../source3/nmbd/nmbd_subnetdb.c:252(create_subnets)
Sep 07 16:32:01 volumio-higole-x86 nmbd[1130]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6).
Sep 07 16:32:01 volumio-higole-x86 sudo[1143]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up
Sep 07 16:32:01 volumio-higole-x86 sudo[1143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:01 volumio-higole-x86 ntpd[1041]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101
Sep 07 16:32:01 volumio-higole-x86 ntpd[1041]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101
Sep 07 16:32:01 volumio-higole-x86 ntpd[1041]: DNS: dns_check: DNS error: -11, System error
Sep 07 16:32:01 volumio-higole-x86 ntpd[1041]: DNS: dns_take_status: 0.debian.pool.ntp.org=>error, 12
Sep 07 16:32:01 volumio-higole-x86 sudo[1143]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:01 volumio-higole-x86 sudo[1146]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get
Sep 07 16:32:01 volumio-higole-x86 sudo[1146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:01 volumio-higole-x86 sudo[1146]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:01 volumio-higole-x86 sudo[1154]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up
Sep 07 16:32:01 volumio-higole-x86 sudo[1154]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:01 volumio-higole-x86 sudo[1154]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:01 volumio-higole-x86 sudo[1156]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan
Sep 07 16:32:01 volumio-higole-x86 sudo[1156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:01 volumio-higole-x86 avahi-daemon[834]: Service "Volumio-higole-x86" (/services/volumio.service) successfully established.
Sep 07 16:32:01 volumio-higole-x86 mpd[1101]: 2025-09-07T16:32:01 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Sep 07 16:32:01 volumio-higole-x86 systemd[1]: Started mpd.service - Music Player Daemon.
Sep 07 16:32:01 volumio-higole-x86 mpd_monitor.sh[843]: MPD Monitor Service: MPD restarted due to no mpc output.
Sep 07 16:32:02 volumio-higole-x86 ntpd[1041]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101
Sep 07 16:32:02 volumio-higole-x86 ntpd[1041]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101
Sep 07 16:32:02 volumio-higole-x86 ntpd[1041]: DNS: dns_check: DNS error: -11, System error
Sep 07 16:32:02 volumio-higole-x86 ntpd[1041]: DNS: dns_take_status: 1.debian.pool.ntp.org=>error, 12
Sep 07 16:32:03 volumio-higole-x86 dhcpcd[817]: eth0: carrier acquired
Sep 07 16:32:03 volumio-higole-x86 sh[797]: eth0: carrier acquired
Sep 07 16:32:03 volumio-higole-x86 dhcpcd[869]: eth0: carrier acquired
Sep 07 16:32:03 volumio-higole-x86 kernel: r8169 0000:01:00.0 eth0: Link is Up - 1Gbps/Full - flow control rx/tx
Sep 07 16:32:03 volumio-higole-x86 dhcpcd[817]: eth0: IAID 5d:b8:8e:9a
Sep 07 16:32:03 volumio-higole-x86 sh[797]: eth0: IAID 5d:b8:8e:9a
Sep 07 16:32:03 volumio-higole-x86 dhcpcd[869]: eth0: IAID 5d:b8:8e:9a
Sep 07 16:32:03 volumio-higole-x86 dhcpcd[869]: eth0: soliciting a DHCP lease
Sep 07 16:32:03 volumio-higole-x86 dhcpcd[869]: eth0: offered 192.168.1.92 from 192.168.1.1
Sep 07 16:32:03 volumio-higole-x86 dhcpcd[869]: eth0: probing address 192.168.1.92/24
Sep 07 16:32:03 volumio-higole-x86 ntpd[1041]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101
Sep 07 16:32:03 volumio-higole-x86 ntpd[1041]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101
Sep 07 16:32:03 volumio-higole-x86 ntpd[1041]: DNS: dns_check: DNS error: -11, System error
Sep 07 16:32:03 volumio-higole-x86 ntpd[1041]: DNS: dns_take_status: 2.debian.pool.ntp.org=>error, 12
Sep 07 16:32:03 volumio-higole-x86 ifplugd(eth0)[1057]: Link beat detected.
Sep 07 16:32:03 volumio-higole-x86 ifplugd(eth0)[1057]: Executing '/etc/ifplugd/ifplugd.action eth0 up'.
Sep 07 16:32:03 volumio-higole-x86 ifplugd(eth0)[1057]: client: ifup: waiting for lock on /run/network/ifstate.eth0
Sep 07 16:32:03 volumio-higole-x86 dhcpcd[869]: eth0: soliciting an IPv6 router
Sep 07 16:32:04 volumio-higole-x86 systemd[1]: systemd-rfkill.service: Deactivated successfully.
Sep 07 16:32:04 volumio-higole-x86 dhcpcd[817]: eth0: soliciting an IPv6 router
Sep 07 16:32:04 volumio-higole-x86 sh[797]: eth0: soliciting an IPv6 router
Sep 07 16:32:04 volumio-higole-x86 ntpd[1041]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101
Sep 07 16:32:04 volumio-higole-x86 ntpd[1041]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101
Sep 07 16:32:04 volumio-higole-x86 ntpd[1041]: DNS: dns_check: DNS error: -11, System error
Sep 07 16:32:04 volumio-higole-x86 ntpd[1041]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12
Sep 07 16:32:04 volumio-higole-x86 dhcpcd[817]: eth0: soliciting a DHCP lease
Sep 07 16:32:04 volumio-higole-x86 sh[797]: eth0: soliciting a DHCP lease
Sep 07 16:32:04 volumio-higole-x86 sh[797]: eth0: offered 192.168.1.92 from 192.168.1.1
Sep 07 16:32:04 volumio-higole-x86 dhcpcd[817]: eth0: offered 192.168.1.92 from 192.168.1.1
Sep 07 16:32:04 volumio-higole-x86 sh[797]: eth0: probing address 192.168.1.92/24
Sep 07 16:32:04 volumio-higole-x86 dhcpcd[817]: eth0: probing address 192.168.1.92/24
Sep 07 16:32:05 volumio-higole-x86 volumio-remote-updater[852]: [2025-09-07 16:32:05] [info] asio async_connect error: asio.system:111 (Connection refused)
Sep 07 16:32:05 volumio-higole-x86 volumio-remote-updater[852]: [2025-09-07 16:32:05] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected)
Sep 07 16:32:05 volumio-higole-x86 volumio-remote-updater[852]: [2025-09-07 16:32:05] [error] handle_connect error: Connection refused
Sep 07 16:32:06 volumio-higole-x86 sudo[1156]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:06 volumio-higole-x86 sudo[1179]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up
Sep 07 16:32:06 volumio-higole-x86 sudo[1179]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:06 volumio-higole-x86 sudo[1179]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:06 volumio-higole-x86 sudo[1181]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set DE
Sep 07 16:32:06 volumio-higole-x86 sudo[1181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:06 volumio-higole-x86 sudo[1181]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:06 volumio-higole-x86 sudo[1188]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0
Sep 07 16:32:06 volumio-higole-x86 sudo[1188]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Sep 07 16:32:06 volumio-higole-x86 sudo[1188]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:06 volumio-higole-x86 sudo[1190]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down
Sep 07 16:32:06 volumio-higole-x86 sudo[1190]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Sep 07 16:32:06 volumio-higole-x86 sudo[1190]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:06 volumio-higole-x86 systemd[1]: welcome.service: Deactivated successfully.
Sep 07 16:32:06 volumio-higole-x86 systemd[1]: Stopped welcome.service - Show a welcome message on console.
Sep 07 16:32:06 volumio-higole-x86 systemd[1]: Stopping welcome.service - Show a welcome message on console...
Sep 07 16:32:06 volumio-higole-x86 systemd[1]: Starting welcome.service - Show a welcome message on console...
Sep 07 16:32:06 volumio-higole-x86 avahi-daemon[834]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1.
Sep 07 16:32:06 volumio-higole-x86 avahi-daemon[834]: New relevant interface wlan0.IPv4 for mDNS.
Sep 07 16:32:06 volumio-higole-x86 avahi-daemon[834]: Registering new address record for 192.168.211.1 on wlan0.IPv4.
Sep 07 16:32:06 volumio-higole-x86 welcome[1195]: Resolved ip:[1] 192.168.211.1
Sep 07 16:32:06 volumio-higole-x86 systemd[1]: Started nmbd.service - Samba NMB Daemon.
Sep 07 16:32:06 volumio-higole-x86 systemd[1]: Finished welcome.service - Show a welcome message on console.
Sep 07 16:32:06 volumio-higole-x86 systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0.
Sep 07 16:32:06 volumio-higole-x86 systemd[1]: Starting winbind.service - Samba Winbind Daemon...
Sep 07 16:32:06 volumio-higole-x86 systemd[1]: Starting hostapd.service - Access point and authentication server for Wi-Fi and Ethernet...
Sep 07 16:32:06 volumio-higole-x86 winbindd[1206]: [2025/09/07 16:32:06.764007, 0] ../../source3/winbindd/winbindd.c:1440(main)
Sep 07 16:32:06 volumio-higole-x86 winbindd[1206]: winbindd version 4.17.12-Debian started.
Sep 07 16:32:06 volumio-higole-x86 winbindd[1206]: Copyright Andrew Tridgell and the Samba Team 1992-2022
Sep 07 16:32:06 volumio-higole-x86 winbindd[1206]: [2025/09/07 16:32:06.770095, 0] ../../source3/winbindd/winbindd_cache.c:3117(initialize_winbindd_cache)
Sep 07 16:32:06 volumio-higole-x86 winbindd[1206]: initialize_winbindd_cache: clearing cache and re-creating with version number 2
Sep 07 16:32:06 volumio-higole-x86 systemd[1]: Started winbind.service - Samba Winbind Daemon.
Sep 07 16:32:06 volumio-higole-x86 systemd[1]: Starting smbd.service - Samba SMB Daemon...
Sep 07 16:32:06 volumio-higole-x86 smbd[1215]: [2025/09/07 16:32:06.933378, 0] ../../source3/smbd/server.c:1741(main)
Sep 07 16:32:06 volumio-higole-x86 smbd[1215]: smbd version 4.17.12-Debian started.
Sep 07 16:32:06 volumio-higole-x86 smbd[1215]: Copyright Andrew Tridgell and the Samba Team 1992-2022
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: Started smbd.service - Samba SMB Daemon.
Sep 07 16:32:07 volumio-higole-x86 dhcpcd[869]: wlan0: carrier acquired
Sep 07 16:32:07 volumio-higole-x86 hostapd[1205]: wlan0: interface state UNINITIALIZED->ENABLED
Sep 07 16:32:07 volumio-higole-x86 hostapd[1205]: wlan0: AP-ENABLED
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: Started hostapd.service - Access point and authentication server for Wi-Fi and Ethernet.
Sep 07 16:32:07 volumio-higole-x86 dhcpcd[869]: wlan0: IAID 2b:f7:76:9f
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: Starting dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server...
Sep 07 16:32:07 volumio-higole-x86 iwconfig[1235]: Error for wireless request "Set Power Management" (8B2C) :
Sep 07 16:32:07 volumio-higole-x86 iwconfig[1235]: SET failed on device wlan0 ; Invalid argument.
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: wireless.service: Deactivated successfully.
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: Started wireless.service - Wireless Services.
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: Started volumio.service - Volumio Backend Module.
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: Started screenshot.service - Process screenshots triggered by PrtSc-button.
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: Started soundcard-init.service - Intel SST and HDA soundcard init service.
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: Started volumio-kiosk.service - Start Volumio Kiosk.
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker.
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: Reached target multi-user.target - Multi-User System.
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: Reached target graphical.target - Graphical Interface.
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP...
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully.
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP.
Sep 07 16:32:07 volumio-higole-x86 volumio-cpu-tweak[1242]: Setting RT Priority for mpd
Sep 07 16:32:07 volumio-higole-x86 dnsmasq[1278]: started, version 2.90 cachesize 150
Sep 07 16:32:07 volumio-higole-x86 dnsmasq[1278]: compile time options: IPv6 GNU-getopt DBus no-UBus i18n IDN2 DHCP DHCPv6 no-Lua TFTP conntrack ipset nftset auth cryptohash DNSSEC loop-detect inotify dumpfile
Sep 07 16:32:07 volumio-higole-x86 dnsmasq-dhcp[1278]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d
Sep 07 16:32:07 volumio-higole-x86 dnsmasq[1278]: reading /etc/resolv.conf
Sep 07 16:32:07 volumio-higole-x86 dnsmasq[1278]: using nameserver 208.67.222.222#53
Sep 07 16:32:07 volumio-higole-x86 dnsmasq[1278]: using nameserver 208.67.220.220#53
Sep 07 16:32:07 volumio-higole-x86 dnsmasq[1278]: read /etc/hosts - 4 names
Sep 07 16:32:07 volumio-higole-x86 volumio-cpu-tweak[1242]: Setting MPD Affinity
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: Started dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server.
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups.
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: Startup finished in 6.927s (firmware) + 2.430s (loader) + 10.815s (kernel) + 9.416s (userspace) = 29.589s.
Sep 07 16:32:07 volumio-higole-x86 volumio-cpu-tweak[1284]: pid 1101's current affinity mask: f
Sep 07 16:32:07 volumio-higole-x86 volumio-cpu-tweak[1284]: pid 1101's new affinity mask: 3
Sep 07 16:32:07 volumio-higole-x86 volumio-cpu-tweak[1242]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: volumio_cpu_tweak.service: Deactivated successfully.
Sep 07 16:32:07 volumio-higole-x86 startx[1311]: X.Org X Server 1.21.1.7
Sep 07 16:32:07 volumio-higole-x86 startx[1311]: X Protocol Version 11, Revision 0
Sep 07 16:32:07 volumio-higole-x86 startx[1311]: Current Operating System: Linux volumio-higole-x86 6.12.35-volumio #14.44 SMP PREEMPT_DYNAMIC Fri Jul 4 14:52:54 CEST 2025 x86_64
Sep 07 16:32:07 volumio-higole-x86 startx[1311]: Kernel command line: BOOT_IMAGE=/vmlinuz initramfs.clear splash plymouth.ignore-serial-consoles quiet loglevel=0 bootdelay=5 biosdevname=0 imgpart=UUID=c416cc9d-1a7a-499f-ac37-78337eedbb1c bootpart=UUID=3831-C55C datapart=UUID=44cf684b-88eb-4fbf-8b1b-3620c1c9961d 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 07 16:32:07 volumio-higole-x86 startx[1311]: xorg-server 2:21.1.7-3+deb12u9 (https://www.debian.org/support)
Sep 07 16:32:07 volumio-higole-x86 startx[1311]: Current version of pixman: 0.42.2
Sep 07 16:32:07 volumio-higole-x86 startx[1311]: Before reporting problems, check http://wiki.x.org
Sep 07 16:32:07 volumio-higole-x86 startx[1311]: to make sure that you have the latest version.
Sep 07 16:32:07 volumio-higole-x86 startx[1311]: Markers: (--) probed, (**) from config file, (==) default setting,
Sep 07 16:32:07 volumio-higole-x86 startx[1311]: (++) from command line, (!!) notice, (II) informational,
Sep 07 16:32:07 volumio-higole-x86 startx[1311]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown.
Sep 07 16:32:07 volumio-higole-x86 startx[1311]: (==) Log file: "/var/log/Xorg.0.log", Time: Sun Sep 7 16:32:07 2025
Sep 07 16:32:07 volumio-higole-x86 startx[1311]: (==) Using system config directory "/usr/share/X11/xorg.conf.d"
Sep 07 16:32:07 volumio-higole-x86 soundcard-init.sh[1321]: Card 0 Chip Realtek ALC269VB Name HDA Intel PCH
Sep 07 16:32:07 volumio-higole-x86 soundcard-init.sh[1333]: Simple mixer control 'Master',0
Sep 07 16:32:07 volumio-higole-x86 soundcard-init.sh[1333]: Capabilities: pvolume pvolume-joined pswitch pswitch-joined
Sep 07 16:32:07 volumio-higole-x86 soundcard-init.sh[1333]: Playback channels: Mono
Sep 07 16:32:07 volumio-higole-x86 soundcard-init.sh[1333]: Limits: Playback 0 - 87
Sep 07 16:32:07 volumio-higole-x86 soundcard-init.sh[1333]: Mono: Playback 65 [75%] [-16.50dB] [on]
Sep 07 16:32:07 volumio-higole-x86 systemd[1]: soundcard-init.service: Deactivated successfully.
Sep 07 16:32:08 volumio-higole-x86 dhcpcd[869]: wlan0: soliciting an IPv6 router
Sep 07 16:32:08 volumio-higole-x86 dhcpcd[869]: wlan0: soliciting a DHCP lease
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: -------------------------------------------
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: ----- Volumio3 ----
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: -------------------------------------------
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: ----- System startup ----
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: -------------------------------------------
Sep 07 16:32:08 volumio-higole-x86 ntpd[1041]: IO: Listen normally on 3 wlan0 192.168.211.1:123
Sep 07 16:32:08 volumio-higole-x86 ntpd[1041]: IO: new interface(s) found: waking up resolver
Sep 07 16:32:08 volumio-higole-x86 ntpd[1041]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101
Sep 07 16:32:08 volumio-higole-x86 ntpd[1041]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101
Sep 07 16:32:08 volumio-higole-x86 ntpd[1041]: DNS: dns_check: DNS error: -11, System error
Sep 07 16:32:08 volumio-higole-x86 ntpd[1041]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: MYVOLUMIO Environment detected
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: Plugin folders cleanup
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: Scanning into folder /volumio/app/plugins/
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: Scanning category audio_interface
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: Scanning category miscellanea
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: Scanning category music_service
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: Scanning category plugins.json
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: Scanning category system_controller
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: Scanning category user_interface
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: Scanning into folder /data/plugins/
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: Scanning category user_interface
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: Plugin folders cleanup completed
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: -------------------------------------------
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: ----- Core plugins startup ----
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: -------------------------------------------
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: Loading plugins from folder /volumio/app/plugins/
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: Adding plugin upnp to MyMusic Plugins
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: Adding plugin airplay_emulation to MyMusic Plugins
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: Adding plugin upnp_browser to MyMusic Plugins
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: Loading plugins from folder /data/plugins/
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: Loading plugin "system"...
Sep 07 16:32:08 volumio-higole-x86 volumio[1237]: info: Loading plugin "appearance"...
Sep 07 16:32:08 volumio-higole-x86 dhcpcd[869]: eth0: leased 192.168.1.92 for 86400 seconds
Sep 07 16:32:08 volumio-higole-x86 avahi-daemon[834]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.92.
Sep 07 16:32:08 volumio-higole-x86 avahi-daemon[834]: New relevant interface eth0.IPv4 for mDNS.
Sep 07 16:32:08 volumio-higole-x86 avahi-daemon[834]: Registering new address record for 192.168.1.92 on eth0.IPv4.
Sep 07 16:32:08 volumio-higole-x86 dhcpcd[869]: eth0: adding route to 192.168.1.0/24
Sep 07 16:32:08 volumio-higole-x86 dhcpcd[869]: eth0: adding default route via 192.168.1.1
Sep 07 16:32:08 volumio-higole-x86 systemd[1]: welcome.service: Deactivated successfully.
Sep 07 16:32:08 volumio-higole-x86 systemd[1]: Stopped welcome.service - Show a welcome message on console.
Sep 07 16:32:08 volumio-higole-x86 systemd[1]: Stopping welcome.service - Show a welcome message on console...
Sep 07 16:32:08 volumio-higole-x86 dnsmasq[1278]: reading /etc/resolv.conf
Sep 07 16:32:08 volumio-higole-x86 dnsmasq[1278]: using nameserver 192.168.1.1#53
Sep 07 16:32:08 volumio-higole-x86 dnsmasq[1278]: using nameserver 208.67.222.222#53
Sep 07 16:32:08 volumio-higole-x86 dnsmasq[1278]: using nameserver 208.67.220.220#53
Sep 07 16:32:09 volumio-higole-x86 systemd[1]: Starting welcome.service - Show a welcome message on console...
Sep 07 16:32:09 volumio-higole-x86 welcome[1383]: Resolved ip:[2] 192.168.1.92 192.168.211.1
Sep 07 16:32:09 volumio-higole-x86 systemd[1]: Finished welcome.service - Show a welcome message on console.
Sep 07 16:32:09 volumio-higole-x86 systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: Loading plugin "network"...
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: Refreshing Cached IP Addresses
Sep 07 16:32:09 volumio-higole-x86 sudo[1447]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Sep 07 16:32:09 volumio-higole-x86 sudo[1447]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:09 volumio-higole-x86 sudo[1447]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:09 volumio-higole-x86 sudo[1449]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 07 16:32:09 volumio-higole-x86 sudo[1449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: Loading plugin "services"...
Sep 07 16:32:09 volumio-higole-x86 sudo[1449]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: Loading plugin "alsa_controller"...
Sep 07 16:32:09 volumio-higole-x86 sudo[1463]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Sep 07 16:32:09 volumio-higole-x86 sudo[1463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: Loading plugin "wizard"...
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: Loading plugin "networkfs"...
Sep 07 16:32:09 volumio-higole-x86 ntpd[1041]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: Starting Udev Watcher for removable devices
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: Ignoring mount for partition: boot
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: Ignoring mount for partition: volumio
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: Ignoring mount for partition: volumio_data
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: Ignoring mount for partition: SYSTEM
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: error: Cannot associate FS Label, not mounting
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: Ignoring mount for partition: Windows
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: Ignoring mount for partition: Recovery
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: Loading plugin "volumio_command_line_client"...
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: Loading plugin "upnp"...
Sep 07 16:32:09 volumio-higole-x86 ntpd[1041]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101
Sep 07 16:32:09 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 82.67.41.119
Sep 07 16:32:09 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 82.64.81.218
Sep 07 16:32:09 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 141.95.171.142
Sep 07 16:32:09 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 91.194.60.128
Sep 07 16:32:09 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 2a0c:8881:5:3b::1
Sep 07 16:32:09 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 2001:41d0:801:2000::acb
Sep 07 16:32:09 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 2001:41d0:2:c837::123
Sep 07 16:32:09 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 2001:41d0:305:2100::621
Sep 07 16:32:09 volumio-higole-x86 ntpd[1041]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: [1757255529580] Starting Upmpd Daemon
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: Loading plugin "my_music"...
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: Loading plugin "mpd"...
Sep 07 16:32:09 volumio-higole-x86 volumio[1237]: info: Loading plugin "upnp_browser"...
Sep 07 16:32:10 volumio-higole-x86 dhcpcd[817]: eth0: leased 192.168.1.92 for 86400 seconds
Sep 07 16:32:10 volumio-higole-x86 sh[797]: eth0: leased 192.168.1.92 for 86400 seconds
Sep 07 16:32:10 volumio-higole-x86 systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Sep 07 16:32:10 volumio-higole-x86 systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Sep 07 16:32:10 volumio-higole-x86 systemd[1]: welcome.service: Deactivated successfully.
Sep 07 16:32:10 volumio-higole-x86 systemd[1]: Stopped welcome.service - Show a welcome message on console.
Sep 07 16:32:10 volumio-higole-x86 systemd[1]: Stopping welcome.service - Show a welcome message on console...
Sep 07 16:32:10 volumio-higole-x86 sh[797]: eth0: adding route to 192.168.1.0/24
Sep 07 16:32:10 volumio-higole-x86 sh[797]: forked to background, child pid 816
Sep 07 16:32:10 volumio-higole-x86 sh[797]: eth0: adding default route via 192.168.1.1
Sep 07 16:32:10 volumio-higole-x86 dhcpcd[817]: eth0: adding route to 192.168.1.0/24
Sep 07 16:32:10 volumio-higole-x86 dhcpcd[817]: eth0: adding default route via 192.168.1.1
Sep 07 16:32:10 volumio-higole-x86 systemd[1]: Starting welcome.service - Show a welcome message on console...
Sep 07 16:32:10 volumio-higole-x86 welcome[1528]: Resolved ip:[2] 192.168.1.92 192.168.211.1
Sep 07 16:32:10 volumio-higole-x86 systemd[1]: Finished welcome.service - Show a welcome message on console.
Sep 07 16:32:10 volumio-higole-x86 systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Sep 07 16:32:10 volumio-higole-x86 ifplugd(eth0)[1057]: client: ifup: interface eth0 already configured
Sep 07 16:32:10 volumio-higole-x86 sh[1567]: eth0=eth0
Sep 07 16:32:10 volumio-higole-x86 ifplugd(eth0)[1057]: Program executed successfully.
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Loading plugin "alarm-clock"...
Sep 07 16:32:10 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:32:10 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:32:10 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:32:10 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Loading plugin "airplay_emulation"...
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Starting Shairport Sync
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Loading plugin "last_100"...
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Loading plugin "webradio"...
Sep 07 16:32:10 volumio-higole-x86 ntpd[1041]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Loading plugin "i2s_dacs"...
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: I2S DAC not set, start Auto-detection
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Loading plugin "volumiodiscovery"...
Sep 07 16:32:10 volumio-higole-x86 ntpd[1041]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101
Sep 07 16:32:10 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 45.90.162.253
Sep 07 16:32:10 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 37.59.63.125
Sep 07 16:32:10 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 94.23.45.103
Sep 07 16:32:10 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 82.64.84.116
Sep 07 16:32:10 volumio-higole-x86 ntpd[1041]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: *** WARNING *** For more information see
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: *** WARNING *** For more information see
Sep 07 16:32:10 volumio-higole-x86 node[1237]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Sep 07 16:32:10 volumio-higole-x86 node[1237]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 07 16:32:10 volumio-higole-x86 node[1237]: *** WARNING *** For more information see
Sep 07 16:32:10 volumio-higole-x86 node[1237]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Sep 07 16:32:10 volumio-higole-x86 node[1237]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 07 16:32:10 volumio-higole-x86 node[1237]: *** WARNING *** For more information see
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Applying required configuration parameters for plugin volumiodiscovery
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Discovery: Started advertising with name: Volumio-higole-x86
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Loading plugin "outputs"...
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Loading plugin "albumart"...
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Plugin example_plugin is not enabled
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Loading plugin "inputs"...
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Loading plugin "updater_comm"...
Sep 07 16:32:10 volumio-higole-x86 volumio[1572]: Forking 3 albumart workers
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Plugin mpdemulation is not enabled
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Loading plugin "rest_api"...
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Loading plugin "websocket"...
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Starting Socket.io Server version 1.7.4
Sep 07 16:32:10 volumio-higole-x86 volumio[1237]: info: Loading plugin "vkiosksettings"...
Sep 07 16:32:10 volumio-higole-x86 volumio[1583]: Starting albumart workers
Sep 07 16:32:10 volumio-higole-x86 volumio[1582]: Starting albumart workers
Sep 07 16:32:10 volumio-higole-x86 volumio[1584]: Starting albumart workers
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: Loading i18n strings for locale en
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: Updating browse sources language
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 07 16:32:11 volumio-higole-x86 ntpd[1041]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101
Sep 07 16:32:11 volumio-higole-x86 ntpd[1041]: IO: Listen normally on 4 eth0 192.168.1.92:123
Sep 07 16:32:11 volumio-higole-x86 ntpd[1041]: PROTO: 82.64.84.116 unlink local addr 192.168.211.1 -> 192.168.1.92
Sep 07 16:32:11 volumio-higole-x86 ntpd[1041]: PROTO: 94.23.45.103 unlink local addr 192.168.211.1 -> 192.168.1.92
Sep 07 16:32:11 volumio-higole-x86 ntpd[1041]: PROTO: 37.59.63.125 unlink local addr 192.168.211.1 -> 192.168.1.92
Sep 07 16:32:11 volumio-higole-x86 ntpd[1041]: PROTO: 45.90.162.253 unlink local addr 192.168.211.1 -> 192.168.1.92
Sep 07 16:32:11 volumio-higole-x86 ntpd[1041]: PROTO: 91.194.60.128 unlink local addr 192.168.211.1 -> 192.168.1.92
Sep 07 16:32:11 volumio-higole-x86 ntpd[1041]: PROTO: 141.95.171.142 unlink local addr 192.168.211.1 -> 192.168.1.92
Sep 07 16:32:11 volumio-higole-x86 ntpd[1041]: PROTO: 82.64.81.218 unlink local addr 192.168.211.1 -> 192.168.1.92
Sep 07 16:32:11 volumio-higole-x86 ntpd[1041]: PROTO: 82.67.41.119 unlink local addr 192.168.211.1 -> 192.168.1.92
Sep 07 16:32:11 volumio-higole-x86 ntpd[1041]: IO: new interface(s) found: waking up resolver
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::initPlayerControls
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: Express server listening on port 3000
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: [Metrics] WebUI: 3s 389.72ms
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: Setting Device type: x86
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreStateMachine::resetVolumioState
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreStateMachine::getcurrentVolume
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioRetrievevolume
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt'
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: Completed loading Core Plugins
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: Preparing to generate the ALSA configuration file
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: Volumio Network Manager: Network status updated: 1
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: verbose: New Socket.io Connection to 192.168.1.92 from 192.168.1.50 UA: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:142.0) Gecko/20100101 Firefox/142.0 Engine version: 3 Transport: polling Total Clients: 1
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: verbose: New Socket.io Connection to 192.168.1.92 from 192.168.1.50 UA: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:142.0) Gecko/20100101 Firefox/142.0 Engine version: 3 Transport: polling Total Clients: 2
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: VolumeController:: Volume=49 Mute =false
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreStateMachine::pushState
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioPushState
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreStateMachine::updateTrackBlock
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrackBlock
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioRetrievevolume
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: Reloading queue from file
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: verbose: New Socket.io Connection to 192.168.1.92 from 192.168.1.50 UA: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:142.0) Gecko/20100101 Firefox/142.0 Engine version: 3 Transport: polling Total Clients: 3
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreStateMachine::setRepeat null single undefined
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreStateMachine::pushState
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioPushState
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreStateMachine::setRandom null
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreStateMachine::pushState
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioPushState
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: verbose: New Socket.io Connection to 192.168.1.92 from 192.168.1.50 UA: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:142.0) Gecko/20100101 Firefox/142.0 Engine version: 3 Transport: polling Total Clients: 4
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: verbose: New Socket.io Connection to 192.168.1.92 from 192.168.1.50 UA: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:142.0) Gecko/20100101 Firefox/142.0 Engine version: 3 Transport: polling Total Clients: 5
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: verbose: New Socket.io Connection to 192.168.1.92 from 192.168.1.50 UA: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:142.0) Gecko/20100101 Firefox/142.0 Engine version: 3 Transport: polling Total Clients: 6
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: VolumeController:: Volume=49 Mute =false
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreStateMachine::pushState
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioPushState
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: Asound.conf file written
Sep 07 16:32:11 volumio-higole-x86 sudo[1656]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf
Sep 07 16:32:11 volumio-higole-x86 sudo[1656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:11 volumio-higole-x86 sudo[1656]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: Output device has changed, restarting MPD
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: Output device has changed, restarting Shairport Sync
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 sudo[1668]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Sep 07 16:32:11 volumio-higole-x86 sudo[1668]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:11 volumio-higole-x86 sudo[1673]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Sep 07 16:32:11 volumio-higole-x86 sudo[1668]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:11 volumio-higole-x86 sudo[1673]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: ___________ START PLUGINS ___________
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: ControllerMpd::onStart: Initializing MPD
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: Creating MPD Configuration file
Sep 07 16:32:11 volumio-higole-x86 systemd[1]: Stopping mpd.service - Music Player Daemon...
Sep 07 16:32:11 volumio-higole-x86 sudo[1681]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 sudo[1681]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: [1757255531700] CoreMusicLibrary::Adding element Media Servers
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 07 16:32:11 volumio-higole-x86 sudo[1681]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:11 volumio-higole-x86 sudo[1683]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Sep 07 16:32:11 volumio-higole-x86 sudo[1683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: [1757255531722] CoreMusicLibrary::Adding element Last_100
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: [1757255531723] CoreMusicLibrary::Adding element Webradio
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: Initializing BBC Radios
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: Volumio Calling Home
Sep 07 16:32:11 volumio-higole-x86 sudo[1709]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/bash -c 'if [ -f /root/.Xauthority ]; then cp /root/.Xauthority /home/volumio/ && chown volumio:volumio /home/volumio/.Xauthority; fi'
Sep 07 16:32:11 volumio-higole-x86 sudo[1709]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:11 volumio-higole-x86 sudo[1709]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:11 volumio-higole-x86 systemd[1]: mpd.service: Deactivated successfully.
Sep 07 16:32:11 volumio-higole-x86 systemd[1]: Stopped mpd.service - Music Player Daemon.
Sep 07 16:32:11 volumio-higole-x86 systemd[1]: mpd.socket: Deactivated successfully.
Sep 07 16:32:11 volumio-higole-x86 systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Sep 07 16:32:11 volumio-higole-x86 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Sep 07 16:32:11 volumio-higole-x86 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Sep 07 16:32:11 volumio-higole-x86 systemd[1]: Starting mpd.service - Music Player Daemon...
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: Discovery: adding 5eab55da-ff4e-4cb0-b17f-14ae9bbd3780
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: Discovery: Found device Volumio-higole-x86
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: vkiosksettings --- fixXauthority: /home/volumio/.Xauthority updated
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: MPD Permissions set
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: MPD Permissions set
Sep 07 16:32:11 volumio-higole-x86 sudo[1717]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Sep 07 16:32:11 volumio-higole-x86 sudo[1717]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Sep 07 16:32:11 volumio-higole-x86 sudo[1717]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: verbose: New Socket.io Connection to 192.168.1.92:3000 from 192.168.1.38 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:11 volumio-higole-x86 volumio[1237]: verbose: New Socket.io Connection to 192.168.1.92:3000 from 192.168.1.24 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: verbose: New Socket.io Connection to 192.168.1.92:3000 from 192.168.1.77 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Starting Shairport Sync
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Starting Shairport Sync
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Starting Shairport Sync
Sep 07 16:32:12 volumio-higole-x86 sudo[1745]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Sep 07 16:32:12 volumio-higole-x86 sudo[1749]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Sep 07 16:32:12 volumio-higole-x86 sudo[1747]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Sep 07 16:32:12 volumio-higole-x86 sudo[1749]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:12 volumio-higole-x86 sudo[1747]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:12 volumio-higole-x86 sudo[1745]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11
Sep 07 16:32:12 volumio-higole-x86 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Sep 07 16:32:12 volumio-higole-x86 systemd[1]: shairport-sync.service: Deactivated successfully.
Sep 07 16:32:12 volumio-higole-x86 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Sep 07 16:32:12 volumio-higole-x86 systemd[1]: shairport-sync.service: Consumed 1.651s CPU time.
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Received Get System Info
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Discovery: Getting this device information
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetVisibleSources
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Received Get System Info
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Discovery: Getting this device information
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Listing playlists
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:12 volumio-higole-x86 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Discovery: adding c8d9e3d6-fa93-49b0-9dc2-577f68689abf
Sep 07 16:32:12 volumio-higole-x86 sudo[1749]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:12 volumio-higole-x86 sudo[1745]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:12 volumio-higole-x86 sudo[1747]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Discovery: Found device Integro-office
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Discovery: Connecting to remote: 192.168.1.38
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Volumio called home
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Shairport-Sync Started
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: Error adding Membership: Error: addMembership EINVAL
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Shairport-Sync Started
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Shairport-Sync Started
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Discovery: Connected to remote: 192.168.1.38
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Discovery: this is already registered, 5eab55da-ff4e-4cb0-b17f-14ae9bbd3780
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Discovery: Found device Volumio-higole-x86
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Discovery: this is already registered, 5eab55da-ff4e-4cb0-b17f-14ae9bbd3780
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Discovery: Found device Volumio-higole-x86
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:12 volumio-higole-x86 mpd[1722]: 2025-09-07T16:32:12 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Sep 07 16:32:12 volumio-higole-x86 systemd[1]: Started mpd.service - Music Player Daemon.
Sep 07 16:32:12 volumio-higole-x86 sudo[1673]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:12 volumio-higole-x86 sudo[1683]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Completed starting Core Plugins
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: -------------------------------------------
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: ----- MyVolumio plugins startup ----
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: -------------------------------------------
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Fetching plans data....
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: MPD running with PID1722
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: ,establishing connection
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: error: MPD error: The expression evaluated to a falsy value:
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: assert.ok(self.idling)
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: error: The expression evaluated to a falsy value:
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: assert.ok(self.idling)
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: error: MPD error: The expression evaluated to a falsy value:
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: assert.ok(self.idling)
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: error: The expression evaluated to a falsy value:
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: assert.ok(self.idling)
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: error: updateQueue error: null
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Discovery: adding 89a86619-18ae-4300-a9bd-067abcfbd7d0
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Discovery: Found device Volumio-primo
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Discovery: Connecting to remote: 192.168.1.77
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Discovery: adding 3442be69-83bf-4678-9915-17f0c5223a5d
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Discovery: Found device Volumio-bwk5-rpi5
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Discovery: Connecting to remote: 192.168.1.24
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Discovery: Connected to remote: 192.168.1.77
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: Discovery: Connected to remote: 192.168.1.24
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:12 volumio-higole-x86 volumio-remote-updater[852]: [2025-09-07 16:32:12] [connect] Successful connection
Sep 07 16:32:12 volumio-higole-x86 volumio-remote-updater[852]: [2025-09-07 16:32:12] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1757255532 101
Sep 07 16:32:12 volumio-higole-x86 volumio[1237]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 12
Sep 07 16:32:12 volumio-higole-x86 sudo[1463]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:13 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:13 volumio-higole-x86 dhcpcd[869]: wlan0: probing for an IPv4LL address
Sep 07 16:32:13 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:13 volumio-higole-x86 volumio[1237]: 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/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 13
Sep 07 16:32:13 volumio-higole-x86 volumio[1237]: info: vkiosksettings --- Preparing playback state watcher...
Sep 07 16:32:13 volumio-higole-x86 volumio[1237]: info: vkiosksettings --- DPMS disabled before playback state check
Sep 07 16:32:13 volumio-higole-x86 volumio[1237]: info: vkiosksettings --- Touchscreens detected: [{"id":"13","name":"⎜ ↳ Goodix Capacitive TouchScreen"},{"id":"18","name":"↳ Goodix Capacitive TouchScreen"}]
Sep 07 16:32:13 volumio-higole-x86 volumio[1237]: info: vkiosksettings --- Detected touchscreen: 13
Sep 07 16:32:13 volumio-higole-x86 volumio[1237]: info: vkiosksettings --- xscreensaver stopped
Sep 07 16:32:13 volumio-higole-x86 volumio[1237]: info: vkiosksettings --- Connected screens: DSI-1
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: 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/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 14
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetVisibleSources
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetQueue
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CoreStateMachine::getQueue
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getQueue
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: Listing playlists
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: Received Get System Info
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: Discovery: Getting this device information
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Sep 07 16:32:14 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:15 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:15 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:15 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard
Sep 07 16:32:15 volumio-higole-x86 kernel: i915 0000:00:02.0: [drm] *ERROR* DSI link not ready
Sep 07 16:32:15 volumio-higole-x86 kernel: ------------[ cut here ]------------
Sep 07 16:32:15 volumio-higole-x86 kernel: i915 0000:00:02.0: [drm] drm_WARN_ON(*data != seq_id)
Sep 07 16:32:15 volumio-higole-x86 kernel: WARNING: CPU: 3 PID: 1311 at drivers/gpu/drm/i915/display/intel_dsi_vbt.c:627 intel_dsi_vbt_exec_sequence+0x2da/0x2f0 [i915]
Sep 07 16:32:15 volumio-higole-x86 kernel: Modules linked in: nft_chain_nat xt_REDIRECT nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 nft_compat nf_tables libcrc32c cmac algif_hash algif_skcipher af_alg bnep nfnetlink sunrpc 8021q garp stp mrp llc binfmt_misc snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic snd_hda_scodec_component rtw88_8821ce rtw88_8821c rtw88_pci x86_pkg_temp_thermal intel_powerclamp rtw88_core snd_hda_intel coretemp mac80211 snd_intel_dspcfg snd_hda_codec snd_hda_core kvm_intel snd_hwdep btusb snd_pcm snd_seq btrtl btintel snd_seq_device btbcm libarc4 bluetooth kvm snd_timer cfg80211 processor_thermal_device_pci_legacy processor_thermal_device snd processor_thermal_wt_hint processor_thermal_rfim processor_thermal_rapl sha3_generic intel_rapl_common processor_thermal_wt_req jitterentropy_rng processor_thermal_power_floor soundcore processor_thermal_mbox int340x_thermal_zone intel_soc_dts_iosf irqbypass sha512_generic wmi_bmof crc32_pclmul aes_generic hmac aesni_intel mei_me gf128mul crypto_simd tpm_tis cryptd
Sep 07 16:32:15 volumio-higole-x86 kernel: drbg tpm_tis_core tpm goodix_ts ansi_cprng libaescfb soc_button_array ecdh_generic ecc intel_pmc_core rng_core libaes sg intel_vsec intel_hid joydev pmt_telemetry int3400_thermal pmt_class acpi_thermal_rel acpi_pad acpi_tad sparse_keymap input_leds serio_raw efi_pstore efivarfs dmi_sysfs ip_tables autofs4 loop ext4 crc32c_generic crc16 mbcache jbd2 sata_vsc sata_via sata_sx4 sata_svw sata_sis sata_sil sata_sil24 sata_qstor sata_promise sata_nv sata_mv pdc_adma pata_via pata_triflex pata_sil680 pata_serverworks pata_sch pata_rz1000 pata_rdc pata_piccolo pata_pdc202xx_old pata_pdc2027x pata_opti pata_oldpiix pata_ns87415 pata_ns87410 pata_ninja32 pata_netcell pata_mpiix pata_marvell pata_jmicron pata_it821x pata_it8213 pata_hpt37x pata_hpt366 pata_efar pata_cmd64x pata_atp867x pata_atiixp pata_artop pata_amd pata_ali ahci acard_ahci libahci radeon drm_suballoc_helper nouveau drm_gpuvm mxm_wmi drm_exec gpu_sched drm_ttm_helper fuse vfat fat nls_utf8 nls_cp437 hid_cherry sdhci_acpi nvme nvme_core squashfs
Sep 07 16:32:15 volumio-higole-x86 kernel: overlay hid_generic usbkbd usbhid i2c_designware_platform i2c_designware_core mmc_block i915 drm_buddy i2c_algo_bit drm_display_helper ttm r8169 realtek mdio_devres of_mdio cec rc_core fixed_phy intel_lpss_pci i2c_i801 sdhci_pci drm_kms_helper fwnode_mdio i2c_mux video cqhci crc32c_intel uas libphy i2c_smbus intel_lpss drm sdhci idma64 wmi pinctrl_jasperlake
Sep 07 16:32:15 volumio-higole-x86 kernel: CPU: 3 UID: 0 PID: 1311 Comm: Xorg Not tainted 6.12.35-volumio #14.44
Sep 07 16:32:15 volumio-higole-x86 kernel: Hardware name: Default string Default string/Default string, BIOS GOLE2_JSL_D88R2_720P_U0T9G3L1 03/26/2024
Sep 07 16:32:15 volumio-higole-x86 kernel: RIP: 0010:intel_dsi_vbt_exec_sequence+0x2da/0x2f0 [i915]
Sep 07 16:32:15 volumio-higole-x86 kernel: Code: d2 74 32 4c 89 45 c0 48 89 55 c8 e8 a0 52 2f e1 48 8b 55 c8 48 c7 c1 ec fa 65 a0 48 c7 c7 0c fa 65 a0 48 89 c6 e8 f6 f7 ba e0 <0f> 0b 4c 8b 45 c0 e9 be fd ff ff 48 8b 17 eb c9 66 0f 1f 44 00 00
Sep 07 16:32:15 volumio-higole-x86 kernel: RSP: 0018:ffffc90000d5b878 EFLAGS: 00010286
Sep 07 16:32:15 volumio-higole-x86 kernel: RAX: 0000000000000000 RBX: 0000000000000002 RCX: 0000000000000027
Sep 07 16:32:15 volumio-higole-x86 kernel: RDX: 0000000000000027 RSI: 0000000000000000 RDI: ffff88847019c948
Sep 07 16:32:15 volumio-higole-x86 kernel: RBP: ffffc90000d5b8b8 R08: 0000000000000000 R09: c0000000ffffefff
Sep 07 16:32:15 volumio-higole-x86 kernel: R10: 0000000000000001 R11: ffffc90000d5b650 R12: ffff88810dcf7400
Sep 07 16:32:15 volumio-higole-x86 kernel: R13: ffff88811570c000 R14: ffff888115a63788 R15: ffff88810dcf7400
Sep 07 16:32:15 volumio-higole-x86 kernel: FS: 00007f9d46606ac0(0000) GS:ffff888470180000(0000) knlGS:0000000000000000
Sep 07 16:32:15 volumio-higole-x86 kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Sep 07 16:32:15 volumio-higole-x86 kernel: CR2: 00002d3400344000 CR3: 0000000113172000 CR4: 0000000000352ef0
Sep 07 16:32:15 volumio-higole-x86 kernel: Call Trace:
Sep 07 16:32:15 volumio-higole-x86 kernel:
Sep 07 16:32:15 volumio-higole-x86 kernel: gen11_dsi_pre_enable+0xebf/0x1b20 [i915]
Sep 07 16:32:15 volumio-higole-x86 kernel: intel_encoders_pre_enable+0x83/0xa0 [i915]
Sep 07 16:32:15 volumio-higole-x86 kernel: hsw_crtc_enable+0x16c/0x890 [i915]
Sep 07 16:32:15 volumio-higole-x86 kernel: intel_enable_crtc+0xec/0x110 [i915]
Sep 07 16:32:15 volumio-higole-x86 kernel: skl_commit_modeset_enables+0x2cd/0x600 [i915]
Sep 07 16:32:15 volumio-higole-x86 kernel: ? intel_modeset_verify_disabled+0x131/0x2d0 [i915]
Sep 07 16:32:15 volumio-higole-x86 kernel: ? intel_pre_plane_update+0x470/0x650 [i915]
Sep 07 16:32:15 volumio-higole-x86 kernel: intel_atomic_commit_tail+0x805/0x1120 [i915]
Sep 07 16:32:15 volumio-higole-x86 kernel: ? flush_workqueue_prep_pwqs+0x119/0x130
Sep 07 16:32:15 volumio-higole-x86 kernel: ? __flush_workqueue+0x17b/0x3b0
Sep 07 16:32:15 volumio-higole-x86 kernel: intel_atomic_commit+0x2d8/0x330 [i915]
Sep 07 16:32:15 volumio-higole-x86 kernel: drm_atomic_commit+0xa9/0xe0 [drm]
Sep 07 16:32:15 volumio-higole-x86 kernel: ? __pfx___drm_printfn_info+0x10/0x10 [drm]
Sep 07 16:32:15 volumio-higole-x86 kernel: drm_atomic_helper_set_config+0x81/0xd0 [drm_kms_helper]
Sep 07 16:32:15 volumio-higole-x86 kernel: drm_mode_setcrtc+0x22a/0x8f0 [drm]
Sep 07 16:32:15 volumio-higole-x86 kernel: ? __pfx_drm_mode_setcrtc+0x10/0x10 [drm]
Sep 07 16:32:15 volumio-higole-x86 kernel: drm_ioctl_kernel+0xab/0x100 [drm]
Sep 07 16:32:15 volumio-higole-x86 kernel: drm_ioctl+0x26d/0x4e0 [drm]
Sep 07 16:32:15 volumio-higole-x86 kernel: ? __pfx_drm_mode_setcrtc+0x10/0x10 [drm]
Sep 07 16:32:15 volumio-higole-x86 kernel: __x64_sys_ioctl+0x97/0xd0
Sep 07 16:32:15 volumio-higole-x86 kernel: x64_sys_call+0x1d09/0x1d50
Sep 07 16:32:15 volumio-higole-x86 kernel: do_syscall_64+0x47/0x110
Sep 07 16:32:15 volumio-higole-x86 kernel: entry_SYSCALL_64_after_hwframe+0x76/0x7e
Sep 07 16:32:15 volumio-higole-x86 kernel: RIP: 0033:0x7f9d4671cd1b
Sep 07 16:32:15 volumio-higole-x86 kernel: Code: 00 48 89 44 24 18 31 c0 48 8d 44 24 60 c7 04 24 10 00 00 00 48 89 44 24 08 48 8d 44 24 20 48 89 44 24 10 b8 10 00 00 00 0f 05 <89> c2 3d 00 f0 ff ff 77 1c 48 8b 44 24 18 64 48 2b 04 25 28 00 00
Sep 07 16:32:15 volumio-higole-x86 kernel: RSP: 002b:00007ffc433b3ae0 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
Sep 07 16:32:15 volumio-higole-x86 kernel: RAX: ffffffffffffffda RBX: 0000564b55528500 RCX: 00007f9d4671cd1b
Sep 07 16:32:15 volumio-higole-x86 kernel: RDX: 00007ffc433b3b70 RSI: 00000000c06864a2 RDI: 0000000000000010
Sep 07 16:32:15 volumio-higole-x86 kernel: RBP: 00007ffc433b3b70 R08: 0000000000000000 R09: 0000564b5552dc00
Sep 07 16:32:15 volumio-higole-x86 kernel: R10: 0000000000000000 R11: 0000000000000246 R12: 00000000c06864a2
Sep 07 16:32:15 volumio-higole-x86 kernel: R13: 0000000000000010 R14: 0000564b55419bf8 R15: 00007ffc433b3c20
Sep 07 16:32:15 volumio-higole-x86 kernel:
Sep 07 16:32:15 volumio-higole-x86 kernel: ---[ end trace 0000000000000000 ]---
Sep 07 16:32:16 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Sep 07 16:32:16 volumio-higole-x86 volumio[1237]: info: Received Get System Info
Sep 07 16:32:16 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Sep 07 16:32:16 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Sep 07 16:32:16 volumio-higole-x86 volumio[1237]: info: Discovery: Getting this device information
Sep 07 16:32:16 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:16 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:16 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Sep 07 16:32:16 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:16 volumio-higole-x86 ntpd[1041]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101
Sep 07 16:32:16 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 51.68.44.27
Sep 07 16:32:16 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 5.196.76.84
Sep 07 16:32:16 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 162.159.200.123
Sep 07 16:32:16 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 146.59.30.179
Sep 07 16:32:16 volumio-higole-x86 ntpd[1041]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8
Sep 07 16:32:16 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:17 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:17 volumio-higole-x86 volumio[1237]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Sep 07 16:32:17 volumio-higole-x86 ntpd[1041]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101
Sep 07 16:32:17 volumio-higole-x86 ntpd[1041]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101
Sep 07 16:32:17 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 188.213.31.235
Sep 07 16:32:17 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 82.65.248.56
Sep 07 16:32:17 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 51.75.17.219
Sep 07 16:32:17 volumio-higole-x86 ntpd[1041]: DNS: Pool taking: 45.13.105.44
Sep 07 16:32:17 volumio-higole-x86 ntpd[1041]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8
Sep 07 16:32:17 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:18 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:18 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:18 volumio-higole-x86 dhcpcd[869]: wlan0: using IPv4LL address 169.254.91.247
Sep 07 16:32:18 volumio-higole-x86 avahi-daemon[834]: Registering new address record for 169.254.91.247 on wlan0.IPv4.
Sep 07 16:32:18 volumio-higole-x86 dhcpcd[869]: wlan0: adding route to 169.254.0.0/16
Sep 07 16:32:18 volumio-higole-x86 systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service...
Sep 07 16:32:18 volumio-higole-x86 systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0.
Sep 07 16:32:18 volumio-higole-x86 systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0...
Sep 07 16:32:18 volumio-higole-x86 systemd[1]: welcome.service: Deactivated successfully.
Sep 07 16:32:18 volumio-higole-x86 systemd[1]: Stopped welcome.service - Show a welcome message on console.
Sep 07 16:32:18 volumio-higole-x86 systemd[1]: Stopping welcome.service - Show a welcome message on console...
Sep 07 16:32:18 volumio-higole-x86 systemd[1]: Starting welcome.service - Show a welcome message on console...
Sep 07 16:32:18 volumio-higole-x86 welcome[1944]: Resolved ip:[3] 192.168.1.92 192.168.211.1 169.254.91.247
Sep 07 16:32:18 volumio-higole-x86 setdatetime-helper.sh[1937]: Time is already synchronized.
Sep 07 16:32:18 volumio-higole-x86 systemd[1]: setdatetime-helper.timer.service: Deactivated successfully.
Sep 07 16:32:18 volumio-higole-x86 systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service.
Sep 07 16:32:18 volumio-higole-x86 systemd[1]: Finished welcome.service - Show a welcome message on console.
Sep 07 16:32:18 volumio-higole-x86 systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0.
Sep 07 16:32:19 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Sep 07 16:32:19 volumio-higole-x86 volumio[1237]: info: Received Get System Info
Sep 07 16:32:19 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Sep 07 16:32:19 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Sep 07 16:32:19 volumio-higole-x86 volumio[1237]: info: Discovery: Getting this device information
Sep 07 16:32:19 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:19 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:19 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Sep 07 16:32:19 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:19 volumio-higole-x86 sudo[1965]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Sep 07 16:32:19 volumio-higole-x86 sudo[1965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:19 volumio-higole-x86 sudo[1965]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:19 volumio-higole-x86 sudo[1967]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 07 16:32:19 volumio-higole-x86 sudo[1967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:19 volumio-higole-x86 sudo[1967]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:19 volumio-higole-x86 sudo[1971]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Sep 07 16:32:19 volumio-higole-x86 sudo[1971]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:19 volumio-higole-x86 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Sep 07 16:32:19 volumio-higole-x86 sudo[1971]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:19 volumio-higole-x86 volumio[1237]: info: Upmpdcli Daemon Started
Sep 07 16:32:19 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:19 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken
Sep 07 16:32:20 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:20 volumio-higole-x86 ntpd[1041]: IO: Listen normally on 5 wlan0 169.254.91.247:123
Sep 07 16:32:20 volumio-higole-x86 ntpd[1041]: IO: new interface(s) found: waking up resolver
Sep 07 16:32:20 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: Adding plugin bluetooth to MyMusic Plugins
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: Adding plugin multiroom to MyMusic Plugins
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: Adding plugin metavolumio to MyMusic Plugins
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: Adding plugin cd_controller to MyMusic Plugins
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: Adding plugin qobuzconnect to MyMusic Plugins
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: Adding plugin smart_inputs to MyMusic Plugins
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: Adding plugin tidalconnect to MyMusic Plugins
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: Starting MyVolumio Remote Streaming Endpoints
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: MyVolumio login type: Token
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: Streaming services startup
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: Starting Streaming Daemon
Sep 07 16:32:21 volumio-higole-x86 sudo[1994]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Sep 07 16:32:21 volumio-higole-x86 sudo[1994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Sep 07 16:32:21 volumio-higole-x86 sudo[1994]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: error: Cannot start Volumio Streaming Daemon
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Sep 07 16:32:21 volumio-higole-x86 volumio[1237]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Sep 07 16:32:22 volumio-higole-x86 ntpd[1041]: CLOCK: time stepped by 0.372191
Sep 07 16:32:22 volumio-higole-x86 ntpd[1041]: INIT: MRU 10922 entries, 13 hash bits, 65536 bytes
Sep 07 16:32:23 volumio-higole-x86 volumio[1237]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Sep 07 16:32:23 volumio-higole-x86 upmpdcli[2006]: writing RSA key
Sep 07 16:32:24 volumio-higole-x86 volumio[1237]: info: MyVolumio token set successfully
Sep 07 16:32:24 volumio-higole-x86 volumio[1237]: info: MYVOLUMIO: Adding device
Sep 07 16:32:24 volumio-higole-x86 volumio[1237]: info: MYVOLUMIO: Evaluating Server
Sep 07 16:32:24 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:32:24 volumio-higole-x86 volumio[1237]: info: MyVolumio Plan changed: superstar
Sep 07 16:32:24 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Subscribed plan changed to superstar
Sep 07 16:32:24 volumio-higole-x86 volumio[1237]: info: Adding audio output:
Sep 07 16:32:24 volumio-higole-x86 volumio[1237]: info: MYVOLUMIO: Adding device
Sep 07 16:32:24 volumio-higole-x86 volumio[1237]: info: MYVOLUMIO: Evaluating Server
Sep 07 16:32:24 volumio-higole-x86 volumio[1237]: info: Remote config written successfully
Sep 07 16:32:24 volumio-higole-x86 volumio[1237]: info: Starting Tunnel 1
Sep 07 16:32:24 volumio-higole-x86 volumio[1237]: info: Starting Tunnel Connection Checker
Sep 07 16:32:24 volumio-higole-x86 volumio[1237]: info: Completed starting MyVolumio Plugin
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: MYVolumio Device enabled
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins...
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: MyVolumio status changed
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Streaming services startup
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Starting Streaming Daemon
Sep 07 16:32:25 volumio-higole-x86 sudo[2047]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Sep 07 16:32:25 volumio-higole-x86 sudo[2047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"...
Sep 07 16:32:25 volumio-higole-x86 sudo[2047]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Loading plugin "multiroom"...
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom
Sep 07 16:32:25 volumio-higole-x86 sudo[2051]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom
Sep 07 16:32:25 volumio-higole-x86 sudo[2051]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:25 volumio-higole-x86 sudo[2051]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: MRS: MultiRoom plugin initialized
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: MRS: STOPPING SNAPCLIENT
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: MRS: Snap server stop
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: MRS: STOPPING volumioStreaming
Sep 07 16:32:25 volumio-higole-x86 sudo[2068]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient
Sep 07 16:32:25 volumio-higole-x86 sudo[2068]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"...
Sep 07 16:32:25 volumio-higole-x86 sudo[2073]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming
Sep 07 16:32:25 volumio-higole-x86 sudo[2073]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:25 volumio-higole-x86 sudo[2071]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver
Sep 07 16:32:25 volumio-higole-x86 sudo[2071]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:25 volumio-higole-x86 sudo[2075]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/*
Sep 07 16:32:25 volumio-higole-x86 sudo[2075]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:25 volumio-higole-x86 sudo[2075]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:25 volumio-higole-x86 sudo[2068]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Loading plugin "manifestui"...
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"...
Sep 07 16:32:25 volumio-higole-x86 sudo[2071]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:25 volumio-higole-x86 sudo[2073]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"...
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"...
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Loading plugin "tidal"...
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Loading plugin "qobuz"...
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"...
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"...
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Preparing to generate the ALSA configuration file
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Reading ALSA contributions from plugins.
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::getUIConfigOnPlugin
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: MRS: Removed streaming files
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: MRS: volumioStreaming STOPPED
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: MRS: SNAPSERVER STOPPED
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: MRS: SNAPCLIENT STOPPED
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: error: Cannot start Volumio Streaming Daemon
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Asound.conf file written
Sep 07 16:32:25 volumio-higole-x86 sudo[2093]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf
Sep 07 16:32:25 volumio-higole-x86 sudo[2093]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:25 volumio-higole-x86 sudo[2093]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Output device has changed, restarting MPD
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Output device has changed, restarting Shairport Sync
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:25 volumio-higole-x86 sudo[2099]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Sep 07 16:32:25 volumio-higole-x86 sudo[2101]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Sep 07 16:32:25 volumio-higole-x86 sudo[2101]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:25 volumio-higole-x86 sudo[2099]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:25 volumio-higole-x86 sudo[2099]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Plugin bluetooth disabled by user. Not starting
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: MRS: Pushing multiroomSync output for this device
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: MRS: Pushing multiroomSync output
Sep 07 16:32:25 volumio-higole-x86 systemd[1]: Stopping mpd.service - Music Player Daemon...
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Adding audio output:
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Adding audio output:
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:25 volumio-higole-x86 systemd[1]: mpd.service: Deactivated successfully.
Sep 07 16:32:25 volumio-higole-x86 systemd[1]: Stopped mpd.service - Music Player Daemon.
Sep 07 16:32:25 volumio-higole-x86 systemd[1]: mpd.socket: Deactivated successfully.
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio
Sep 07 16:32:25 volumio-higole-x86 systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Sep 07 16:32:25 volumio-higole-x86 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Adding METAVOLUMIO REST API Endpoints
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Preparing CD Folders
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Adding CD REST API Endpoints
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Starting UDEV Watcher for CD
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: Detecting CD presence with UDEV
Sep 07 16:32:25 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices
Sep 07 16:32:25 volumio-higole-x86 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Sep 07 16:32:25 volumio-higole-x86 systemd[1]: Starting mpd.service - Music Player Daemon...
Sep 07 16:32:25 volumio-higole-x86 sudo[2118]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Sep 07 16:32:25 volumio-higole-x86 sudo[2118]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Sep 07 16:32:25 volumio-higole-x86 sudo[2118]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:26 volumio-higole-x86 mpd[2120]: 2025-09-07T16:32:26 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Sep 07 16:32:26 volumio-higole-x86 systemd[1]: Started mpd.service - Music Player Daemon.
Sep 07 16:32:26 volumio-higole-x86 sudo[2101]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:28 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:32:28 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:32:28 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:32:28 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:32:29 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:32:29 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:32:29 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:32:29 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:32:29 volumio-higole-x86 systemd[1]: systemd-fsckd.service: Deactivated successfully.
Sep 07 16:32:30 volumio-higole-x86 systemd[1]: systemd-hostnamed.service: Deactivated successfully.
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: warn: [cd-plugin] cdspeedctl: device or media not ready
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Adding inputs REST Endpoints
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Scanning Audio Inputs
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Checking against Known Cards name
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Checking against Known Cards name
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Adding Server instance for streaming
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: error: Hi Res Audio Failed Login: Missing Login Data
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Adding HIGHRESAUDIO REST API Endpoints
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect
Sep 07 16:32:30 volumio-higole-x86 sudo[2148]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Sep 07 16:32:30 volumio-higole-x86 sudo[2148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: QobuzConnect: Starting Qobuz Connect socket and service
Sep 07 16:32:30 volumio-higole-x86 sudo[2155]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service
Sep 07 16:32:30 volumio-higole-x86 sudo[2155]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Stopping AccessToken refresher cron
Sep 07 16:32:30 volumio-higole-x86 sudo[2148]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:30 volumio-higole-x86 sudo[2155]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:30 volumio-higole-x86 sudo[2159]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: AccessToken refresher cron started
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Stopping AccessToken refresher cron for QOBUZ
Sep 07 16:32:30 volumio-higole-x86 sudo[2159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: AccessToken refresher cron started for QOBUZ
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Adding TIDAL REST API Endpoints
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Adding QOBUZ REST API Endpoints
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: MRS: Getting audio outputs on start
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: MRS: Requesting all other devices output
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: MRS: Adding multiroomSync output
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Adding audio output:
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: MRS: Pushing multiroomSync output
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: MRS: Adding multiroomSync output
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Adding audio output:
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: MRS: Pushing multiroomSync output
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Setting Geolocation for MyVolumio to eu9
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Setting Geolocation for MyVolumio to eu9
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:30 volumio-higole-x86 systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service.
Sep 07 16:32:30 volumio-higole-x86 sudo[2159]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: MPD Permissions set
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:30 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:32:30 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:32:30 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:32:30 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: error: updateQueue error: null
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Executing endpoint qc_getconfig
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig
Sep 07 16:32:30 volumio-higole-x86 qobuz-connect[2161]: 20250907 16:32:30.900 [2161.2161] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Starting Shairport Sync
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object]
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: QobuzConnect: QOBUZ Connect daemon connected
Sep 07 16:32:30 volumio-higole-x86 sudo[2176]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Sep 07 16:32:30 volumio-higole-x86 sudo[2176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:30 volumio-higole-x86 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Sep 07 16:32:30 volumio-higole-x86 systemd[1]: shairport-sync.service: Deactivated successfully.
Sep 07 16:32:30 volumio-higole-x86 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Sep 07 16:32:30 volumio-higole-x86 systemd[1]: shairport-sync.service: Consumed 1.581s CPU time.
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Received Get System Version
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 07 16:32:30 volumio-higole-x86 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Sep 07 16:32:30 volumio-higole-x86 sudo[2176]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:30 volumio-higole-x86 volumio[1237]: info: Shairport-Sync Started
Sep 07 16:32:31 volumio-higole-x86 qobuz-connect[2161]: 20250907 16:32:31.035 [2161.2161] INFO VolumeManager: [0x5649769a5320]: Setting new playback volume: 75
Sep 07 16:32:31 volumio-higole-x86 qobuz-connect[2161]: 20250907 16:32:31.035 [2161.2161] INFO VolumeManager: [0x5649769a5320]: Setting new mute state: 0
Sep 07 16:32:31 volumio-higole-x86 qobuz-connect[2161]: 20250907 16:32:31.035 [2161.2161] INFO QobuzConnect: [0x5649769a6540]: Client initialized!
Sep 07 16:32:31 volumio-higole-x86 qobuz-connect[2161]: 20250907 16:32:31.035 [2161.2161] INFO SampleApp: Starting Avahi advertising, name: Volumio-higole-x86, service name: _qobuz-connect._tcp
Sep 07 16:32:31 volumio-higole-x86 qobuz-connect[2161]: 20250907 16:32:31.037 [2161.2161] INFO LocalConfigManager: [0x5649769a4610]: Starting Local Configuration server
Sep 07 16:32:31 volumio-higole-x86 qobuz-connect[2161]: 20250907 16:32:31.037 [2161.2161] INFO SampleApp: Starting Local configuration server
Sep 07 16:32:31 volumio-higole-x86 qobuz-connect[2161]: 20250907 16:32:31.038 [2161.2161] INFO SampleApp: Connected to UNIX socket client 0x56497697abb0
Sep 07 16:32:31 volumio-higole-x86 qobuz-connect[2161]: 20250907 16:32:31.050 [2161.2161] INFO SampleApp: Playback volume changed: 75
Sep 07 16:32:31 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:31 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:31 volumio-higole-x86 sudo[2196]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service
Sep 07 16:32:31 volumio-higole-x86 sudo[2196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:31 volumio-higole-x86 systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 07 16:32:31 volumio-higole-x86 systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 07 16:32:31 volumio-higole-x86 systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel.
Sep 07 16:32:31 volumio-higole-x86 sudo[2196]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:31 volumio-higole-x86 volumio[1237]: info: Remote SSH Started
Sep 07 16:32:31 volumio-higole-x86 autossh[2199]: port set to 0, monitoring disabled
Sep 07 16:32:31 volumio-higole-x86 autossh[2199]: starting ssh (count 1)
Sep 07 16:32:31 volumio-higole-x86 autossh[2199]: ssh child pid is 2202
Sep 07 16:32:31 volumio-higole-x86 volumiossh-tunnel[2202]: Warning: Permanently added '[eu1.myvolumio.org]:2222' (RSA) to the list of known hosts.
Sep 07 16:32:31 volumio-higole-x86 volumio[1237]: info: Updating MyVolumio device info
Sep 07 16:32:31 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:31 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:31 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:31 volumio-higole-x86 volumio[1237]: info: Updating MyVolumio device info
Sep 07 16:32:31 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:31 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:31 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: Received Get System Version
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: Received Get System Info
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: Discovery: Getting this device information
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: TidalConnect service stoped!
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect
Sep 07 16:32:33 volumio-higole-x86 sudo[2216]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service
Sep 07 16:32:33 volumio-higole-x86 sudo[2216]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:32:33 volumio-higole-x86 systemd[1]: Started vtcs.service - Volumio Tidal Connect Service.
Sep 07 16:32:33 volumio-higole-x86 sudo[2216]: pam_unix(sudo:session): session closed for user root
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: Executing endpoint tc_getconfig
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig
Sep 07 16:32:33 volumio-higole-x86 vtcs[2219]: STARTING TidalConnect services, version: 1.5.1-beta1
Sep 07 16:32:33 volumio-higole-x86 vtcs[2219]: STARTED TidalConnect services.
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: Executing endpoint tc_connect
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: Connecting to TidalConnect
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::servicePushState
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CoreStateMachine::pushState
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioPushState
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: MRS: Pushing multiroomSync output update for this device
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: MRS: Pushing multiroomSync output
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::servicePushState
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CoreStateMachine::pushState
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioPushState
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: MRS: Pushing multiroomSync output update for this device
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: MRS: Pushing multiroomSync output
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: vkiosksettings --- Volumio status=stop timeout=0 noifplay=true
Sep 07 16:32:33 volumio-higole-x86 volumio[1237]: info: vkiosksettings --- Volumio status=stop timeout=0 noifplay=true
Sep 07 16:32:36 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:32:36 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:32:36 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:32:36 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:32:36 volumio-higole-x86 volumio[1237]: info: TidalConnect service started!
Sep 07 16:32:36 volumio-higole-x86 volumio[1237]: [Metrics] CommandRouter: 27s 980.44ms
Sep 07 16:32:36 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumiosetStartupVolume
Sep 07 16:32:36 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:36 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:36 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::Close All Modals sent
Sep 07 16:32:36 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::Close All Modals sent
Sep 07 16:32:36 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:32:36 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:32:36 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:32:36 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:32:37 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Sep 07 16:32:37 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Sep 07 16:32:37 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Sep 07 16:32:37 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Sep 07 16:32:40 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:32:40 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:32:40 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:32:40 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:32:41 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:32:41 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:32:41 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:32:41 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:32:42 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:42 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 07 16:32:42 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Sep 07 16:32:42 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Sep 07 16:32:42 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Sep 07 16:32:42 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetBrowseSources
Sep 07 16:32:42 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 07 16:32:42 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 07 16:32:42 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 07 16:32:42 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Sep 07 16:32:42 volumio-higole-x86 volumio-remote-updater[852]: Test mode enabled
Sep 07 16:32:42 volumio-higole-x86 volumio-remote-updater[852]: Alpha mode disabled
Sep 07 16:32:42 volumio-higole-x86 volumio-remote-updater[852]: Alpha legacy test mode disabled
Sep 07 16:32:42 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Sep 07 16:32:42 volumio-higole-x86 volumio[1237]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false}
Sep 07 16:32:42 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Sep 07 16:32:43 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:32:43 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:32:43 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:32:43 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:32:43 volumio-higole-x86 volumio[1237]: info: BOOT COMPLETED
Sep 07 16:32:44 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:32:44 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:32:44 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:32:44 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:32:47 volumio-higole-x86 volumio[1237]: error: Failed to add MyVolumio device: undefined
Sep 07 16:32:47 volumio-higole-x86 volumio[1237]: error: Failed to add MyVolumio device: undefined
Sep 07 16:32:47 volumio-higole-x86 volumio[1237]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15
Sep 07 16:32:47 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:32:47 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:32:47 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:32:47 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:32:49 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:32:49 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:32:49 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:32:49 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:32:49 volumio-higole-x86 systemd[1]: systemd-timedated.service: Deactivated successfully.
Sep 07 16:32:56 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:32:56 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:32:56 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:32:56 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:32:57 volumio-higole-x86 volumio[1237]: error: Failed to update MyVolumio device: undefined
Sep 07 16:32:57 volumio-higole-x86 volumio[1237]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 16
Sep 07 16:32:57 volumio-higole-x86 volumio[1237]: error: Failed to update MyVolumio device: undefined
Sep 07 16:32:57 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:57 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:57 volumio-higole-x86 volumio[1237]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 17
Sep 07 16:32:57 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:57 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:32:58 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:32:58 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:33:00 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:33:00 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:33:00 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:33:00 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:33:00 volumio-higole-x86 volumio[1237]: info: Executing endpoint metavolumio
Sep 07 16:33:00 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Sep 07 16:33:05 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:33:05 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:33:05 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:33:05 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:33:06 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:33:06 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:33:06 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:33:06 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:33:07 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::getUIConfigOnPlugin
Sep 07 16:33:07 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Sep 07 16:33:07 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Sep 07 16:33:07 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Sep 07 16:33:07 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs
Sep 07 16:33:08 volumio-higole-x86 volumio[1237]: info: Received Get System Version
Sep 07 16:33:08 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 07 16:33:11 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:33:11 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:33:11 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:33:11 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:33:15 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:33:15 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:33:15 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:33:15 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:33:15 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:33:15 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:33:15 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:33:15 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:33:15 volumio-higole-x86 volumio[1237]: info: CALLMETHOD: system_controller system saveHDMISettings [object Object]
Sep 07 16:33:15 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , saveHDMISettings
Sep 07 16:33:15 volumio-higole-x86 sudo[2385]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-kiosk.service
Sep 07 16:33:15 volumio-higole-x86 sudo[2385]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:33:15 volumio-higole-x86 startx[1307]: xinit: connection to X server lost
Sep 07 16:33:15 volumio-higole-x86 systemd[1]: Stopping volumio-kiosk.service - Start Volumio Kiosk...
Sep 07 16:33:15 volumio-higole-x86 startx[1307]:
Sep 07 16:33:15 volumio-higole-x86 startx[1307]: waiting for X server to shut down
Sep 07 16:33:15 volumio-higole-x86 startx[1311]: (II) Server terminated successfully (0). Closing log file.
Sep 07 16:33:16 volumio-higole-x86 startx[1307]: xinit: unexpected signal 15
Sep 07 16:33:16 volumio-higole-x86 systemd[1]: volumio-kiosk.service: Main process exited, code=exited, status=1/FAILURE
Sep 07 16:33:16 volumio-higole-x86 systemd[1]: volumio-kiosk.service: Failed with result 'exit-code'.
Sep 07 16:33:16 volumio-higole-x86 systemd[1]: Stopped volumio-kiosk.service - Start Volumio Kiosk.
Sep 07 16:33:16 volumio-higole-x86 systemd[1]: volumio-kiosk.service: Consumed 9.032s CPU time.
Sep 07 16:33:16 volumio-higole-x86 systemd[1]: Started volumio-kiosk.service - Start Volumio Kiosk.
Sep 07 16:33:16 volumio-higole-x86 sudo[2385]: pam_unix(sudo:session): session closed for user root
Sep 07 16:33:16 volumio-higole-x86 sudo[2394]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl enable volumio-kiosk.service
Sep 07 16:33:16 volumio-higole-x86 sudo[2394]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 07 16:33:16 volumio-higole-x86 systemd[1]: Reloading.
Sep 07 16:33:16 volumio-higole-x86 startx[2416]: X.Org X Server 1.21.1.7
Sep 07 16:33:16 volumio-higole-x86 startx[2416]: X Protocol Version 11, Revision 0
Sep 07 16:33:16 volumio-higole-x86 startx[2416]: Current Operating System: Linux volumio-higole-x86 6.12.35-volumio #14.44 SMP PREEMPT_DYNAMIC Fri Jul 4 14:52:54 CEST 2025 x86_64
Sep 07 16:33:16 volumio-higole-x86 startx[2416]: Kernel command line: BOOT_IMAGE=/vmlinuz initramfs.clear splash plymouth.ignore-serial-consoles quiet loglevel=0 bootdelay=5 biosdevname=0 imgpart=UUID=c416cc9d-1a7a-499f-ac37-78337eedbb1c bootpart=UUID=3831-C55C datapart=UUID=44cf684b-88eb-4fbf-8b1b-3620c1c9961d 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 07 16:33:16 volumio-higole-x86 startx[2416]: xorg-server 2:21.1.7-3+deb12u9 (https://www.debian.org/support)
Sep 07 16:33:16 volumio-higole-x86 startx[2416]: Current version of pixman: 0.42.2
Sep 07 16:33:16 volumio-higole-x86 startx[2416]: Before reporting problems, check http://wiki.x.org
Sep 07 16:33:16 volumio-higole-x86 startx[2416]: to make sure that you have the latest version.
Sep 07 16:33:16 volumio-higole-x86 startx[2416]: Markers: (--) probed, (**) from config file, (==) default setting,
Sep 07 16:33:16 volumio-higole-x86 startx[2416]: (++) from command line, (!!) notice, (II) informational,
Sep 07 16:33:16 volumio-higole-x86 startx[2416]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown.
Sep 07 16:33:16 volumio-higole-x86 startx[2416]: (==) Log file: "/var/log/Xorg.0.log", Time: Sun Sep 7 16:33:16 2025
Sep 07 16:33:16 volumio-higole-x86 startx[2416]: (==) Using system config directory "/usr/share/X11/xorg.conf.d"
Sep 07 16:33:16 volumio-higole-x86 systemd-gpt-auto-generator[2423]: EFI loader partition unknown, exiting.
Sep 07 16:33:16 volumio-higole-x86 systemd-gpt-auto-generator[2423]: (The boot loader did not set EFI variable LoaderDevicePartUUID.)
Sep 07 16:33:16 volumio-higole-x86 systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 07 16:33:16 volumio-higole-x86 systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 07 16:33:16 volumio-higole-x86 sudo[2394]: pam_unix(sudo:session): session closed for user root
Sep 07 16:33:16 volumio-higole-x86 volumio[1237]: info: enable volumio-kiosk service success
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: 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/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 17
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: 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/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 18
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetVisibleSources
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetQueue
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CoreStateMachine::getQueue
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getQueue
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: Listing playlists
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: Received Get System Info
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: Discovery: Getting this device information
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Sep 07 16:33:18 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Sep 07 16:33:20 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Sep 07 16:33:20 volumio-higole-x86 volumio[1237]: info: Received Get System Info
Sep 07 16:33:20 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Sep 07 16:33:20 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Sep 07 16:33:20 volumio-higole-x86 volumio[1237]: info: Discovery: Getting this device information
Sep 07 16:33:20 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:33:20 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:33:20 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Sep 07 16:33:20 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard
Sep 07 16:33:21 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Sep 07 16:33:21 volumio-higole-x86 volumio[1237]: info: Received Get System Info
Sep 07 16:33:21 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Sep 07 16:33:21 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Sep 07 16:33:21 volumio-higole-x86 volumio[1237]: info: Discovery: Getting this device information
Sep 07 16:33:21 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:33:21 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:33:21 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Sep 07 16:33:23 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Sep 07 16:33:23 volumio-higole-x86 volumio[1237]: info: CURURI: music-library
Sep 07 16:33:23 volumio-higole-x86 volumio[1237]: error: Failed LSINFO: null
Sep 07 16:33:23 volumio-higole-x86 volumio[1237]: info: Preload queue cleared
Sep 07 16:33:28 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:33:28 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:33:28 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:33:28 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:33:28 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Sep 07 16:33:28 volumio-higole-x86 systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service...
Sep 07 16:33:28 volumio-higole-x86 dbus-daemon[838]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.37' (uid=0 pid=2691 comm="timedatectl show --property=NTPSynchronized --valu")
Sep 07 16:33:28 volumio-higole-x86 systemd[1]: Starting systemd-timedated.service - Time & Date Service...
Sep 07 16:33:28 volumio-higole-x86 dbus-daemon[838]: [system] Successfully activated service 'org.freedesktop.timedate1'
Sep 07 16:33:28 volumio-higole-x86 systemd[1]: Started systemd-timedated.service - Time & Date Service.
Sep 07 16:33:28 volumio-higole-x86 setdatetime-helper.sh[2690]: Time is not synchronized. Attempting to sync...
Sep 07 16:33:29 volumio-higole-x86 sudo[2700]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Sun, 07 Sep 2025 14:33:29 GMT#015'
Sep 07 16:33:29 volumio-higole-x86 sudo[2700]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Sep 07 16:33:29 volumio-higole-x86 setdatetime-helper.sh[2701]: Sun Sep 7 16:33:29 CEST 2025
Sep 07 16:33:29 volumio-higole-x86 systemd-journald[504]: Time jumped backwards, rotating.
Sep 07 16:33:29 volumio-higole-x86 setdatetime-helper.sh[2690]: Time synchronized successfully.
Sep 07 16:33:29 volumio-higole-x86 sudo[2700]: pam_unix(sudo:session): session closed for user root
Sep 07 16:33:29 volumio-higole-x86 systemd[1]: setdatetime-helper.timer.service: Deactivated successfully.
Sep 07 16:33:29 volumio-higole-x86 systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service.
Sep 07 16:33:34 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:33:34 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:33:34 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:33:34 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:33:35 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:33:35 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:33:36 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Sep 07 16:33:36 volumio-higole-x86 volumio[1237]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
Sep 07 16:33:36 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
Sep 07 16:33:36 volumio-higole-x86 volumio[1237]: info: Received Get System Version
Sep 07 16:33:36 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 07 16:33:36 volumio-higole-x86 volumio[1237]: info: Received Get System Info
Sep 07 16:33:36 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Sep 07 16:33:36 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Sep 07 16:33:36 volumio-higole-x86 volumio[1237]: info: Discovery: Getting this device information
Sep 07 16:33:36 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:33:36 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:33:36 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Sep 07 16:33:37 volumio-higole-x86 volumio[1237]: info: Executing endpoint metavolumio
Sep 07 16:33:37 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Sep 07 16:33:37 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Sep 07 16:33:37 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Sep 07 16:33:42 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::getUIConfigOnPlugin
Sep 07 16:33:46 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:33:46 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:33:46 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:33:46 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:33:47 volumio-higole-x86 kernel: pcieport 0000:00:1c.6: AER: Multiple Correctable error message received from 0000:02:00.0
Sep 07 16:33:47 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
Sep 07 16:33:47 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: device [10ec:c821] error status/mask=00000001/0000e000
Sep 07 16:33:47 volumio-higole-x86 kernel: rtw_8821ce 0000:02:00.0: [ 0] RxErr (First)
Sep 07 16:33:47 volumio-higole-x86 volumio[1237]: info: CALLMETHOD: user_interface vkiosksettings savescreensettings [object Object]
Sep 07 16:33:47 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::executeOnPlugin: vkiosksettings , savescreensettings
Sep 07 16:33:47 volumio-higole-x86 volumio[1237]: error: vkiosksettings --- : Error waking up the screen: Error: Command failed: /usr/bin/xset -display :0 -dpms
Sep 07 16:33:47 volumio-higole-x86 volumio[1237]: Invalid MIT-MAGIC-COOKIE-1 key
Sep 07 16:33:47 volumio-higole-x86 volumio[1237]: /usr/bin/xset: unable to open display ":0"
Sep 07 16:33:48 volumio-higole-x86 volumio[1237]: info: vkiosksettings --- Preparing playback state watcher...
Sep 07 16:33:48 volumio-higole-x86 volumio[1237]: info: CoreCommandRouter::volumioGetState
Sep 07 16:33:48 volumio-higole-x86 volumio[1237]: info: CorePlayQueue::getTrack 0
Sep 07 16:33:48 volumio-higole-x86 volumio[1237]: error: vkiosksettings --- Failed to disable DPMS: Error: Command failed: /usr/bin/xset -display :0 -dpms
Sep 07 16:33:48 volumio-higole-x86 volumio[1237]: Invalid MIT-MAGIC-COOKIE-1 key
Sep 07 16:33:48 volumio-higole-x86 volumio[1237]: /usr/bin/xset: unable to open display ":0"
Sep 07 16:33:48 volumio-higole-x86 volumio[1237]: error: vkiosksettings --- applyscreensettings error: xinput error: Invalid MIT-MAGIC-COOKIE-1 key
Sep 07 16:33:48 volumio-higole-x86 volumio[1237]: Unable to connect to X server
Sep 07 16:33:48 volumio-higole-x86 volumio[1237]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 07 16:33:48 volumio-higole-x86 volumio[1237]: [UnhandledPromiseRejection: This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). The promise rejected with the reason "xinput error: Invalid MIT-MAGIC-COOKIE-1 key
Sep 07 16:33:48 volumio-higole-x86 volumio[1237]: Unable to connect to X server
Sep 07 16:33:48 volumio-higole-x86 volumio[1237]: ".] {
Sep 07 16:33:48 volumio-higole-x86 volumio[1237]: code: 'ERR_UNHANDLED_REJECTION'
Sep 07 16:33:48 volumio-higole-x86 volumio[1237]: }
Sep 07 16:33:48 volumio-higole-x86 volumio[1237]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 07 16:33:48 volumio-higole-x86 sudo[2782]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-09-07 16:32'
Sep 07 16:33:48 volumio-higole-x86 sudo[2782]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Debian GNU/Linux 12 (bookworm)"
NAME="Debian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
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="dfc7bb04e09bf2260691765a2340814af1fa2971"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="30d63a8c53d2826bd7f262e22b4e4511a4cc9d01"
VOLUMIO_ARCH="x64"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Sat Aug 30 07:07:32 UTC 2025"
VOLUMIO_VERSION="4.022"
VOLUMIO_HARDWARE="x86_amd64"
VOLUMIO_DEVICENAME="x86_64"
VOLUMIO_HASH="9a5a1566f5c8d470330ec8a877815bcf"