-- Logs begin at Sun 2025-05-18 14:27:47 CST, end at Sun 2025-05-18 14:29:54 CST. -- May 18 14:28:00 volumio sudo[953]: pam_unix(sudo:session): session closed for user root May 18 14:28:00 volumio wireless.js[710]: Start wireless flow May 18 14:28:00 volumio wireless.js[710]: Stopped hotspot (if there).. May 18 14:28:00 volumio sudo[963]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 May 18 14:28:00 volumio sudo[963]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:00 volumio sudo[963]: pam_unix(sudo:session): session closed for user root May 18 14:28:00 volumio sudo[965]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down May 18 14:28:00 volumio sudo[965]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:00 volumio sudo[965]: pam_unix(sudo:session): session closed for user root May 18 14:28:00 volumio wireless.js[710]: DHCP IP May 18 14:28:00 volumio wireless.js[710]: Start ap May 18 14:28:00 volumio wpa_supplicant[967]: Successfully initialized wpa_supplicant May 18 14:28:00 volumio sudo[968]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd May 18 14:28:00 volumio sudo[968]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:00 volumio dhcpcd[969]: sending commands to master dhcpcd process May 18 14:28:00 volumio dhcpcd[787]: control command: /sbin/dhcpcd May 18 14:28:00 volumio sudo[968]: pam_unix(sudo:session): session closed for user root May 18 14:28:00 volumio mpd[918]: May 18 14:28 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 18 14:28:00 volumio kernel: ACPI: \: failed to evaluate _DSM bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001) May 18 14:28:00 volumio kernel: ACPI: \: failed to evaluate _DSM bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001) May 18 14:28:00 volumio kernel: ACPI: \: failed to evaluate _DSM bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001) May 18 14:28:00 volumio kernel: ACPI: \: failed to evaluate _DSM bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001) May 18 14:28:00 volumio kernel: ACPI: \: failed to evaluate _DSM bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001) May 18 14:28:00 volumio kernel: ACPI: \: failed to evaluate _DSM bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001) May 18 14:28:00 volumio kernel: ACPI: \: failed to evaluate _DSM bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001) May 18 14:28:00 volumio systemd[1]: Started Music Player Daemon. May 18 14:28:00 volumio mpd_monitor.sh[694]: MPD Monitor Service: MPD restarted due to no mpc output. May 18 14:28:01 volumio wireless.js[710]: trying... May 18 14:28:01 volumio sudo[977]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 18 14:28:01 volumio sudo[977]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:01 volumio sudo[977]: pam_unix(sudo:session): session closed for user root May 18 14:28:02 volumio wireless.js[710]: trying... May 18 14:28:02 volumio sudo[980]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 18 14:28:02 volumio sudo[980]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:02 volumio sudo[980]: pam_unix(sudo:session): session closed for user root May 18 14:28:02 volumio wpa_supplicant[972]: wlan0: SME: Trying to authenticate with d4:da:21:ee:fa:47 (SSID='Redmi_ZJ_5G' freq=5240 MHz) May 18 14:28:02 volumio kernel: wlan0: authenticate with d4:da:21:ee:fa:47 May 18 14:28:02 volumio kernel: wlan0: send auth to d4:da:21:ee:fa:47 (try 1/3) May 18 14:28:02 volumio wpa_supplicant[972]: wlan0: Trying to associate with d4:da:21:ee:fa:47 (SSID='Redmi_ZJ_5G' freq=5240 MHz) May 18 14:28:02 volumio kernel: wlan0: authenticated May 18 14:28:02 volumio kernel: wlan0: associate with d4:da:21:ee:fa:47 (try 1/3) May 18 14:28:02 volumio kernel: wlan0: RX AssocResp from d4:da:21:ee:fa:47 (capab=0x1511 status=0 aid=4) May 18 14:28:02 volumio wpa_supplicant[972]: wlan0: Associated with d4:da:21:ee:fa:47 May 18 14:28:02 volumio wpa_supplicant[972]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 May 18 14:28:02 volumio wpa_supplicant[972]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=CN May 18 14:28:02 volumio kernel: wlan0: associated May 18 14:28:02 volumio kernel: wlan0: Limiting TX power to 27 (30 - 3) dBm as advertised by d4:da:21:ee:fa:47 May 18 14:28:02 volumio wpa_supplicant[972]: wlan0: WPA: Key negotiation completed with d4:da:21:ee:fa:47 [PTK=CCMP GTK=CCMP] May 18 14:28:02 volumio wpa_supplicant[972]: wlan0: CTRL-EVENT-CONNECTED - Connection to d4:da:21:ee:fa:47 completed [id=0 id_str=] May 18 14:28:02 volumio dhcpcd[787]: wlan0: carrier acquired May 18 14:28:02 volumio dhcpcd[787]: wlan0: IAID 9b:ba:0f:ae May 18 14:28:02 volumio dhcpcd[787]: wlan0: adding address fe80::cc27:7996:4edd:27a3 May 18 14:28:02 volumio dhcpcd[787]: ipv6_addaddr1: Permission denied May 18 14:28:02 volumio dhcpcd[787]: wlan0: rebinding lease of 192.168.31.173 May 18 14:28:02 volumio dhcpcd[787]: wlan0: probing address 192.168.31.173/24 May 18 14:28:03 volumio wireless.js[710]: trying... May 18 14:28:03 volumio sudo[999]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 18 14:28:03 volumio sudo[999]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:03 volumio sudo[999]: pam_unix(sudo:session): session closed for user root May 18 14:28:03 volumio dhcpcd[787]: wlan0: soliciting an IPv6 router May 18 14:28:03 volumio screensaver.sh[732]: curl: (7) Failed to connect to 127.0.0.1 port 3000: Connection refused May 18 14:28:04 volumio volumio-time-update[705]: volumio-time-update-util: Fetching time from Volumio... May 18 14:28:04 volumio volumio-time-update[705]: volumio-time-update-util: Date not found in response May 18 14:28:04 volumio volumio-time-update[705]: volumio-time-update-util: Retrying in 5 seconds... May 18 14:28:04 volumio wireless.js[710]: trying... May 18 14:28:04 volumio sudo[1014]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 18 14:28:04 volumio sudo[1014]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:04 volumio sudo[1014]: pam_unix(sudo:session): session closed for user root May 18 14:28:05 volumio wireless.js[710]: trying... May 18 14:28:05 volumio sudo[1017]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 18 14:28:05 volumio sudo[1017]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:05 volumio sudo[1017]: pam_unix(sudo:session): session closed for user root May 18 14:28:06 volumio wireless.js[710]: trying... May 18 14:28:06 volumio sudo[1020]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 18 14:28:06 volumio sudo[1020]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:06 volumio sudo[1020]: pam_unix(sudo:session): session closed for user root May 18 14:28:07 volumio volumio-remote-updater[695]: [2025-05-18 14:28:07] [info] asio async_connect error: system:111 (Connection refused) May 18 14:28:07 volumio volumio-remote-updater[695]: [2025-05-18 14:28:07] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) May 18 14:28:07 volumio volumio-remote-updater[695]: [2025-05-18 14:28:07] [error] handle_connect error: Underlying Transport Error May 18 14:28:07 volumio wireless.js[710]: trying... May 18 14:28:07 volumio sudo[1023]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 18 14:28:07 volumio sudo[1023]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:07 volumio sudo[1023]: pam_unix(sudo:session): session closed for user root May 18 14:28:08 volumio dhcpcd[787]: wlan0: leased 192.168.31.173 for 43200 seconds May 18 14:28:08 volumio avahi-daemon[700]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.31.173. May 18 14:28:08 volumio avahi-daemon[700]: New relevant interface wlan0.IPv4 for mDNS. May 18 14:28:08 volumio avahi-daemon[700]: Registering new address record for 192.168.31.173 on wlan0.IPv4. May 18 14:28:08 volumio dhcpcd[787]: wlan0: adding route to 192.168.31.0/24 May 18 14:28:08 volumio dhcpcd[787]: wlan0: adding default route via 192.168.31.1 May 18 14:28:08 volumio wireless.js[710]: trying... May 18 14:28:08 volumio sudo[1039]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 18 14:28:08 volumio sudo[1039]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:08 volumio sudo[1039]: pam_unix(sudo:session): session closed for user root May 18 14:28:08 volumio wireless.js[710]: Connected to: ----Redmi_ZJ_5G May 18 14:28:08 volumio wireless.js[710]: ---- May 18 14:28:08 volumio sudo[1042]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 18 14:28:08 volumio sudo[1042]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:08 volumio sudo[1042]: pam_unix(sudo:session): session closed for user root May 18 14:28:08 volumio wireless.js[710]: ... joined AP, wlan0 IPv4 is 192.168.31.173, ipV6 is undefined May 18 14:28:08 volumio wireless.js[710]: It's done! AP May 18 14:28:08 volumio systemd[1]: Started Wireless Services. May 18 14:28:08 volumio systemd[1]: Started Volumio Backend Module. May 18 14:28:08 volumio systemd[1]: Started Intel SST and HDA soundcard init service. May 18 14:28:08 volumio systemd[1]: Started Volumio Cpu Tweaker. May 18 14:28:08 volumio systemd[1]: Started Start Volumio Kiosk. May 18 14:28:08 volumio volumio-cpu-tweak[1063]: Setting RT Priority for mpd May 18 14:28:08 volumio volumio-cpu-tweak[1063]: Not enough cores to set MPD affinity May 18 14:28:08 volumio volumio-cpu-tweak[1063]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance May 18 14:28:08 volumio systemd[1]: volumio_cpu_tweak.service: Succeeded. May 18 14:28:08 volumio ntpd[902]: ntpd exiting on signal 15 (Terminated) May 18 14:28:08 volumio systemd[1]: Stopping Network Time Service... May 18 14:28:08 volumio systemd[1]: ntp.service: Succeeded. May 18 14:28:08 volumio systemd[1]: Stopped Network Time Service. May 18 14:28:08 volumio systemd[1]: Starting Network Time Service... May 18 14:28:09 volumio ntpd[1111]: ntpd 4.2.8p12@1.3728-o (1): Starting May 18 14:28:09 volumio ntpd[1111]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 May 18 14:28:09 volumio ntpd[1127]: proto: precision = 0.315 usec (-22) May 18 14:28:09 volumio systemd[1]: Started Network Time Service. May 18 14:28:09 volumio ntpd[1127]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature May 18 14:28:09 volumio ntpd[1127]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 May 18 14:28:09 volumio ntpd[1127]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 873 days ago May 18 14:28:09 volumio ntpd[1127]: Listen and drop on 0 v6wildcard [::]:123 May 18 14:28:09 volumio ntpd[1127]: Listen and drop on 1 v4wildcard 0.0.0.0:123 May 18 14:28:09 volumio ntpd[1127]: Listen normally on 2 lo 127.0.0.1:123 May 18 14:28:09 volumio ntpd[1127]: Listen normally on 3 wlan0 192.168.31.173:123 May 18 14:28:09 volumio ntpd[1127]: Listening on routing socket on fd #20 for interface updates May 18 14:28:09 volumio ntpd[1127]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 18 14:28:09 volumio ntpd[1127]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 18 14:28:09 volumio startx[1067]: X.Org X Server 1.20.4 May 18 14:28:09 volumio startx[1067]: X Protocol Version 11, Revision 0 May 18 14:28:09 volumio startx[1067]: Build Operating System: Linux 5.10.0-10-amd64 x86_64 Debian May 18 14:28:09 volumio startx[1067]: Current Operating System: Linux volumio 6.6.32-volumio #2 SMP PREEMPT_DYNAMIC Wed May 29 23:04:42 CEST 2024 x86_64 May 18 14:28:09 volumio startx[1067]: Kernel command line: BOOT_IMAGE=vmlinuz initramfs.clear splash plymouth.ignore-serial-consoles quiet loglevel=0 biosdevname=0 imgpart=UUID=d0822069-d48a-490f-b8bc-9970c0b6e384 bootpart=UUID=1496-1547 datapart=UUID=a0bf3376-7b72-4c09-9fc2-d0970ff7651c 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 initrd=volumio.initrd May 18 14:28:09 volumio startx[1067]: Build Date: 18 December 2021 09:05:36AM May 18 14:28:09 volumio startx[1067]: xorg-server 2:1.20.4-1+deb10u4 (https://www.debian.org/support) May 18 14:28:09 volumio startx[1067]: Current version of pixman: 0.36.0 May 18 14:28:09 volumio startx[1067]: Before reporting problems, check http://wiki.x.org May 18 14:28:09 volumio startx[1067]: to make sure that you have the latest version. May 18 14:28:09 volumio startx[1067]: Markers: (--) probed, (**) from config file, (==) default setting, May 18 14:28:09 volumio startx[1067]: (++) from command line, (!!) notice, (II) informational, May 18 14:28:09 volumio startx[1067]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. May 18 14:28:09 volumio startx[1067]: (==) Log file: "/var/log/Xorg.0.log", Time: Sun May 18 14:28:09 2025 May 18 14:28:09 volumio startx[1067]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" May 18 14:28:09 volumio volumio-time-update[705]: volumio-time-update-util: Fetching time from Volumio... May 18 14:28:09 volumio startx[1067]: (II) [KMS] Kernel modesetting enabled. May 18 14:28:10 volumio ntpd[1127]: Soliciting pool server 95.111.202.5 May 18 14:28:10 volumio volumio-time-update[705]: volumio-time-update-util: Setting system time to: 2025-05-18 14:28:11 May 18 14:28:10 volumio sudo[1180]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-05-18 14:28:11 May 18 14:28:10 volumio sudo[1180]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:10 volumio dbus-daemon[687]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.8' (uid=0 pid=1183 comm="timedatectl set-time 2025-05-18 14:28:11 ") May 18 14:28:10 volumio systemd[1]: Starting Time & Date Service... May 18 14:28:10 volumio dbus-daemon[687]: [system] Successfully activated service 'org.freedesktop.timedate1' May 18 14:28:10 volumio systemd[1]: Started Time & Date Service. May 18 14:28:11 volumio systemd-timedated[1187]: Changed local time to Sun May 18 14:28:11 2025 May 18 14:28:11 volumio sudo[1180]: pam_unix(sudo:session): session closed for user root May 18 14:28:11 volumio volumio-time-update[705]: volumio-time-update-util: System time updated successfully. May 18 14:28:11 volumio systemd[1]: Started Volumio Time Update Utility. May 18 14:28:11 volumio ntpd[1127]: Soliciting pool server 117.80.231.60 May 18 14:28:11 volumio ntpd[1127]: Soliciting pool server 202.118.1.81 May 18 14:28:11 volumio systemd[1]: soundcard-init.service: Succeeded. May 18 14:28:11 volumio nmbd[872]: [2025/05/18 14:28:11.974264, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 18 14:28:11 volumio nmbd[872]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections May 18 14:28:11 volumio systemd[1]: Started Samba NMB Daemon. May 18 14:28:12 volumio systemd[1]: Starting Samba Winbind Daemon... May 18 14:28:12 volumio nmbd[872]: [2025/05/18 14:28:12.036373, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) May 18 14:28:12 volumio nmbd[872]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.31.173 for name WORKGROUP<1d>. May 18 14:28:12 volumio nmbd[872]: This response was from IP 192.168.31.210, reporting an IP address of 192.168.31.210. May 18 14:28:12 volumio nmbd[872]: [2025/05/18 14:28:12.037602, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) May 18 14:28:12 volumio nmbd[872]: query_name_response: Multiple (3) responses received for a query on subnet 192.168.31.173 for name WORKGROUP<1d>. May 18 14:28:12 volumio nmbd[872]: This response was from IP 192.168.31.210, reporting an IP address of 192.168.31.210. May 18 14:28:12 volumio nmbd[872]: [2025/05/18 14:28:12.037860, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) May 18 14:28:12 volumio nmbd[872]: query_name_response: Multiple (4) responses received for a query on subnet 192.168.31.173 for name WORKGROUP<1d>. May 18 14:28:12 volumio nmbd[872]: This response was from IP 192.168.31.210, reporting an IP address of 192.168.31.210. May 18 14:28:12 volumio ntpd[1127]: Soliciting pool server 119.28.183.184 May 18 14:28:12 volumio ntpd[1127]: Soliciting pool server 118.163.74.161 May 18 14:28:12 volumio winbindd[1237]: [2025/05/18 14:28:12.563581, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) May 18 14:28:12 volumio winbindd[1237]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 May 18 14:28:12 volumio winbindd[1237]: [2025/05/18 14:28:12.580027, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 18 14:28:12 volumio systemd[1]: Started Samba Winbind Daemon. May 18 14:28:12 volumio winbindd[1237]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections May 18 14:28:12 volumio systemd[1]: Starting Samba SMB Daemon... May 18 14:28:13 volumio ntpd[1127]: Soliciting pool server 162.159.200.1 May 18 14:28:13 volumio ntpd[1127]: Soliciting pool server 193.182.111.143 May 18 14:28:13 volumio systemd[1]: Started Samba SMB Daemon. May 18 14:28:13 volumio smbd[1243]: [2025/05/18 14:28:13.675400, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 18 14:28:13 volumio systemd[1]: Reached target Multi-User System. May 18 14:28:13 volumio smbd[1243]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections May 18 14:28:13 volumio systemd[1]: Reached target Graphical Interface. May 18 14:28:13 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... May 18 14:28:13 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. May 18 14:28:13 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. May 18 14:28:13 volumio systemd[1]: Startup finished in 30.766s (kernel) + 27.619s (userspace) = 58.386s. May 18 14:28:14 volumio volumio[1056]: info: ------------------------------------------- May 18 14:28:14 volumio volumio[1056]: info: ----- Volumio3 ---- May 18 14:28:14 volumio volumio[1056]: info: ------------------------------------------- May 18 14:28:14 volumio volumio[1056]: info: ----- System startup ---- May 18 14:28:14 volumio volumio[1056]: info: ------------------------------------------- May 18 14:28:16 volumio volumio[1056]: info: MYVOLUMIO Environment detected May 18 14:28:17 volumio volumio[1056]: info: Plugin folders cleanup May 18 14:28:17 volumio volumio[1056]: info: Scanning into folder /volumio/app/plugins/ May 18 14:28:17 volumio volumio[1056]: info: Scanning category audio_interface May 18 14:28:17 volumio volumio[1056]: info: Scanning category miscellanea May 18 14:28:17 volumio volumio[1056]: info: Scanning category music_service May 18 14:28:17 volumio volumio[1056]: info: Scanning category plugins.json May 18 14:28:17 volumio volumio[1056]: info: Scanning category system_controller May 18 14:28:17 volumio volumio[1056]: info: Scanning category user_interface May 18 14:28:17 volumio volumio[1056]: info: Scanning into folder /data/plugins/ May 18 14:28:17 volumio volumio[1056]: info: Scanning category music_service May 18 14:28:17 volumio volumio[1056]: info: Scanning category user_interface May 18 14:28:17 volumio volumio[1056]: info: Plugin folders cleanup completed May 18 14:28:17 volumio volumio[1056]: info: ------------------------------------------- May 18 14:28:17 volumio volumio[1056]: info: ----- Core plugins startup ---- May 18 14:28:17 volumio volumio[1056]: info: ------------------------------------------- May 18 14:28:17 volumio volumio[1056]: info: Loading plugins from folder /volumio/app/plugins/ May 18 14:28:17 volumio volumio[1056]: info: Adding plugin upnp to MyMusic Plugins May 18 14:28:17 volumio volumio[1056]: info: Adding plugin airplay_emulation to MyMusic Plugins May 18 14:28:17 volumio volumio[1056]: info: Adding plugin upnp_browser to MyMusic Plugins May 18 14:28:17 volumio volumio[1056]: info: Loading plugins from folder /data/plugins/ May 18 14:28:17 volumio volumio[1056]: info: Loading plugin "system"... May 18 14:28:17 volumio volumio-remote-updater[695]: [2025-05-18 14:28:17] [connect] Successful connection May 18 14:28:17 volumio volumio[1056]: info: Loading plugin "appearance"... May 18 14:28:20 volumio ntpd[1127]: receive: Unexpected origin timestamp 0xebd3fc83.46ebcd73 does not match aorg 0000000000.00000000 from server@95.111.202.5 xmt 0xebd3fc84.cd6d83e2 May 18 14:28:21 volumio volumio[1056]: info: Loading plugin "network"... May 18 14:28:21 volumio volumio[1056]: info: Refreshing Cached IP Addresses May 18 14:28:21 volumio sudo[1332]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 18 14:28:21 volumio sudo[1332]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:21 volumio sudo[1332]: pam_unix(sudo:session): session closed for user root May 18 14:28:21 volumio sudo[1334]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 18 14:28:21 volumio sudo[1334]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:21 volumio sudo[1334]: pam_unix(sudo:session): session closed for user root May 18 14:28:21 volumio volumio[1056]: info: Loading plugin "services"... May 18 14:28:21 volumio volumio[1056]: info: Loading plugin "alsa_controller"... May 18 14:28:22 volumio sudo[1343]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 18 14:28:22 volumio sudo[1343]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:22 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 18 14:28:22 volumio volumio[1056]: info: Loading plugin "wizard"... May 18 14:28:22 volumio volumio[1056]: info: Loading plugin "networkfs"... May 18 14:28:23 volumio volumio[1056]: info: Starting Udev Watcher for removable devices May 18 14:28:23 volumio volumio[1056]: info: Ignoring mount for partition: boot May 18 14:28:23 volumio volumio[1056]: info: Ignoring mount for partition: volumio May 18 14:28:23 volumio volumio[1056]: info: Ignoring mount for partition: volumio_data May 18 14:28:23 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 18 14:28:23 volumio volumio[1056]: info: Loading plugin "volumio_command_line_client"... May 18 14:28:23 volumio sudo[1363]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=BG4BWN,password=ZHANGjun19790130,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,vers=3.11 //192.168.31.210/音乐 /mnt/NAS/音乐 May 18 14:28:23 volumio sudo[1363]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:23 volumio volumio[1056]: info: Loading plugin "upnp"... May 18 14:28:23 volumio volumio[1056]: info: [1747549703236] Starting Upmpd Daemon May 18 14:28:23 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 18 14:28:23 volumio volumio[1056]: info: Loading plugin "my_music"... May 18 14:28:23 volumio volumio[1056]: info: Loading plugin "mpd"... May 18 14:28:23 volumio kernel: FS-Cache: Loaded May 18 14:28:23 volumio kernel: Key type dns_resolver registered May 18 14:28:23 volumio kernel: Key type cifs.spnego registered May 18 14:28:23 volumio kernel: Key type cifs.idmap registered May 18 14:28:23 volumio kernel: CIFS: Attempting to mount //192.168.31.210/音乐 May 18 14:28:23 volumio sudo[1363]: pam_unix(sudo:session): session closed for user root May 18 14:28:23 volumio systemd[1]: systemd-fsckd.service: Succeeded. May 18 14:28:24 volumio volumio[1056]: info: Loading plugin "upnp_browser"... May 18 14:28:24 volumio sudo[1343]: pam_unix(sudo:session): session closed for user root May 18 14:28:25 volumio volumio[1056]: info: Loading plugin "alarm-clock"... May 18 14:28:25 volumio sh[616]: timed out May 18 14:28:25 volumio sh[616]: dhcpcd exited May 18 14:28:25 volumio dhcpcd[667]: timed out May 18 14:28:25 volumio sh[616]: ifup: failed to bring up eth0 May 18 14:28:25 volumio dhcpcd[667]: dhcpcd exited May 18 14:28:25 volumio systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE May 18 14:28:25 volumio systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. May 18 14:28:25 volumio volumio[1056]: info: Loading plugin "airplay_emulation"... May 18 14:28:25 volumio volumio[1056]: info: Starting Shairport Sync May 18 14:28:25 volumio volumio[1056]: info: Loading plugin "last_100"... May 18 14:28:25 volumio volumio[1056]: info: Loading plugin "webradio"... May 18 14:28:25 volumio volumio[1056]: info: Loading plugin "i2s_dacs"... May 18 14:28:26 volumio volumio[1056]: info: I2S DAC not set, start Auto-detection May 18 14:28:26 volumio volumio[1056]: info: Loading plugin "volumiodiscovery"... May 18 14:28:26 volumio volumio[1056]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 18 14:28:26 volumio volumio[1056]: *** WARNING *** Please fix your application to use the native API of Avahi! May 18 14:28:26 volumio volumio[1056]: *** WARNING *** For more information see May 18 14:28:26 volumio volumio[1056]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 18 14:28:26 volumio volumio[1056]: *** WARNING *** Please fix your application to use the native API of Avahi! May 18 14:28:26 volumio volumio[1056]: *** WARNING *** For more information see May 18 14:28:26 volumio node[1056]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 18 14:28:26 volumio node[1056]: *** WARNING *** Please fix your application to use the native API of Avahi! May 18 14:28:26 volumio node[1056]: *** WARNING *** For more information see May 18 14:28:26 volumio node[1056]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 18 14:28:26 volumio node[1056]: *** WARNING *** Please fix your application to use the native API of Avahi! May 18 14:28:26 volumio node[1056]: *** WARNING *** For more information see May 18 14:28:26 volumio volumio[1056]: info: Applying required configuration parameters for plugin volumiodiscovery May 18 14:28:26 volumio volumio[1056]: info: Discovery: Started advertising with name: Volumio May 18 14:28:26 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 18 14:28:26 volumio volumio[1056]: info: Loading plugin "jellyfin"... May 18 14:28:27 volumio systemd[1]: systemd-hostnamed.service: Succeeded. May 18 14:28:28 volumio volumio[1056]: info: Loading plugin "peppy_screensaver"... May 18 14:28:29 volumio volumio[1056]: info: Applying required configuration parameters for plugin peppy_screensaver May 18 14:28:29 volumio volumio[1056]: info: Loading plugin "outputs"... May 18 14:28:29 volumio volumio[1056]: info: Loading plugin "albumart"... May 18 14:28:29 volumio volumio[1056]: info: Plugin example_plugin is not enabled May 18 14:28:29 volumio volumio[1056]: info: Loading plugin "inputs"... May 18 14:28:29 volumio volumio[1056]: info: Loading plugin "updater_comm"... May 18 14:28:29 volumio volumio[1056]: Forking 1 albumart workers May 18 14:28:29 volumio volumio[1056]: info: Plugin mpdemulation is not enabled May 18 14:28:29 volumio volumio[1056]: info: Loading plugin "rest_api"... May 18 14:28:29 volumio volumio[1056]: info: Loading plugin "websocket"... May 18 14:28:29 volumio volumio[1056]: info: Starting Socket.io Server version 2.3.0 May 18 14:28:29 volumio volumio[1056]: info: Loading plugin "RoonBridge"... May 18 14:28:30 volumio volumio[1056]: info: Applying required configuration parameters for plugin RoonBridge May 18 14:28:30 volumio volumio[1056]: info: Loading plugin "minidlna"... May 18 14:28:30 volumio volumio[1056]: info: Applying required configuration parameters for plugin minidlna May 18 14:28:30 volumio volumio[1056]: Starting albumart workers May 18 14:28:30 volumio volumio[1056]: info: Loading i18n strings for locale zh May 18 14:28:30 volumio volumio[1056]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. May 18 14:28:30 volumio volumio[1056]: Updating browse sources language May 18 14:28:30 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 18 14:28:31 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 14:28:31 volumio volumio[1056]: info: CoreCommandRouter::initPlayerControls May 18 14:28:31 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:31 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:31 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:31 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:31 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:31 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:31 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:31 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:31 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 14:28:31 volumio volumio[1056]: Express server listening on port 3000 May 18 14:28:31 volumio volumio[1056]: [Metrics] WebUI: 17s 630.87ms May 18 14:28:31 volumio volumio[1056]: info: Setting Device type: x86 May 18 14:28:31 volumio volumio[1056]: info: CoreStateMachine::resetVolumioState May 18 14:28:31 volumio volumio[1056]: info: CoreStateMachine::getcurrentVolume May 18 14:28:31 volumio volumio[1056]: info: CoreCommandRouter::volumioRetrievevolume May 18 14:28:31 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:28:31 volumio volumio[1056]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' May 18 14:28:31 volumio volumio[1056]: info: Completed loading Core Plugins May 18 14:28:31 volumio volumio[1056]: info: Preparing to generate the ALSA configuration file May 18 14:28:31 volumio volumio[1056]: info: Volumio Network Manager: Network status updated: 2 May 18 14:28:31 volumio volumio[1056]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision May 18 14:28:31 volumio volumio[1056]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf May 18 14:28:31 volumio volumio[1056]: info: Reading ALSA contributions from plugins. May 18 14:28:31 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:28:31 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:28:31 volumio volumio[1056]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 May 18 14:28:31 volumio volumio[1056]: info: Reloading queue from file May 18 14:28:31 volumio volumio[1056]: info: VolumeController:: Volume=79 Mute =false May 18 14:28:31 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:28:31 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:28:31 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:28:31 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:28:31 volumio volumio[1056]: info: CoreStateMachine::updateTrackBlock May 18 14:28:31 volumio volumio[1056]: info: CorePlayQueue::getTrackBlock May 18 14:28:31 volumio volumio[1056]: info: CoreCommandRouter::volumioRetrievevolume May 18 14:28:31 volumio volumio[1056]: info: CoreStateMachine::setRepeat null single undefined May 18 14:28:32 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:28:32 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:28:32 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:28:32 volumio volumio[1056]: info: CoreStateMachine::setRandom null May 18 14:28:32 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:28:32 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:28:32 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:28:32 volumio volumio[1056]: info: Discovery: adding 6576be8c-9ca3-4f6e-ad09-3e064e726785 May 18 14:28:32 volumio volumio[1056]: info: Discovery: Found device Volumio May 18 14:28:32 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:28:32 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:28:32 volumio volumio[1056]: info: Asound.conf file unchanged, so no further update is needed May 18 14:28:32 volumio volumio[1056]: info: Output device has changed, restarting MPD May 18 14:28:32 volumio sudo[1513]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 18 14:28:32 volumio sudo[1513]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:32 volumio sudo[1513]: pam_unix(sudo:session): session closed for user root May 18 14:28:32 volumio volumio[1056]: info: Output device has changed, restarting Shairport Sync May 18 14:28:32 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:32 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:28:32 volumio sudo[1516]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 18 14:28:32 volumio sudo[1516]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:32 volumio volumio[1056]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 18 14:28:32 volumio volumio[1056]: info: ___________ START PLUGINS ___________ May 18 14:28:32 volumio systemd[1]: Stopping Music Player Daemon... May 18 14:28:32 volumio volumio[1056]: info: ControllerMpd::onStart: Initializing MPD May 18 14:28:32 volumio volumio[1056]: info: Creating MPD Configuration file May 18 14:28:32 volumio systemd[1]: mpd.service: Succeeded. May 18 14:28:32 volumio systemd[1]: Stopped Music Player Daemon. May 18 14:28:32 volumio systemd[1]: Starting Music Player Daemon... May 18 14:28:32 volumio sudo[1524]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 18 14:28:32 volumio sudo[1524]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:32 volumio sudo[1524]: pam_unix(sudo:session): session closed for user root May 18 14:28:32 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 14:28:32 volumio volumio[1056]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 18 14:28:32 volumio volumio[1056]: info: [1747549712737] CoreMusicLibrary::Adding element 媒体服务器 May 18 14:28:32 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 18 14:28:32 volumio sudo[1527]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 18 14:28:32 volumio sudo[1527]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:32 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM May 18 14:28:32 volumio systemd[1]: mpd.service: Succeeded. May 18 14:28:32 volumio systemd[1]: Stopped Music Player Daemon. May 18 14:28:32 volumio systemd[1]: Starting Music Player Daemon... May 18 14:28:32 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:32 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:28:33 volumio sudo[1529]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 18 14:28:33 volumio sudo[1529]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:33 volumio volumio[1056]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 18 14:28:33 volumio sudo[1529]: pam_unix(sudo:session): session closed for user root May 18 14:28:33 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:33 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:28:33 volumio volumio[1056]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 18 14:28:33 volumio volumio[1056]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 18 14:28:33 volumio volumio[1056]: info: [1747549713138] CoreMusicLibrary::Adding element Last_100 May 18 14:28:33 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 18 14:28:33 volumio volumio[1056]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 18 14:28:33 volumio volumio[1056]: info: [1747549713149] CoreMusicLibrary::Adding element Webradio May 18 14:28:33 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 18 14:28:33 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 18 14:28:33 volumio volumio[1056]: info: Initializing BBC Radios May 18 14:28:33 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 18 14:28:33 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:28:33 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 18 14:28:33 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 14:28:33 volumio volumio[1056]: info: Discovery: Getting this device information May 18 14:28:33 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:28:33 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:28:33 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 14:28:33 volumio volumio[1056]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 18 14:28:33 volumio volumio[1056]: info: [1747549713517] CoreMusicLibrary::Adding element Jellyfin May 18 14:28:33 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 18 14:28:33 volumio volumio[1056]: Cannot find translation for source Jellyfin May 18 14:28:33 volumio volumio[1056]: info: [jellyfin] Initialized plugin with device info: {"id":"6576be8c-9ca3-4f6e-ad09-3e064e726785","host":"http://192.168.31.173","name":"Volumio","type":"device","serviceName":"Volumio","state":{"status":"stop","volume":79,"mute":false,"artist":"","track":"","albumart":"http://192.168.31.173/albumart"}} May 18 14:28:33 volumio volumio[1056]: info: Loading i18n strings for locale zh May 18 14:28:33 volumio volumio[1056]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. May 18 14:28:33 volumio volumio[1056]: info: /tmp/myfifo created May 18 14:28:33 volumio volumio[1056]: info: /tmp/myfifosa created May 18 14:28:33 volumio volumio-remote-updater[695]: [2025-05-18 14:28:33] [connect] Successful connection May 18 14:28:33 volumio sudo[1553]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd-dummy index=7 pcm_substreams=1 fake_buffer=0 May 18 14:28:33 volumio sudo[1553]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:33 volumio sudo[1553]: pam_unix(sudo:session): session closed for user root May 18 14:28:33 volumio volumio[1056]: info: snd-dummy loaded May 18 14:28:34 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:28:34 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:34 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:34 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startShairportSync May 18 14:28:34 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:34 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:28:34 volumio volumio[1056]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 18 14:28:34 volumio volumio[1056]: info: Loading i18n strings for locale zh May 18 14:28:34 volumio volumio[1056]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. May 18 14:28:34 volumio sudo[1573]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service May 18 14:28:34 volumio sudo[1573]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:34 volumio volumio[1056]: info: Volumio Calling Home May 18 14:28:34 volumio sudo[1573]: pam_unix(sudo:session): session closed for user root May 18 14:28:34 volumio systemd[1]: Started RoonBridge. May 18 14:28:36 volumio volumio[1056]: info: VolumeController:: Volume=79 Mute =false May 18 14:28:36 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:28:36 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:28:36 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:28:36 volumio sudo[1591]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 18 14:28:36 volumio sudo[1591]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:36 volumio sudo[1591]: pam_unix(sudo:session): session closed for user root May 18 14:28:36 volumio volumio[1056]: info: minidlna: Found miniDLNA version 1.2.1 May 18 14:28:36 volumio volumio[1056]: info: minidlna: Starting minidlna.service May 18 14:28:36 volumio sudo[1593]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 18 14:28:36 volumio sudo[1593]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:36 volumio sudo[1593]: pam_unix(sudo:session): session closed for user root May 18 14:28:36 volumio mpd[1534]: May 18 14:28 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 18 14:28:36 volumio volumio[1056]: info: MPD Permissions set May 18 14:28:36 volumio volumio[1056]: info: MPD Permissions set May 18 14:28:36 volumio sudo[1597]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start minidlna.service May 18 14:28:36 volumio sudo[1597]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:36 volumio volumio-remote-updater[695]: [2025-05-18 14:28:36] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1747549713 101 May 18 14:28:36 volumio systemd[1]: Started MiniDLNA lightweight DLNA/UPnP-AV server. May 18 14:28:36 volumio volumio[1056]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 2 May 18 14:28:36 volumio sudo[1597]: pam_unix(sudo:session): session closed for user root May 18 14:28:36 volumio volumio[1056]: info: Volumio called home May 18 14:28:37 volumio sudo[1604]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount --bind /tmp/mpd.conf.tmpl /volumio/app/plugins/music_service/mpd/mpd.conf.tmpl May 18 14:28:37 volumio sudo[1604]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:37 volumio sudo[1604]: pam_unix(sudo:session): session closed for user root May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:28:37 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:28:37 volumio systemd[1]: Started Music Player Daemon. May 18 14:28:37 volumio sudo[1516]: pam_unix(sudo:session): session closed for user root May 18 14:28:37 volumio volumio[1056]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 May 18 14:28:37 volumio sudo[1527]: pam_unix(sudo:session): session closed for user root May 18 14:28:37 volumio volumio[1056]: info: minidlna: systemctl start minidlna.service succeeded. May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 18 14:28:37 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:37 volumio RoonBridge[1577]: 00:00:00.029 Warn: get lock file path: /tmp/.rnbgem0- May 18 14:28:38 volumio volumio[1056]: info: Completed starting Core Plugins May 18 14:28:38 volumio volumio[1056]: info: ------------------------------------------- May 18 14:28:38 volumio volumio[1056]: info: ----- MyVolumio plugins startup ---- May 18 14:28:38 volumio volumio[1056]: info: ------------------------------------------- May 18 14:28:38 volumio volumio[1056]: info: [MyVolumio PluginManager] Fetching plans data.... May 18 14:28:38 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , createMPDFile May 18 14:28:38 volumio sudo[1626]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 18 14:28:38 volumio sudo[1626]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:38 volumio sudo[1626]: pam_unix(sudo:session): session closed for user root May 18 14:28:38 volumio volumio[1056]: info: MPD running with PID1534 May 18 14:28:38 volumio volumio[1056]: ,establishing connection May 18 14:28:38 volumio systemd[1]: minidlna.service: Succeeded. May 18 14:28:38 volumio RoonBridge[1577]: 00:00:01.153 Trace: [childprocess] using unix child process May 18 14:28:38 volumio volumio[1056]: error: MPD error: The expression evaluated to a falsy value: May 18 14:28:38 volumio volumio[1056]: assert.ok(self.idling) May 18 14:28:38 volumio volumio[1056]: error: The expression evaluated to a falsy value: May 18 14:28:38 volumio volumio[1056]: assert.ok(self.idling) May 18 14:28:38 volumio volumio[1056]: error: MPD error: The expression evaluated to a falsy value: May 18 14:28:38 volumio volumio[1056]: assert.ok(self.idling) May 18 14:28:38 volumio volumio[1056]: error: The expression evaluated to a falsy value: May 18 14:28:38 volumio volumio[1056]: assert.ok(self.idling) May 18 14:28:38 volumio volumio[1056]: info: MPD Permissions set May 18 14:28:38 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd May 18 14:28:38 volumio volumio[1056]: info: Starting Shairport Sync May 18 14:28:38 volumio RoonBridge[1577]: 00:00:01.293 Debug: PathForResource, filename: ../.update May 18 14:28:38 volumio sudo[1631]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 18 14:28:38 volumio sudo[1631]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:38 volumio volumio[1056]: info: Starting Shairport Sync May 18 14:28:38 volumio systemd[1]: Stopping Music Player Daemon... May 18 14:28:39 volumio RoonBridge[1577]: 00:00:01.364 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/../.update May 18 14:28:39 volumio RoonBridge[1577]: 00:00:01.381 Debug: PathForResource, filename: RAATServer May 18 14:28:39 volumio RoonBridge[1577]: 00:00:01.381 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RAATServer May 18 14:28:39 volumio RoonBridge[1577]: 00:00:01.391 Debug: PathForResource, filename: RoonBridgeHelper May 18 14:28:39 volumio RoonBridge[1577]: 00:00:01.391 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RoonBridgeHelper May 18 14:28:39 volumio RoonBridge[1577]: Initializing May 18 14:28:39 volumio volumio[1056]: info: Starting Shairport Sync May 18 14:28:39 volumio sudo[1634]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 18 14:28:39 volumio sudo[1634]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:39 volumio systemd[1]: mpd.service: Succeeded. May 18 14:28:39 volumio systemd[1]: Stopped Music Player Daemon. May 18 14:28:39 volumio systemd[1]: Starting Music Player Daemon... May 18 14:28:39 volumio volumio[1056]: info: Starting Shairport Sync May 18 14:28:39 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 18 14:28:39 volumio systemd[1]: shairport-sync.service: Succeeded. May 18 14:28:39 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 18 14:28:39 volumio sudo[1637]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 18 14:28:39 volumio sudo[1637]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:39 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 18 14:28:39 volumio RoonBridge[1577]: 00:00:01.608 Info: Starting /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RoonBridgeHelper May 18 14:28:39 volumio sudo[1634]: pam_unix(sudo:session): session closed for user root May 18 14:28:39 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 18 14:28:39 volumio systemd[1]: shairport-sync.service: Succeeded. May 18 14:28:39 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 18 14:28:39 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 18 14:28:39 volumio sudo[1637]: pam_unix(sudo:session): session closed for user root May 18 14:28:39 volumio sudo[1641]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 18 14:28:39 volumio sudo[1644]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 18 14:28:39 volumio sudo[1644]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:39 volumio sudo[1641]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:39 volumio RoonBridge[1577]: 00:00:01.829 Info: ConnectOrStartAndWaitForExit RAATServer, path: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RAATServer May 18 14:28:39 volumio sudo[1641]: pam_unix(sudo:session): session closed for user root May 18 14:28:39 volumio sudo[1649]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 18 14:28:39 volumio sudo[1649]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:39 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 18 14:28:39 volumio systemd[1]: shairport-sync.service: Succeeded. May 18 14:28:39 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 18 14:28:39 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 18 14:28:39 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 18 14:28:39 volumio sudo[1644]: pam_unix(sudo:session): session closed for user root May 18 14:28:39 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 18 14:28:39 volumio systemd[1]: shairport-sync.service: Succeeded. May 18 14:28:39 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 18 14:28:39 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 18 14:28:39 volumio sudo[1649]: pam_unix(sudo:session): session closed for user root May 18 14:28:39 volumio sudo[1659]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 18 14:28:39 volumio sudo[1659]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:39 volumio volumio[1056]: error: MPD error: Error: write EPIPE May 18 14:28:39 volumio volumio[1056]: error: write EPIPE {"errno":-32,"code":"EPIPE","syscall":"write"} May 18 14:28:39 volumio systemd[1]: Started UPnP Renderer front-end to MPD. May 18 14:28:39 volumio sudo[1659]: pam_unix(sudo:session): session closed for user root May 18 14:28:40 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:28:40 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:28:40 volumio RoonBridge[1577]: Not Running (.o) May 18 14:28:40 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:40 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:40 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:40 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:28:40 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 18 14:28:40 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:28:40 volumio volumio[1056]: info: Upmpdcli Daemon Started May 18 14:28:40 volumio volumio[1056]: info: Shairport-Sync Started May 18 14:28:40 volumio volumio[1056]: Error adding Membership: Error: addMembership EINVAL May 18 14:28:40 volumio volumio[1056]: info: Shairport-Sync Started May 18 14:28:40 volumio volumio[1056]: info: Shairport-Sync Started May 18 14:28:40 volumio volumio[1056]: info: Shairport-Sync Started May 18 14:28:41 volumio RoonBridge[1577]: Running May 18 14:28:42 volumio systemd[1]: systemd-timedated.service: Succeeded. May 18 14:28:42 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:28:42 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:28:43 volumio mpd[1655]: May 18 14:28 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 18 14:28:43 volumio volumio[1056]: Upnp client error: Error: This socket has been ended by the other party May 18 14:28:43 volumio systemd[1]: Started Music Player Daemon. May 18 14:28:43 volumio sudo[1631]: pam_unix(sudo:session): session closed for user root May 18 14:28:43 volumio volumio[1056]: error: updateQueue error: null May 18 14:28:44 volumio RoonBridge[1577]: 00:00:00.212 Warn: get lock file path: /tmp/.rnbhgem0- May 18 14:28:44 volumio volumio[1672]: Generating RSA private key, 4096 bit long modulus (2 primes) May 18 14:28:45 volumio volumio[1672]: ....................++++ May 18 14:28:45 volumio volumio[1056]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso May 18 14:28:47 volumio volumio[1056]: info: Adding plugin bluetooth to MyMusic Plugins May 18 14:28:47 volumio volumio[1056]: info: Adding plugin multiroom to MyMusic Plugins May 18 14:28:47 volumio volumio[1056]: info: Adding plugin metavolumio to MyMusic Plugins May 18 14:28:47 volumio volumio[1056]: info: Adding plugin cd_controller to MyMusic Plugins May 18 14:28:47 volumio volumio[1056]: info: Adding plugin qobuzconnect to MyMusic Plugins May 18 14:28:47 volumio volumio[1056]: info: Adding plugin smart_inputs to MyMusic Plugins May 18 14:28:47 volumio volumio[1056]: info: Adding plugin tidalconnect to MyMusic Plugins May 18 14:28:47 volumio volumio[1056]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... May 18 14:28:48 volumio RoonBridge[1577]: 00:00:10.844 Warn: exception starting raatserver: System.Net.Sockets.SocketException (0x80004005): Connection refused May 18 14:28:48 volumio RoonBridge[1577]: at System.Net.Sockets.TcpClient..ctor (System.String hostname, System.Int32 port) [0x0006d] in <08911f3881ec4a92acc8fdc4d13b73bf>:0 May 18 14:28:48 volumio RoonBridge[1577]: at Sooloos.RAATServer.ConnectOrStartAndWaitForExit (System.String path, System.String args, System.Action`1[T] status, Base.ChildProcess& p) [0x00165] in <5529660cb9214b5a92e49e1607b30d50>:0 May 18 14:28:48 volumio RoonBridge[1577]: Not Running (.o) May 18 14:28:48 volumio RoonBridge[1577]: 00:00:11.097 Debug: PathForResource, filename: ../.update May 18 14:28:48 volumio RoonBridge[1577]: 00:00:11.109 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/../.update May 18 14:28:49 volumio volumio[1672]: ............................................................++++ May 18 14:28:49 volumio volumio[1672]: e is 65537 (0x010001) May 18 14:28:49 volumio volumio[1672]: writing RSA key May 18 14:28:50 volumio RoonBridge[1577]: 00:00:13.110 Info: ConnectOrStartAndWaitForExit RAATServer, path: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RAATServer May 18 14:28:50 volumio RoonBridge[1577]: Running May 18 14:28:51 volumio volumio[1056]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded May 18 14:28:51 volumio volumio[1056]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio May 18 14:28:51 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:28:51 volumio volumio[1056]: info: Starting MyVolumio Remote Streaming Endpoints May 18 14:28:51 volumio volumio[1056]: info: MyVolumio login type: Token May 18 14:28:51 volumio volumio[1056]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started May 18 14:28:51 volumio volumio[1056]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... May 18 14:28:53 volumio volumio[1056]: info: Starting Streaming Service Transparent Proxy May 18 14:28:53 volumio volumio[1056]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded May 18 14:28:53 volumio volumio[1056]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services May 18 14:28:53 volumio volumio[1056]: info: Streaming services startup May 18 14:28:53 volumio volumio[1056]: info: Starting Streaming Daemon May 18 14:28:53 volumio sudo[1971]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 18 14:28:53 volumio sudo[1971]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:28:54 volumio sudo[1971]: pam_unix(sudo:session): session closed for user root May 18 14:28:54 volumio volumio[1056]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started May 18 14:28:54 volumio volumio[1056]: error: Cannot start Volumio Streaming Daemon May 18 14:28:54 volumio volumio[1056]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 18 14:28:54 volumio volumio[1056]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 18 14:28:54 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:28:54 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:28:55 volumio volumio[1056]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN May 18 14:28:56 volumio volumio[1056]: STREAMING PROXY: Starting server on port 3245 May 18 14:28:56 volumio volumio[1056]: Node JS runtime: 14 May 18 14:28:58 volumio volumio[1056]: info: MyVolumio token set successfully May 18 14:28:58 volumio volumio[1056]: info: MYVOLUMIO: Adding device May 18 14:28:58 volumio volumio[1056]: info: MYVOLUMIO: Evaluating Server May 18 14:28:59 volumio volumio[1056]: info: MyVolumio status changed May 18 14:28:59 volumio volumio[1056]: info: Streaming services startup May 18 14:28:59 volumio volumio[1056]: info: Starting Streaming Daemon May 18 14:28:59 volumio volumio[1056]: info: Removing browser output: myVolumio user plan is not superstar May 18 14:28:59 volumio volumio[1056]: info: Removing audio output: May 18 14:28:59 volumio volumio[1056]: info: Stoppping Tunnel 1 May 18 14:29:00 volumio sudo[2055]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 18 14:29:00 volumio sudo[2055]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:29:00 volumio sudo[2055]: pam_unix(sudo:session): session closed for user root May 18 14:29:00 volumio sudo[2058]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service May 18 14:29:00 volumio sudo[2058]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:29:00 volumio volumio[1056]: error: Cannot start Volumio Streaming Daemon May 18 14:29:00 volumio volumio[1056]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 18 14:29:00 volumio volumio[1056]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 18 14:29:00 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 14:29:00 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 14:29:00 volumio volumio[1056]: info: Discovery: Getting this device information May 18 14:29:00 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:00 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:00 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 14:29:00 volumio volumio[1056]: verbose: New Socket.io Connection to 192.168.31.173:3000 from 192.168.31.108 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 5 May 18 14:29:00 volumio sudo[2058]: pam_unix(sudo:session): session closed for user root May 18 14:29:00 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:00 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:00 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 18 14:29:00 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 18 14:29:00 volumio volumio[1056]: info: Remote SSH Stopped May 18 14:29:01 volumio volumio[1056]: info: Setting Geolocation for MyVolumio to us2 May 18 14:29:01 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:29:01 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:29:01 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:29:01 volumio volumio[1056]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 May 18 14:29:02 volumio volumio[1056]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} May 18 14:29:02 volumio volumio[1056]: info: Updating MyVolumio device info May 18 14:29:02 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:29:03 volumio volumio[1056]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} May 18 14:29:04 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 18 14:29:04 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:29:04 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 18 14:29:04 volumio volumio[1056]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 May 18 14:29:04 volumio volumio-remote-updater[695]: No test mode May 18 14:29:04 volumio volumio-remote-updater[695]: No alpha test mode May 18 14:29:04 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 18 14:29:04 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::volumioGetVisibleSources May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:05 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 18 14:29:05 volumio volumio[1056]: info: Received Get System Info May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 14:29:05 volumio volumio[1056]: info: Discovery: Getting this device information May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:05 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:05 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:05 volumio volumio[1056]: info: Listing playlists May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 18 14:29:05 volumio volumio[1056]: info: Received Get System Info May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 14:29:05 volumio volumio[1056]: info: Discovery: Getting this device information May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:05 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:05 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::volumioGetVisibleSources May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:05 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:05 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 18 14:29:05 volumio volumio[1056]: info: Received Get System Info May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 14:29:05 volumio volumio[1056]: info: Discovery: Getting this device information May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:05 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:05 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:05 volumio volumio[1056]: info: Listing playlists May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 18 14:29:05 volumio volumio[1056]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 18 14:29:05 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:05 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:06 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 18 14:29:06 volumio volumio[1056]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 May 18 14:29:06 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:06 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:06 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 18 14:29:06 volumio volumio[1056]: info: Received Get System Info May 18 14:29:06 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 14:29:06 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 14:29:06 volumio volumio[1056]: info: Discovery: Getting this device information May 18 14:29:06 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:06 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:06 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 14:29:06 volumio volumio[1056]: info: MYVOLUMIO: Adding device May 18 14:29:06 volumio volumio[1056]: info: MYVOLUMIO: Evaluating Server May 18 14:29:06 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 14:29:06 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 14:29:06 volumio volumio[1056]: info: Discovery: Getting this device information May 18 14:29:06 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:06 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:06 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 14:29:07 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 18 14:29:08 volumio volumio[1056]: info: Setting Geolocation for MyVolumio to us2 May 18 14:29:08 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:29:08 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:29:09 volumio volumio[1056]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} May 18 14:29:09 volumio volumio[1056]: info: Updating MyVolumio device info May 18 14:29:09 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:29:09 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:29:09 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:29:10 volumio volumio[1056]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} May 18 14:29:11 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:29:11 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:29:11 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 18 14:29:11 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 18 14:29:11 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 18 14:29:11 volumio volumio[1056]: info: CoreCommandRouter::volumioGetBrowseSources May 18 14:29:11 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 18 14:29:11 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 18 14:29:14 volumio volumio[1056]: error: MyVolumio Plugin failed to authenticate in a timely fashion May 18 14:29:14 volumio volumio[1056]: info: Completed starting MyVolumio Plugin May 18 14:29:14 volumio volumio[1056]: [Metrics] CommandRouter: 58s 560.02ms May 18 14:29:14 volumio volumio[1056]: info: CoreCommandRouter::volumiosetStartupVolume May 18 14:29:14 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 14:29:14 volumio volumio[1056]: info: VolumeController:: Setting startup Volume 80 May 18 14:29:14 volumio volumio[1056]: info: VolumeController::SetAlsaVolume80 May 18 14:29:14 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 14:29:14 volumio volumio[1056]: info: CoreCommandRouter::Close All Modals sent May 18 14:29:14 volumio volumio[1056]: info: CoreCommandRouter::Close All Modals sent May 18 14:29:14 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:14 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:14 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:14 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:15 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 18 14:29:15 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 18 14:29:15 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 18 14:29:16 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 18 14:29:16 volumio volumio[1056]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 18 14:29:16 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 18 14:29:16 volumio volumio[1056]: info: Received Get System Version May 18 14:29:16 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 18 14:29:16 volumio volumio[1056]: info: Received Get System Info May 18 14:29:16 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 14:29:16 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 14:29:16 volumio volumio[1056]: info: Discovery: Getting this device information May 18 14:29:16 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:16 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:16 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 14:29:17 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:17 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:18 volumio ntpd[1127]: Soliciting pool server 202.118.1.130 May 18 14:29:20 volumio ntpd[1127]: Soliciting pool server 114.34.171.136 May 18 14:29:21 volumio volumio[1056]: info: BOOT COMPLETED May 18 14:29:21 volumio ntpd[1127]: Soliciting pool server 193.182.111.142 May 18 14:29:23 volumio ntpd[1127]: Soliciting pool server 45.76.221.157 May 18 14:29:24 volumio volumio[1056]: info: Clearing queue after UPNP request May 18 14:29:24 volumio volumio[1056]: info: CoreStateMachine::ClearQueue May 18 14:29:24 volumio volumio[1056]: info: CoreStateMachine::stop May 18 14:29:24 volumio volumio[1056]: info: CoreStateMachine::setConsumeUpdateService undefined May 18 14:29:24 volumio volumio[1056]: info: CorePlayQueue::clearPlayQueue May 18 14:29:24 volumio volumio[1056]: info: CorePlayQueue::saveQueue May 18 14:29:24 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:24 volumio volumio[1056]: info: CoreCommandRouter::volumioPushQueue May 18 14:29:24 volumio volumio[1056]: info: May 18 14:29:24 volumio volumio[1056]: ---------------------------- MPD announces system playlist update May 18 14:29:24 volumio volumio[1056]: info: Ignoring MPD Status Update May 18 14:29:24 volumio volumio[1056]: error: updateQueue error: null May 18 14:29:24 volumio volumio[1056]: info: ------------------------------ 6ms May 18 14:29:24 volumio volumio[1056]: info: Starting UPNP Playback May 18 14:29:24 volumio volumio[1056]: info: Preparing playback through UPNP May 18 14:29:24 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:24 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:24 volumio volumio[1056]: info: CoreStateMachine::setConsumeUpdateService mpd May 18 14:29:25 volumio volumio[1056]: info: May 18 14:29:25 volumio volumio[1056]: ---------------------------- MPD announces system playlist update May 18 14:29:25 volumio volumio[1056]: info: Ignoring MPD Status Update May 18 14:29:25 volumio volumio[1056]: info: ------------------------------ 4ms May 18 14:29:25 volumio volumio[1056]: info: May 18 14:29:25 volumio volumio[1056]: ---------------------------- MPD announces system playlist update May 18 14:29:25 volumio volumio[1056]: info: Ignoring MPD Status Update May 18 14:29:25 volumio volumio[1056]: info: May 18 14:29:25 volumio volumio[1056]: ---------------------------- MPD announces system playlist update May 18 14:29:25 volumio volumio[1056]: info: Ignoring MPD Status Update May 18 14:29:25 volumio volumio[1056]: info: ------------------------------ 5ms May 18 14:29:25 volumio volumio[1056]: info: ------------------------------ 4ms May 18 14:29:25 volumio volumio[1056]: info: May 18 14:29:25 volumio volumio[1056]: ---------------------------- MPD announces system playlist update May 18 14:29:25 volumio volumio[1056]: info: Ignoring MPD Status Update May 18 14:29:25 volumio volumio[1056]: info: May 18 14:29:25 volumio volumio[1056]: ---------------------------- MPD announces system playlist update May 18 14:29:25 volumio volumio[1056]: info: Ignoring MPD Status Update May 18 14:29:25 volumio volumio[1056]: info: ------------------------------ 3ms May 18 14:29:25 volumio volumio[1056]: info: ------------------------------ 3ms May 18 14:29:25 volumio volumio[1056]: info: May 18 14:29:25 volumio volumio[1056]: ---------------------------- MPD announces system playlist update May 18 14:29:25 volumio volumio[1056]: info: Ignoring MPD Status Update May 18 14:29:25 volumio volumio[1056]: info: ------------------------------ 2ms May 18 14:29:25 volumio volumio[1672]: 78 May 18 14:29:25 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:25 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:25 volumio volumio[1056]: info: May 18 14:29:25 volumio volumio[1056]: ---------------------------- Client requests Volume 78 May 18 14:29:25 volumio volumio[1056]: info: VolumeController::SetAlsaVolume78 May 18 14:29:25 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:25 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:25 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:25 volumio volumio[1672]: [158B blob data] May 18 14:29:25 volumio volumio[1672]: {"time":1747549765332,"response":"volume Success"}78 May 18 14:29:25 volumio volumio[1056]: info: May 18 14:29:25 volumio volumio[1056]: ---------------------------- MPD announces state update: player May 18 14:29:25 volumio volumio[1056]: info: ControllerMpd::getState May 18 14:29:25 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand status May 18 14:29:25 volumio volumio[1056]: info: May 18 14:29:25 volumio volumio[1056]: ---------------------------- MPD announces state update: player May 18 14:29:25 volumio volumio[1056]: info: sendMpdCommand status took 92 milliseconds May 18 14:29:25 volumio volumio[1056]: info: ControllerMpd::getState May 18 14:29:25 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand status May 18 14:29:25 volumio volumio[1056]: verbose: ControllerMpd::parseState May 18 14:29:25 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 14:29:25 volumio volumio[1056]: info: sendMpdCommand status took 17 milliseconds May 18 14:29:25 volumio volumio[1056]: verbose: ControllerMpd::parseState May 18 14:29:25 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 14:29:25 volumio volumio[1056]: info: sendMpdCommand playlistinfo took 21 milliseconds May 18 14:29:25 volumio volumio[1056]: verbose: ControllerMpd::parseTrackInfo May 18 14:29:25 volumio volumio[1056]: info: ControllerMpd::pushState May 18 14:29:25 volumio volumio[1056]: info: CoreCommandRouter::servicePushState May 18 14:29:25 volumio volumio[1056]: verbose: In UPNP mode May 18 14:29:25 volumio volumio[1056]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":298,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"金风玉露","artist":"梅小琴","album":"潇洒","uri":"http://192.168.31.126:34461/bridge-1.flac","trackType":"flac"} May 18 14:29:25 volumio volumio[1056]: verbose: CURRENT POSITION 0 May 18 14:29:25 volumio volumio[1056]: info: CoreStateMachine::syncState stateService play May 18 14:29:25 volumio volumio[1056]: info: CoreStateMachine::syncState currentStatus stop May 18 14:29:25 volumio volumio[1056]: info: ------------------------------ 165ms May 18 14:29:25 volumio volumio[1056]: info: sendMpdCommand playlistinfo took 47 milliseconds May 18 14:29:25 volumio volumio[1056]: verbose: ControllerMpd::parseTrackInfo May 18 14:29:25 volumio volumio[1056]: info: ControllerMpd::pushState May 18 14:29:25 volumio volumio[1056]: info: CoreCommandRouter::servicePushState May 18 14:29:25 volumio volumio[1056]: verbose: In UPNP mode May 18 14:29:25 volumio volumio[1056]: verbose: STATE SERVICE {"status":"play","position":0,"seek":705,"duration":298,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"917 Kbps","isStreaming":false,"title":"金风玉露","artist":"梅小琴","album":"潇洒","uri":"http://192.168.31.126:34461/bridge-1.flac","trackType":"flac"} May 18 14:29:25 volumio volumio[1056]: verbose: CURRENT POSITION 0 May 18 14:29:25 volumio volumio[1056]: info: CoreStateMachine::syncState stateService play May 18 14:29:25 volumio volumio[1056]: info: CoreStateMachine::syncState currentStatus play May 18 14:29:25 volumio volumio[1056]: info: Received an update from plugin. extracting info from payload May 18 14:29:25 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 18 14:29:25 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:25 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:25 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:25 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:25 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:25 volumio volumio[1056]: info: ------------------------------ 184ms May 18 14:29:25 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:25 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:25 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:25 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:25 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:25 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:28 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:28 volumio sudo[2202]: root : TTY=unknown ; PWD=/data/plugins/user_interface/peppy_screensaver ; USER=root ; COMMAND=/usr/bin/python3 ./screensaver/volumio_peppymeter.py May 18 14:29:28 volumio sudo[2202]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 14:29:32 volumio volumio[1056]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 7 May 18 14:29:33 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:35 volumio volumio[1056]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 8 May 18 14:29:35 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:36 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 14:29:36 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 14:29:36 volumio volumio[1056]: info: Discovery: Getting this device information May 18 14:29:36 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState May 18 14:29:36 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 14:29:38 volumio volumio[1672]: 79 May 18 14:29:38 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:38 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:38 volumio volumio[1056]: info: May 18 14:29:38 volumio volumio[1056]: ---------------------------- Client requests Volume 79 May 18 14:29:38 volumio volumio[1056]: info: VolumeController::SetAlsaVolume79 May 18 14:29:38 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:38 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:38 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:38 volumio volumio[1672]: [158B blob data] May 18 14:29:38 volumio volumio[1672]: {"time":1747549778405,"response":"volume Success"}79 May 18 14:29:38 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:38 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:38 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:38 volumio volumio[1672]: 80 May 18 14:29:38 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:38 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:38 volumio volumio[1056]: info: May 18 14:29:38 volumio volumio[1056]: ---------------------------- Client requests Volume 80 May 18 14:29:38 volumio volumio[1056]: info: VolumeController::SetAlsaVolume80 May 18 14:29:38 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:38 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:38 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:38 volumio volumio[1672]: [158B blob data] May 18 14:29:38 volumio volumio[1672]: {"time":1747549778669,"response":"volume Success"}80 May 18 14:29:38 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:38 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:38 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:38 volumio volumio[1672]: 81 May 18 14:29:38 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:38 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:39 volumio volumio[1056]: info: May 18 14:29:39 volumio volumio[1056]: ---------------------------- Client requests Volume 81 May 18 14:29:39 volumio volumio[1056]: info: VolumeController::SetAlsaVolume81 May 18 14:29:39 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:39 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:39 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:39 volumio volumio[1672]: [158B blob data] May 18 14:29:39 volumio volumio[1672]: {"time":1747549778999,"response":"volume Success"}81 May 18 14:29:39 volumio volumio[1672]: 82 May 18 14:29:39 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:39 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:39 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:39 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:39 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:39 volumio volumio[1056]: info: May 18 14:29:39 volumio volumio[1056]: ---------------------------- Client requests Volume 82 May 18 14:29:39 volumio volumio[1056]: info: VolumeController::SetAlsaVolume82 May 18 14:29:39 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:39 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:39 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:39 volumio volumio[1672]: [158B blob data] May 18 14:29:39 volumio volumio[1672]: {"time":1747549779278,"response":"volume Success"}82 May 18 14:29:39 volumio volumio[1672]: 84 May 18 14:29:39 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:39 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:39 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:39 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:39 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:39 volumio volumio[1056]: info: May 18 14:29:39 volumio volumio[1056]: ---------------------------- Client requests Volume 84 May 18 14:29:39 volumio volumio[1056]: info: VolumeController::SetAlsaVolume84 May 18 14:29:39 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:39 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:39 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:39 volumio volumio[1672]: [158B blob data] May 18 14:29:39 volumio volumio[1672]: {"time":1747549779532,"response":"volume Success"}84 May 18 14:29:39 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:39 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:39 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:39 volumio volumio[1672]: 83 May 18 14:29:39 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:39 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:39 volumio volumio[1056]: info: May 18 14:29:39 volumio volumio[1056]: ---------------------------- Client requests Volume 83 May 18 14:29:39 volumio volumio[1056]: info: VolumeController::SetAlsaVolume83 May 18 14:29:39 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:39 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:39 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:39 volumio volumio[1672]: [237B blob data] May 18 14:29:39 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:39 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:39 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:39 volumio volumio[1672]: {"time":1747549779784,"response":"volume Success"}83 May 18 14:29:39 volumio volumio[1672]: 85 May 18 14:29:40 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:40 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:40 volumio volumio[1056]: info: May 18 14:29:40 volumio volumio[1056]: ---------------------------- Client requests Volume 85 May 18 14:29:40 volumio volumio[1056]: info: VolumeController::SetAlsaVolume85 May 18 14:29:40 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:40 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:40 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:40 volumio volumio[1672]: [158B blob data] May 18 14:29:40 volumio volumio[1672]: {"time":1747549780046,"response":"volume Success"}85 May 18 14:29:40 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:40 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:40 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:40 volumio volumio[1672]: 86 May 18 14:29:40 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:40 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:40 volumio volumio[1056]: info: May 18 14:29:40 volumio volumio[1056]: ---------------------------- Client requests Volume 86 May 18 14:29:40 volumio volumio[1056]: info: VolumeController::SetAlsaVolume86 May 18 14:29:40 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:40 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:40 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:40 volumio volumio[1672]: [158B blob data] May 18 14:29:40 volumio volumio[1672]: {"time":1747549780254,"response":"volume Success"}86 May 18 14:29:40 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:40 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:40 volumio volumio[1672]: 87 May 18 14:29:40 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:40 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:40 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:40 volumio volumio[1056]: info: May 18 14:29:40 volumio volumio[1056]: ---------------------------- Client requests Volume 87 May 18 14:29:40 volumio volumio[1056]: info: VolumeController::SetAlsaVolume87 May 18 14:29:40 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:40 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:40 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:40 volumio volumio[1672]: [158B blob data] May 18 14:29:40 volumio volumio[1672]: {"time":1747549780488,"response":"volume Success"}87 May 18 14:29:40 volumio volumio[1672]: 88 May 18 14:29:40 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:40 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:40 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:40 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:40 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:40 volumio volumio[1056]: info: May 18 14:29:40 volumio volumio[1056]: ---------------------------- Client requests Volume 88 May 18 14:29:40 volumio volumio[1056]: info: VolumeController::SetAlsaVolume88 May 18 14:29:40 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:40 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:40 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:40 volumio volumio[1672]: [158B blob data] May 18 14:29:40 volumio volumio[1672]: {"time":1747549780747,"response":"volume Success"}88 May 18 14:29:40 volumio volumio[1672]: 89 May 18 14:29:40 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:40 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:40 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:40 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:40 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:40 volumio volumio[1056]: info: May 18 14:29:40 volumio volumio[1056]: ---------------------------- Client requests Volume 89 May 18 14:29:40 volumio volumio[1056]: info: VolumeController::SetAlsaVolume89 May 18 14:29:41 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:41 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:41 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:41 volumio volumio[1672]: [158B blob data] May 18 14:29:41 volumio volumio[1672]: {"time":1747549780966,"response":"volume Success"}89 May 18 14:29:41 volumio volumio[1672]: 92 May 18 14:29:41 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:41 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:41 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:41 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:41 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:41 volumio volumio[1056]: info: May 18 14:29:41 volumio volumio[1056]: ---------------------------- Client requests Volume 92 May 18 14:29:41 volumio volumio[1056]: info: VolumeController::SetAlsaVolume92 May 18 14:29:41 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:41 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:41 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:41 volumio volumio[1672]: [158B blob data] May 18 14:29:41 volumio volumio[1672]: {"time":1747549781169,"response":"volume Success"}92 May 18 14:29:41 volumio volumio[1672]: 91 May 18 14:29:41 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:41 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:41 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:41 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:41 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:41 volumio volumio[1056]: info: May 18 14:29:41 volumio volumio[1056]: ---------------------------- Client requests Volume 91 May 18 14:29:41 volumio volumio[1056]: info: VolumeController::SetAlsaVolume91 May 18 14:29:41 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:41 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:41 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:41 volumio volumio[1672]: [158B blob data] May 18 14:29:41 volumio volumio[1672]: {"time":1747549781451,"response":"volume Success"}91 May 18 14:29:41 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:41 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:41 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:41 volumio volumio[1672]: 93 May 18 14:29:41 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:41 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:41 volumio volumio[1056]: info: May 18 14:29:41 volumio volumio[1056]: ---------------------------- Client requests Volume 93 May 18 14:29:41 volumio volumio[1056]: info: VolumeController::SetAlsaVolume93 May 18 14:29:41 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:41 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:41 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:41 volumio volumio[1672]: [158B blob data] May 18 14:29:41 volumio volumio[1672]: {"time":1747549781707,"response":"volume Success"}93 May 18 14:29:41 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:41 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:41 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:41 volumio volumio[1672]: 90 May 18 14:29:41 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:41 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:41 volumio volumio[1056]: info: May 18 14:29:41 volumio volumio[1056]: ---------------------------- Client requests Volume 90 May 18 14:29:41 volumio volumio[1056]: info: VolumeController::SetAlsaVolume90 May 18 14:29:41 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:41 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:41 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:41 volumio volumio[1672]: [158B blob data] May 18 14:29:42 volumio volumio[1672]: {"time":1747549781891,"response":"volume Success"}90 May 18 14:29:42 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:42 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:42 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:42 volumio volumio[1672]: 94 May 18 14:29:42 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:42 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:42 volumio volumio[1056]: info: May 18 14:29:42 volumio volumio[1056]: ---------------------------- Client requests Volume 94 May 18 14:29:42 volumio volumio[1056]: info: VolumeController::SetAlsaVolume94 May 18 14:29:42 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:42 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:42 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:42 volumio volumio[1672]: [158B blob data] May 18 14:29:42 volumio volumio[1672]: {"time":1747549782116,"response":"volume Success"}94 May 18 14:29:42 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:42 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:42 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:42 volumio volumio[1672]: 96 May 18 14:29:42 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:42 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:42 volumio volumio[1056]: info: May 18 14:29:42 volumio volumio[1056]: ---------------------------- Client requests Volume 96 May 18 14:29:42 volumio volumio[1056]: info: VolumeController::SetAlsaVolume96 May 18 14:29:42 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:42 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:42 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:42 volumio volumio[1672]: [158B blob data] May 18 14:29:42 volumio volumio[1672]: {"time":1747549782332,"response":"volume Success"}96 May 18 14:29:42 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:42 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:42 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:42 volumio volumio[1672]: 97 May 18 14:29:42 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:42 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:42 volumio volumio[1056]: info: May 18 14:29:42 volumio volumio[1056]: ---------------------------- Client requests Volume 97 May 18 14:29:42 volumio volumio[1056]: info: VolumeController::SetAlsaVolume97 May 18 14:29:42 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:42 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:42 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:42 volumio volumio[1672]: [158B blob data] May 18 14:29:42 volumio volumio[1672]: {"time":1747549782555,"response":"volume Success"}97 May 18 14:29:42 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:42 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:42 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:42 volumio volumio[1672]: 99 May 18 14:29:42 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:42 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:42 volumio volumio[1056]: info: May 18 14:29:42 volumio volumio[1056]: ---------------------------- Client requests Volume 99 May 18 14:29:42 volumio volumio[1056]: info: VolumeController::SetAlsaVolume99 May 18 14:29:42 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:42 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:42 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:42 volumio volumio[1672]: [237B blob data] May 18 14:29:42 volumio volumio[1672]: {"time":1747549782788,"response":"volume Success"}99 May 18 14:29:42 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:42 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:42 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:42 volumio volumio[1672]: 100 May 18 14:29:43 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:43 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:43 volumio volumio[1056]: info: May 18 14:29:43 volumio volumio[1056]: ---------------------------- Client requests Volume 100 May 18 14:29:43 volumio volumio[1056]: info: VolumeController::SetAlsaVolume100 May 18 14:29:43 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:43 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:43 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:43 volumio volumio[1672]: [158B blob data] May 18 14:29:43 volumio volumio[1672]: {"time":1747549783047,"response":"volume Success"}100 May 18 14:29:43 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:43 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:43 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:43 volumio volumio[1672]: 95 May 18 14:29:43 volumio volumio[1672]: % Total % Received % Xferd Average Speed Time Time Time Current May 18 14:29:43 volumio volumio[1672]: Dload Upload Total Spent Left Speed May 18 14:29:43 volumio volumio[1056]: info: May 18 14:29:43 volumio volumio[1056]: ---------------------------- Client requests Volume 95 May 18 14:29:43 volumio volumio[1056]: info: VolumeController::SetAlsaVolume95 May 18 14:29:43 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:43 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 14:29:43 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:43 volumio volumio[1672]: [158B blob data] May 18 14:29:43 volumio volumio[1672]: {"time":1747549783352,"response":"volume Success"}95 May 18 14:29:43 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue May 18 14:29:43 volumio volumio[1056]: info: CoreStateMachine::getQueue May 18 14:29:43 volumio volumio[1056]: info: CorePlayQueue::getQueue May 18 14:29:53 volumio volumio[1056]: info: May 18 14:29:53 volumio volumio[1056]: ---------------------------- MPD announces state update: player May 18 14:29:53 volumio volumio[1056]: info: ControllerMpd::getState May 18 14:29:53 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand status May 18 14:29:53 volumio volumio[1056]: info: sendMpdCommand status took 3 milliseconds May 18 14:29:53 volumio volumio[1056]: verbose: ControllerMpd::parseState May 18 14:29:53 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 14:29:53 volumio volumio[1056]: info: sendMpdCommand playlistinfo took 1 milliseconds May 18 14:29:53 volumio volumio[1056]: verbose: ControllerMpd::parseTrackInfo May 18 14:29:53 volumio volumio[1056]: info: ControllerMpd::pushState May 18 14:29:53 volumio volumio[1056]: info: CoreCommandRouter::servicePushState May 18 14:29:53 volumio volumio[1056]: info: CoreStateMachine::pushState May 18 14:29:53 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:53 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 May 18 14:29:53 volumio volumio[1056]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"金风玉露","artist":"梅小琴","album":"潇洒","uri":"http://192.168.31.126:34461/bridge-1.flac","trackType":"flac"} May 18 14:29:53 volumio volumio[1056]: verbose: CURRENT POSITION 0 May 18 14:29:53 volumio volumio[1056]: info: CoreStateMachine::syncState stateService stop May 18 14:29:53 volumio volumio[1056]: info: CoreStateMachine::syncState currentStatus play May 18 14:29:53 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState May 18 14:29:53 volumio volumio[1056]: info: CoreStateMachine::stPlaybackTimer May 18 14:29:53 volumio volumio[1056]: info: ------------------------------ 63ms May 18 14:29:53 volumio volumio[1056]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 18 14:29:53 volumio volumio[1056]: Error: ENOTDIR: not a directory, scandir '/tmp/peppyrunning' May 18 14:29:53 volumio volumio[1056]: at Object.readdirSync (fs.js:1048:3) May 18 14:29:53 volumio volumio[1056]: at rmkidsSync (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:349:11) May 18 14:29:53 volumio volumio[1056]: at rmdirSync (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:342:7) May 18 14:29:53 volumio volumio[1056]: at Function.rimrafSync [as sync] (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:319:62) May 18 14:29:53 volumio volumio[1056]: at Object.removeSync (/data/plugins/user_interface/peppy_screensaver/node_modules/fs-extra/lib/remove/index.js:4:17) May 18 14:29:53 volumio volumio[1056]: at Socket. (/data/plugins/user_interface/peppy_screensaver/index.js:225:48) May 18 14:29:53 volumio volumio[1056]: at Socket.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) May 18 14:29:53 volumio volumio[1056]: at Socket.onevent (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/socket.js:278:10) May 18 14:29:53 volumio volumio[1056]: at Socket.onpacket (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/socket.js:236:12) May 18 14:29:53 volumio volumio[1056]: at Manager. (/data/plugins/user_interface/peppy_screensaver/node_modules/component-bind/index.js:21:15) May 18 14:29:53 volumio volumio[1056]: at Manager.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) May 18 14:29:53 volumio volumio[1056]: at Manager.ondecoded (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/manager.js:349:8) May 18 14:29:53 volumio volumio[1056]: at Decoder. (/data/plugins/user_interface/peppy_screensaver/node_modules/component-bind/index.js:21:15) May 18 14:29:53 volumio volumio[1056]: at Decoder.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) May 18 14:29:53 volumio volumio[1056]: at Decoder.add (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-parser/index.js:251:12) May 18 14:29:53 volumio volumio[1056]: at Manager.ondata (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/manager.js:339:16) { May 18 14:29:53 volumio volumio[1056]: errno: -20, May 18 14:29:53 volumio volumio[1056]: syscall: 'scandir', May 18 14:29:53 volumio volumio[1056]: code: 'ENOTDIR', May 18 14:29:53 volumio volumio[1056]: path: '/tmp/peppyrunning' May 18 14:29:53 volumio volumio[1056]: } May 18 14:29:53 volumio volumio[1056]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 18 14:29:54 volumio sudo[2624]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-18 14:28 May 18 14:29:54 volumio sudo[2624]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:50:12 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="39b0f8c200b2dcadf117e189b4b3632d"