-- Logs begin at Sat 2022-10-01 16:28:45 EEST, end at Sat 2022-10-01 16:30:18 EEST. -- Oct 01 16:29:00 volumio wireless.js[538]: trying... Oct 01 16:29:00 volumio sudo[1038]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 01 16:29:00 volumio sudo[1038]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:00 volumio sudo[1038]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:01 volumio wireless.js[538]: trying... Oct 01 16:29:01 volumio sudo[1048]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 01 16:29:01 volumio sudo[1048]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:01 volumio sudo[1048]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:02 volumio sh[488]: eth0: leased 192.168.1.210 for 43200 seconds Oct 01 16:29:02 volumio sh[488]: eth0: adding route to 192.168.1.0/24 Oct 01 16:29:02 volumio sh[488]: eth0: adding default route via 192.168.1.1 Oct 01 16:29:02 volumio dhcpcd[523]: eth0: leased 192.168.1.210 for 43200 seconds Oct 01 16:29:02 volumio avahi-daemon[536]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.210. Oct 01 16:29:02 volumio dhcpcd[523]: eth0: adding route to 192.168.1.0/24 Oct 01 16:29:02 volumio avahi-daemon[536]: New relevant interface eth0.IPv4 for mDNS. Oct 01 16:29:02 volumio dhcpcd[523]: eth0: adding default route via 192.168.1.1 Oct 01 16:29:02 volumio avahi-daemon[536]: Registering new address record for 192.168.1.210 on eth0.IPv4. Oct 01 16:29:02 volumio wireless.js[538]: trying... Oct 01 16:29:02 volumio sudo[1075]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 01 16:29:02 volumio sh[488]: Warning: The unit file, source configuration file or drop-ins of systemd-timesyncd.service changed on disk. Run 'systemctl daemon-reload' to reload units. Oct 01 16:29:02 volumio sudo[1075]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:02 volumio sudo[1075]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:02 volumio ntpd[807]: ntpd exiting on signal 15 (Terminated) Oct 01 16:29:02 volumio systemd[1]: Stopping Network Time Service... Oct 01 16:29:03 volumio systemd[1]: ntp.service: Succeeded. Oct 01 16:29:03 volumio systemd[1]: Stopped Network Time Service. Oct 01 16:29:03 volumio systemd[1]: Starting Network Time Service... Oct 01 16:29:03 volumio ntpd[1100]: ntpd 4.2.8p12@1.3728-o (1): Starting Oct 01 16:29:03 volumio ntpd[1100]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Oct 01 16:29:03 volumio systemd[1]: Started Network Time Service. Oct 01 16:29:03 volumio sh[488]: forked to background, child pid 1107 Oct 01 16:29:03 volumio dhcpcd[523]: forked to background, child pid 1107 Oct 01 16:29:03 volumio ntpd[1106]: proto: precision = 0.875 usec (-20) Oct 01 16:29:03 volumio ntpd[1106]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Oct 01 16:29:03 volumio ntpd[1106]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Oct 01 16:29:03 volumio ntpd[1106]: Listen and drop on 0 v6wildcard [::]:123 Oct 01 16:29:03 volumio ntpd[1106]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Oct 01 16:29:03 volumio ntpd[1106]: Listen normally on 2 lo 127.0.0.1:123 Oct 01 16:29:03 volumio ntpd[1106]: Listen normally on 3 eth0 192.168.1.210:123 Oct 01 16:29:03 volumio ntpd[1106]: Listening on routing socket on fd #20 for interface updates Oct 01 16:29:03 volumio ntpd[1106]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 01 16:29:03 volumio ntpd[1106]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 01 16:29:03 volumio kernel: nf_conntrack: automatic helper assignment is deprecated and it will be removed soon. Use the iptables CT target to attach helpers instead. Oct 01 16:29:03 volumio ifplugd(eth0)[821]: client: ifup: interface eth0 already configured Oct 01 16:29:03 volumio sh[488]: eth0=eth0 Oct 01 16:29:03 volumio ifplugd(eth0)[821]: Program executed successfully. Oct 01 16:29:03 volumio ifplugd[780]: Network Interface Plugging Daemon...start eth0...done. Oct 01 16:29:03 volumio systemd[1]: Started LSB: Brings up/down network automatically. Oct 01 16:29:03 volumio nmbd[786]: [2022/10/01 16:29:03.342670, 0] ../lib/util/become_daemon.c:138(daemon_ready) Oct 01 16:29:03 volumio systemd[1]: Started Samba NMB Daemon. Oct 01 16:29:03 volumio nmbd[786]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Oct 01 16:29:03 volumio systemd[1]: Starting Samba Winbind Daemon... Oct 01 16:29:03 volumio dhcpcd[645]: eth0: leased 192.168.1.210 for 43200 seconds Oct 01 16:29:03 volumio dhcpcd[645]: eth0: adding route to 192.168.1.0/24 Oct 01 16:29:03 volumio dhcpcd[645]: eth0: adding default route via 192.168.1.1 Oct 01 16:29:03 volumio ntpd[1106]: ntpd exiting on signal 15 (Terminated) Oct 01 16:29:03 volumio systemd[1]: Stopping Network Time Service... Oct 01 16:29:03 volumio systemd[1]: ntp.service: Succeeded. Oct 01 16:29:03 volumio systemd[1]: Stopped Network Time Service. Oct 01 16:29:03 volumio systemd[1]: Starting Network Time Service... Oct 01 16:29:03 volumio ntpd[1168]: ntpd 4.2.8p12@1.3728-o (1): Starting Oct 01 16:29:03 volumio ntpd[1168]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Oct 01 16:29:03 volumio systemd[1]: Started Network Time Service. Oct 01 16:29:03 volumio ntpd[1174]: proto: precision = 0.583 usec (-21) Oct 01 16:29:03 volumio ntpd[1174]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Oct 01 16:29:03 volumio ntpd[1174]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Oct 01 16:29:03 volumio ntpd[1174]: Listen and drop on 0 v6wildcard [::]:123 Oct 01 16:29:03 volumio ntpd[1174]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Oct 01 16:29:03 volumio ntpd[1174]: Listen normally on 2 lo 127.0.0.1:123 Oct 01 16:29:03 volumio ntpd[1174]: Listen normally on 3 eth0 192.168.1.210:123 Oct 01 16:29:03 volumio ntpd[1174]: Listening on routing socket on fd #20 for interface updates Oct 01 16:29:03 volumio ntpd[1174]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 01 16:29:03 volumio ntpd[1174]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 01 16:29:03 volumio winbindd[1134]: [2022/10/01 16:29:03.665221, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Oct 01 16:29:03 volumio winbindd[1134]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Oct 01 16:29:03 volumio systemd[1]: Started Samba Winbind Daemon. Oct 01 16:29:03 volumio systemd[1]: Starting Samba SMB Daemon... Oct 01 16:29:03 volumio winbindd[1134]: [2022/10/01 16:29:03.680011, 0] ../lib/util/become_daemon.c:138(daemon_ready) Oct 01 16:29:03 volumio winbindd[1134]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Oct 01 16:29:03 volumio wireless.js[538]: trying... Oct 01 16:29:03 volumio sudo[1181]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 01 16:29:03 volumio sudo[1181]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:03 volumio sudo[1181]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:04 volumio winbindd[1134]: [2022/10/01 16:29:04.003993, 0] ../source3/winbindd/wb_lookupsids.c:659(wb_lookupsids_recv) Oct 01 16:29:04 volumio winbindd[1134]: res_names->count = 3, expected 4 Oct 01 16:29:04 volumio systemd[1]: Started Samba SMB Daemon. Oct 01 16:29:04 volumio smbd[1179]: [2022/10/01 16:29:04.024872, 0] ../lib/util/become_daemon.c:138(daemon_ready) Oct 01 16:29:04 volumio smbd[1179]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Oct 01 16:29:04 volumio ntpd[1174]: Soliciting pool server 135.181.151.153 Oct 01 16:29:04 volumio wireless.js[538]: trying... Oct 01 16:29:04 volumio sudo[1198]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 01 16:29:04 volumio sudo[1198]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:04 volumio sudo[1198]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:05 volumio ntpd[1174]: Soliciting pool server 95.216.78.223 Oct 01 16:29:05 volumio wireless.js[538]: trying... Oct 01 16:29:05 volumio sudo[1208]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 01 16:29:05 volumio sudo[1208]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:05 volumio sudo[1208]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:06 volumio ntpd[1174]: Soliciting pool server 162.159.200.1 Oct 01 16:29:06 volumio wireless.js[538]: trying... Oct 01 16:29:06 volumio sudo[1218]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 01 16:29:06 volumio sudo[1218]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:06 volumio sudo[1218]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:07 volumio ntpd[1174]: Soliciting pool server 185.251.115.30 Oct 01 16:29:07 volumio wireless.js[538]: trying... Oct 01 16:29:07 volumio sudo[1228]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 01 16:29:07 volumio sudo[1228]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:07 volumio sudo[1228]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:08 volumio wireless.js[538]: trying... Oct 01 16:29:08 volumio sudo[1238]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 01 16:29:08 volumio sudo[1238]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:08 volumio sudo[1238]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:09 volumio wireless.js[538]: trying... Oct 01 16:29:09 volumio sudo[1248]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 01 16:29:09 volumio volumio-remote-updater[540]: [2022-10-01 16:29:09] [info] asio async_connect error: system:111 (Connection refused) Oct 01 16:29:09 volumio volumio-remote-updater[540]: [2022-10-01 16:29:09] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Oct 01 16:29:09 volumio volumio-remote-updater[540]: [2022-10-01 16:29:09] [error] handle_connect error: Underlying Transport Error Oct 01 16:29:09 volumio sudo[1248]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:09 volumio sudo[1248]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:10 volumio wireless.js[538]: Overtime, starting plan B Oct 01 16:29:10 volumio iwconfig[1259]: Error for wireless request "Set Power Management" (8B2C) : Oct 01 16:29:10 volumio iwconfig[1259]: SET failed on device wlan0 ; Operation not permitted. Oct 01 16:29:10 volumio systemd[1]: Started Wireless Services. Oct 01 16:29:10 volumio systemd[1]: Started Volumio Backend Module. Oct 01 16:29:10 volumio systemd[1]: Started Start Volumio Kiosk. Oct 01 16:29:10 volumio systemd[1]: Started Volumio Cpu Tweaker. Oct 01 16:29:10 volumio systemd[1]: Reached target Multi-User System. Oct 01 16:29:10 volumio startkiosk.sh[1261]: Starting Volumio Kiosk with arguments for cursor display Oct 01 16:29:10 volumio systemd[1]: Reached target Graphical Interface. Oct 01 16:29:10 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Oct 01 16:29:10 volumio volumio-cpu-tweak[1262]: Setting RT Priority for mpd Oct 01 16:29:10 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Oct 01 16:29:10 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Oct 01 16:29:10 volumio systemd[1]: Startup finished in 14.265s (kernel) + 26.481s (userspace) = 40.747s. Oct 01 16:29:11 volumio volumio-cpu-tweak[1262]: pid 35's current scheduling policy: SCHED_OTHER Oct 01 16:29:11 volumio volumio-cpu-tweak[1262]: pid 35's current scheduling priority: 0 Oct 01 16:29:11 volumio volumio-cpu-tweak[1262]: Setting MPD Affinity Oct 01 16:29:11 volumio volumio-cpu-tweak[1262]: pid 3's current affinity mask: 1 Oct 01 16:29:11 volumio volumio-cpu-tweak[1262]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Oct 01 16:29:11 volumio volumio-cpu-tweak[1262]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Oct 01 16:29:11 volumio systemd[1]: volumio_cpu_tweak.service: Succeeded. Oct 01 16:29:11 volumio startkiosk.sh[1261]: X.Org X Server 1.20.4 Oct 01 16:29:11 volumio startkiosk.sh[1261]: X Protocol Version 11, Revision 0 Oct 01 16:29:11 volumio startkiosk.sh[1261]: Build Operating System: Linux 4.19.0-18-armmp-lpae armv7l Debian Oct 01 16:29:11 volumio startkiosk.sh[1261]: Current Operating System: Linux volumio 4.4.71+ #23 SMP Sun Sep 20 12:23:26 CEST 2020 armv7l Oct 01 16:29:11 volumio startkiosk.sh[1261]: Kernel command line: earlyprintk quiet loglevel=0 splash plymouth.ignore-serial-consoles initramfs.clear console=tty1 console=ttyS3,115200n8 rw init=/sbin/init imgpart=UUID=a32bdd9f-4394-4094-acb5-0caaf5cc0c55 imgfile=/volumio_current.sqsh bootpart=UUID=0A1E-49F8 datapart=UUID=e426b45d-4a55-46df-b7cf-a2c913e247c6 uuidconfig=/extlinux/extlinux.conf vt.global_cursor_default=0 bootdelay=5 uboot_version=2017.07-g879646d1d6 root=/dev/mmcblk1p2 Oct 01 16:29:11 volumio startkiosk.sh[1261]: Build Date: 18 December 2021 09:05:36AM Oct 01 16:29:11 volumio startkiosk.sh[1261]: xorg-server 2:1.20.4-1+deb10u4 (https://www.debian.org/support) Oct 01 16:29:11 volumio startkiosk.sh[1261]: Current version of pixman: 0.36.0 Oct 01 16:29:11 volumio startkiosk.sh[1261]: Before reporting problems, check http://wiki.x.org Oct 01 16:29:11 volumio startkiosk.sh[1261]: to make sure that you have the latest version. Oct 01 16:29:11 volumio startkiosk.sh[1261]: Markers: (--) probed, (**) from config file, (==) default setting, Oct 01 16:29:11 volumio startkiosk.sh[1261]: (++) from command line, (!!) notice, (II) informational, Oct 01 16:29:11 volumio startkiosk.sh[1261]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Oct 01 16:29:11 volumio startkiosk.sh[1261]: (==) Log file: "/var/log/Xorg.0.log", Time: Sat Oct 1 16:29:11 2022 Oct 01 16:29:11 volumio startkiosk.sh[1261]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Oct 01 16:29:11 volumio startkiosk.sh[1261]: gbm: failed to open any driver (search paths /usr/lib/arm-linux-gnueabihf/dri:\$${ORIGIN}/dri:/usr/lib/dri) Oct 01 16:29:11 volumio startkiosk.sh[1261]: gbm: Last dlopen error: /usr/lib/dri/rockchip_dri.so: cannot open shared object file: No such file or directory Oct 01 16:29:11 volumio startkiosk.sh[1261]: failed to load driver: rockchip Oct 01 16:29:11 volumio startkiosk.sh[1261]: (II) modeset(0): Initializing kms color map for depth 24, 8 bpc. Oct 01 16:29:12 volumio volumio[1260]: info: ------------------------------------------- Oct 01 16:29:12 volumio volumio[1260]: info: ----- Volumio3 ---- Oct 01 16:29:12 volumio volumio[1260]: info: ------------------------------------------- Oct 01 16:29:12 volumio volumio[1260]: info: ----- System startup ---- Oct 01 16:29:12 volumio volumio[1260]: info: ------------------------------------------- Oct 01 16:29:13 volumio volumio[1260]: info: MYVOLUMIO Environment detected Oct 01 16:29:13 volumio volumio[1260]: info: Plugin folders cleanup Oct 01 16:29:13 volumio volumio[1260]: info: Scanning into folder /volumio/app/plugins/ Oct 01 16:29:13 volumio volumio[1260]: info: Scanning category audio_interface Oct 01 16:29:13 volumio volumio[1260]: info: Scanning category miscellanea Oct 01 16:29:13 volumio volumio[1260]: info: Scanning category music_service Oct 01 16:29:13 volumio volumio[1260]: info: Scanning category plugins.json Oct 01 16:29:13 volumio volumio[1260]: info: Scanning category system_controller Oct 01 16:29:13 volumio volumio[1260]: info: Scanning category user_interface Oct 01 16:29:13 volumio volumio[1260]: info: Scanning into folder /data/plugins/ Oct 01 16:29:13 volumio volumio[1260]: info: Plugin folders cleanup completed Oct 01 16:29:13 volumio volumio[1260]: info: ------------------------------------------- Oct 01 16:29:13 volumio volumio[1260]: info: ----- Core plugins startup ---- Oct 01 16:29:13 volumio volumio[1260]: info: ------------------------------------------- Oct 01 16:29:13 volumio volumio[1260]: info: Loading plugins from folder /volumio/app/plugins/ Oct 01 16:29:13 volumio volumio[1260]: info: Adding plugin upnp to MyMusic Plugins Oct 01 16:29:13 volumio volumio[1260]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 01 16:29:13 volumio volumio[1260]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 01 16:29:13 volumio volumio[1260]: info: Loading plugins from folder /data/plugins/ Oct 01 16:29:13 volumio volumio[1260]: info: Loading plugin "system"... Oct 01 16:29:13 volumio volumio[1260]: info: Loading plugin "appearance"... Oct 01 16:29:14 volumio volumio[1260]: info: Loading plugin "network"... Oct 01 16:29:14 volumio volumio[1260]: info: Refreshing Cached IP Addresses Oct 01 16:29:14 volumio sudo[1376]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 01 16:29:14 volumio volumio[1260]: info: Loading plugin "services"... Oct 01 16:29:14 volumio volumio[1260]: info: Loading plugin "alsa_controller"... Oct 01 16:29:14 volumio sudo[1378]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 01 16:29:14 volumio sudo[1376]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:14 volumio sudo[1378]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:14 volumio sudo[1376]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:14 volumio sudo[1381]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 01 16:29:14 volumio sudo[1378]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:14 volumio sudo[1381]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:14 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 01 16:29:14 volumio volumio[1260]: info: Loading plugin "wizard"... Oct 01 16:29:14 volumio volumio[1260]: info: Loading plugin "networkfs"... Oct 01 16:29:14 volumio volumio[1260]: info: Starting Udev Watcher for removable devices Oct 01 16:29:14 volumio volumio[1260]: info: Ignoring mount for partition: BOOT Oct 01 16:29:14 volumio volumio[1260]: info: Ignoring mount for partition: volumio Oct 01 16:29:14 volumio volumio[1260]: info: Ignoring mount for partition: volumio_data Oct 01 16:29:14 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 01 16:29:14 volumio volumio[1260]: info: Loading plugin "volumio_command_line_client"... Oct 01 16:29:14 volumio volumio[1260]: info: Loading plugin "upnp"... Oct 01 16:29:14 volumio volumio[1260]: info: [1664630954809] Starting Upmpd Daemon Oct 01 16:29:14 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 01 16:29:14 volumio volumio[1260]: info: Loading plugin "my_music"... Oct 01 16:29:14 volumio volumio[1260]: info: Loading plugin "mpd"... Oct 01 16:29:15 volumio volumio[1260]: info: Loading plugin "upnp_browser"... Oct 01 16:29:15 volumio volumio[1260]: info: Loading plugin "alarm-clock"... Oct 01 16:29:15 volumio volumio[1260]: info: Loading plugin "airplay_emulation"... Oct 01 16:29:15 volumio volumio[1260]: info: Starting Shairport Sync Oct 01 16:29:15 volumio volumio[1260]: info: Loading plugin "last_100"... Oct 01 16:29:15 volumio volumio[1260]: info: Loading plugin "webradio"... Oct 01 16:29:15 volumio volumio[1260]: info: Loading plugin "i2s_dacs"... Oct 01 16:29:15 volumio volumio[1260]: info: I2S DAC not set, start Auto-detection Oct 01 16:29:15 volumio volumio[1260]: info: Loading plugin "volumiodiscovery"... Oct 01 16:29:15 volumio volumio[1260]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 01 16:29:15 volumio volumio[1260]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 01 16:29:15 volumio volumio[1260]: *** WARNING *** For more information see Oct 01 16:29:15 volumio volumio[1260]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 01 16:29:15 volumio volumio[1260]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 01 16:29:15 volumio node[1260]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 01 16:29:15 volumio volumio[1260]: *** WARNING *** For more information see Oct 01 16:29:15 volumio node[1260]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 01 16:29:15 volumio node[1260]: *** WARNING *** For more information see Oct 01 16:29:15 volumio node[1260]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 01 16:29:15 volumio node[1260]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 01 16:29:15 volumio node[1260]: *** WARNING *** For more information see Oct 01 16:29:15 volumio volumio[1260]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 01 16:29:15 volumio volumio[1260]: info: Discovery: Started advertising with name: Volumio Oct 01 16:29:15 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 01 16:29:15 volumio volumio[1260]: info: Loading plugin "outputs"... Oct 01 16:29:15 volumio volumio[1260]: info: Loading plugin "albumart"... Oct 01 16:29:15 volumio volumio[1260]: info: Plugin example_plugin is not enabled Oct 01 16:29:15 volumio volumio[1260]: info: Loading plugin "inputs"... Oct 01 16:29:15 volumio volumio[1260]: info: Loading plugin "updater_comm"... Oct 01 16:29:15 volumio volumio[1260]: info: Plugin mpdemulation is not enabled Oct 01 16:29:15 volumio volumio[1260]: info: Loading plugin "rest_api"... Oct 01 16:29:15 volumio volumio[1260]: info: Loading plugin "websocket"... Oct 01 16:29:15 volumio volumio[1260]: info: Starting Socket.io Server version 2.3.0 Oct 01 16:29:15 volumio volumio[1260]: info: Loading i18n strings for locale fi Oct 01 16:29:15 volumio volumio[1260]: Updating browse sources language Oct 01 16:29:15 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 01 16:29:15 volumio volumio[1260]: Forking 3 albumart workers Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::initPlayerControls Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio systemd[1]: systemd-fsckd.service: Succeeded. Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: Express server listening on port 3000 Oct 01 16:29:16 volumio volumio[1260]: [Metrics] WebUI: 3s 775.37ms Oct 01 16:29:16 volumio sudo[1381]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:16 volumio volumio[1260]: info: CoreStateMachine::resetVolumioState Oct 01 16:29:16 volumio volumio[1260]: info: CoreStateMachine::getcurrentVolume Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::volumioRetrievevolume Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Oct 01 16:29:16 volumio volumio[1260]: info: Completed loading Core Plugins Oct 01 16:29:16 volumio volumio[1260]: info: Preparing to generate the ALSA configuration file Oct 01 16:29:16 volumio volumio[1260]: info: Reloading queue from file Oct 01 16:29:16 volumio volumio[1260]: info: VolumeController:: Volume=37 Mute =false Oct 01 16:29:16 volumio volumio[1260]: info: CoreStateMachine::pushState Oct 01 16:29:16 volumio volumio[1260]: info: CorePlayQueue::getTrack 0 Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::volumioPushState Oct 01 16:29:16 volumio volumio[1260]: info: CoreStateMachine::updateTrackBlock Oct 01 16:29:16 volumio volumio[1260]: info: CorePlayQueue::getTrackBlock Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::volumioRetrievevolume Oct 01 16:29:16 volumio volumio[1260]: info: Asound.conf file unchanged, so no further update is needed Oct 01 16:29:16 volumio volumio[1260]: info: Output device has changed, restarting MPD Oct 01 16:29:16 volumio volumio[1260]: info: Output device has changed, restarting Shairport Sync Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 01 16:29:16 volumio sudo[1457]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 01 16:29:16 volumio sudo[1457]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:16 volumio sudo[1457]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:16 volumio sudo[1459]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 01 16:29:16 volumio volumio[1260]: info: ___________ START PLUGINS ___________ Oct 01 16:29:16 volumio sudo[1459]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:16 volumio volumio[1260]: info: ControllerMpd::onStart: Initializing MPD Oct 01 16:29:16 volumio volumio[1260]: info: Creating MPD Configuration file Oct 01 16:29:16 volumio systemd[1]: Listening on mpd.socket. Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 01 16:29:16 volumio volumio[1260]: info: [1664630956474] CoreMusicLibrary::Adding element Mediapalvelimet Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 01 16:29:16 volumio systemd[1]: Starting Music Player Daemon... Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 01 16:29:16 volumio sudo[1478]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 01 16:29:16 volumio sudo[1481]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 01 16:29:16 volumio sudo[1478]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:16 volumio sudo[1481]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:16 volumio sudo[1478]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:16 volumio volumio[1260]: Starting albumart workers Oct 01 16:29:16 volumio volumio[1260]: Starting albumart workers Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 01 16:29:16 volumio sudo[1480]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 01 16:29:16 volumio volumio[1260]: info: [1664630956615] CoreMusicLibrary::Adding element Last_100 Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 01 16:29:16 volumio volumio[1260]: info: [1664630956617] CoreMusicLibrary::Adding element Webradio Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 01 16:29:16 volumio sudo[1480]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 01 16:29:16 volumio volumio[1260]: info: Initializing BBC Radios Oct 01 16:29:16 volumio sudo[1480]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:16 volumio volumio[1260]: Starting albumart workers Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: Volumio Calling Home Oct 01 16:29:16 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 01 16:29:16 volumio systemd[1]: mpd.service: Succeeded. Oct 01 16:29:16 volumio systemd[1]: Stopped Music Player Daemon. Oct 01 16:29:16 volumio systemd[1]: Starting Music Player Daemon... Oct 01 16:29:16 volumio volumio[1260]: info: CoreStateMachine::setRepeat true single undefined Oct 01 16:29:16 volumio volumio[1260]: info: CoreStateMachine::pushState Oct 01 16:29:16 volumio volumio[1260]: info: CorePlayQueue::getTrack 0 Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::volumioPushState Oct 01 16:29:16 volumio volumio[1260]: info: CoreStateMachine::setRandom true Oct 01 16:29:16 volumio volumio[1260]: info: CoreStateMachine::pushState Oct 01 16:29:16 volumio volumio[1260]: info: CorePlayQueue::getTrack 0 Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::volumioPushState Oct 01 16:29:16 volumio volumio[1260]: info: Setting Device type: Tinkerboard Oct 01 16:29:16 volumio volumio[1260]: info: MPD Permissions set Oct 01 16:29:16 volumio sudo[1520]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 01 16:29:16 volumio volumio[1260]: info: MPD Permissions set Oct 01 16:29:16 volumio sudo[1520]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:16 volumio volumio[1260]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio sudo[1520]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:16 volumio sudo[1520]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 01 16:29:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 01 16:29:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 01 16:29:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 01 16:29:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:17 volumio volumio[1260]: info: VolumeController:: Volume=37 Mute =false Oct 01 16:29:17 volumio volumio[1260]: info: CoreStateMachine::pushState Oct 01 16:29:17 volumio volumio[1260]: info: CorePlayQueue::getTrack 0 Oct 01 16:29:17 volumio volumio[1260]: info: CoreCommandRouter::volumioPushState Oct 01 16:29:17 volumio volumio[1260]: info: Volumio called home Oct 01 16:29:17 volumio volumio[1260]: info: Starting Shairport Sync Oct 01 16:29:17 volumio volumio[1260]: info: Starting Shairport Sync Oct 01 16:29:17 volumio volumio[1260]: info: Starting Shairport Sync Oct 01 16:29:17 volumio sudo[1575]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 01 16:29:17 volumio volumio[1260]: info: CoreCommandRouter::volumioGetState Oct 01 16:29:17 volumio volumio[1260]: info: CorePlayQueue::getTrack 0 Oct 01 16:29:17 volumio volumio[1260]: info: Discovery: adding 373e7ce4-f4c8-4e01-997c-b859806414dd Oct 01 16:29:17 volumio volumio[1260]: info: Discovery: Found device Volumio Oct 01 16:29:17 volumio volumio[1260]: info: CoreCommandRouter::volumioGetState Oct 01 16:29:17 volumio volumio[1260]: info: CorePlayQueue::getTrack 0 Oct 01 16:29:17 volumio sudo[1577]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 01 16:29:17 volumio sudo[1575]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:17 volumio sudo[1581]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 01 16:29:17 volumio sudo[1581]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:17 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 01 16:29:17 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 01 16:29:17 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 01 16:29:17 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 01 16:29:17 volumio sudo[1577]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:17 volumio sudo[1575]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:17 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 01 16:29:17 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Oct 01 16:29:17 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 01 16:29:17 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 01 16:29:17 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 01 16:29:17 volumio sudo[1581]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:17 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 01 16:29:17 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Oct 01 16:29:17 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 01 16:29:17 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 01 16:29:17 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 01 16:29:17 volumio sudo[1577]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:17 volumio volumio[1260]: info: Shairport-Sync Started Oct 01 16:29:17 volumio volumio[1260]: Error adding Membership: Error: addMembership EINVAL Oct 01 16:29:17 volumio volumio[1260]: info: Shairport-Sync Started Oct 01 16:29:17 volumio volumio[1260]: info: Shairport-Sync Started Oct 01 16:29:17 volumio systemd[1]: systemd-hostnamed.service: Succeeded. Oct 01 16:29:18 volumio mpd[1560]: Oct 01 16:29 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 01 16:29:18 volumio systemd[1]: Started Music Player Daemon. Oct 01 16:29:18 volumio sudo[1459]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:18 volumio sudo[1481]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:18 volumio volumio[1260]: info: Completed starting Core Plugins Oct 01 16:29:18 volumio volumio[1260]: info: ------------------------------------------- Oct 01 16:29:18 volumio volumio[1260]: info: ----- MyVolumio plugins startup ---- Oct 01 16:29:18 volumio volumio[1260]: info: ------------------------------------------- Oct 01 16:29:18 volumio volumio[1260]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 01 16:29:19 volumio volumio[1260]: error: MPD error: The expression evaluated to a falsy value: Oct 01 16:29:19 volumio volumio[1260]: assert.ok(self.idling) Oct 01 16:29:19 volumio volumio[1260]: error: The expression evaluated to a falsy value: Oct 01 16:29:19 volumio volumio[1260]: assert.ok(self.idling) Oct 01 16:29:19 volumio volumio[1260]: info: MPD running with PID1560 Oct 01 16:29:19 volumio volumio[1260]: ,establishing connection Oct 01 16:29:19 volumio volumio[1260]: error: updateQueue error: null Oct 01 16:29:19 volumio volumio[1260]: error: updateQueue error: null Oct 01 16:29:19 volumio volumio-remote-updater[540]: [2022-10-01 16:29:19] [connect] Successful connection Oct 01 16:29:19 volumio volumio-remote-updater[540]: [2022-10-01 16:29:19] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1664630959 101 Oct 01 16:29:19 volumio volumio[1260]: 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 Oct 01 16:29:23 volumio volumio[1260]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 3 Oct 01 16:29:23 volumio volumio[1260]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 01 16:29:24 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 01 16:29:24 volumio sudo[1781]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 01 16:29:24 volumio sudo[1778]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 01 16:29:24 volumio sudo[1782]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 01 16:29:24 volumio sudo[1781]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:24 volumio sudo[1778]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:24 volumio sudo[1782]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 16:29:24 volumio sudo[1781]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:24 volumio sudo[1778]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:24 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Oct 01 16:29:24 volumio sudo[1782]: pam_unix(sudo:session): session closed for user root Oct 01 16:29:25 volumio volumio[1260]: info: Upmpdcli Daemon Started Oct 01 16:29:25 volumio volumio[1802]: Generating RSA private key, 4096 bit long modulus (2 primes) Oct 01 16:29:25 volumio volumio[1260]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 4 Oct 01 16:29:25 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 01 16:29:25 volumio volumio[1260]: info: CoreCommandRouter::volumioGetVisibleSources Oct 01 16:29:25 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 01 16:29:25 volumio volumio[1260]: info: CoreCommandRouter::volumioGetState Oct 01 16:29:25 volumio volumio[1260]: info: CorePlayQueue::getTrack 0 Oct 01 16:29:25 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 01 16:29:25 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 01 16:29:25 volumio volumio[1260]: info: Received Get System Info Oct 01 16:29:25 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 01 16:29:25 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 01 16:29:25 volumio volumio[1260]: info: Discovery: Getting this device information Oct 01 16:29:25 volumio volumio[1260]: info: CoreCommandRouter::volumioGetState Oct 01 16:29:25 volumio volumio[1260]: info: CorePlayQueue::getTrack 0 Oct 01 16:29:25 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 01 16:29:25 volumio volumio[1260]: info: CoreCommandRouter::volumioGetState Oct 01 16:29:25 volumio volumio[1260]: info: CorePlayQueue::getTrack 0 Oct 01 16:29:25 volumio volumio[1260]: info: Listing playlists Oct 01 16:29:25 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 01 16:29:25 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 01 16:29:26 volumio volumio[1260]: info: CoreCommandRouter::volumioGetState Oct 01 16:29:26 volumio volumio[1260]: info: CorePlayQueue::getTrack 0 Oct 01 16:29:26 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 01 16:29:26 volumio volumio[1260]: info: Received Get System Info Oct 01 16:29:26 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 01 16:29:26 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 01 16:29:26 volumio volumio[1260]: info: Discovery: Getting this device information Oct 01 16:29:26 volumio volumio[1260]: info: CoreCommandRouter::volumioGetState Oct 01 16:29:26 volumio volumio[1260]: info: CorePlayQueue::getTrack 0 Oct 01 16:29:26 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 01 16:29:27 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 01 16:29:27 volumio volumio[1802]: .................................................++++ Oct 01 16:29:29 volumio volumio[1802]: .................................++++ Oct 01 16:29:29 volumio volumio[1802]: e is 65537 (0x010001) Oct 01 16:29:29 volumio volumio[1802]: writing RSA key Oct 01 16:29:35 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 01 16:29:38 volumio volumio[1260]: error: MyVolumio Plugin failed to start in a timely fashion Oct 01 16:29:38 volumio volumio[1260]: info: BOOT COMPLETED Oct 01 16:29:38 volumio volumio[1260]: [Metrics] CommandRouter: 26s 62.86ms Oct 01 16:29:38 volumio volumio[1260]: info: CoreCommandRouter::volumiosetStartupVolume Oct 01 16:29:38 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 01 16:29:38 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 01 16:29:38 volumio volumio[1260]: info: CoreCommandRouter::Close All Modals sent Oct 01 16:29:38 volumio volumio[1260]: info: CoreCommandRouter::Close All Modals sent Oct 01 16:29:39 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 01 16:29:39 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 01 16:29:40 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 01 16:29:46 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 01 16:29:46 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 01 16:29:46 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 01 16:30:08 volumio ntpd[1174]: Soliciting pool server 162.159.200.123 Oct 01 16:30:10 volumio ntpd[1174]: Soliciting pool server 37.27.202.175 Oct 01 16:30:11 volumio ntpd[1174]: Soliciting pool server 95.216.138.141 Oct 01 16:30:14 volumio ntpd[1174]: Soliciting pool server 37.27.6.27 Oct 01 16:30:15 volumio volumio[1260]: info: Clearing queue after UPNP request Oct 01 16:30:15 volumio volumio[1260]: info: CoreStateMachine::ClearQueue Oct 01 16:30:15 volumio volumio[1260]: info: CoreStateMachine::stop Oct 01 16:30:15 volumio volumio[1260]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 01 16:30:15 volumio volumio[1260]: info: CorePlayQueue::clearPlayQueue Oct 01 16:30:15 volumio volumio[1260]: info: CorePlayQueue::saveQueue Oct 01 16:30:15 volumio volumio[1260]: info: CoreCommandRouter::volumioPushState Oct 01 16:30:15 volumio volumio[1260]: info: CoreCommandRouter::volumioPushQueue Oct 01 16:30:15 volumio volumio[1260]: info: Oct 01 16:30:15 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:15 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:15 volumio volumio[1260]: info: Oct 01 16:30:15 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:15 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:15 volumio volumio[1260]: info: Oct 01 16:30:15 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:15 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:15 volumio volumio[1260]: error: updateQueue error: null Oct 01 16:30:15 volumio volumio[1260]: error: updateQueue error: null Oct 01 16:30:15 volumio volumio[1260]: error: updateQueue error: null Oct 01 16:30:15 volumio volumio[1260]: info: ------------------------------ 6ms Oct 01 16:30:15 volumio volumio[1260]: info: ------------------------------ 4ms Oct 01 16:30:15 volumio volumio[1260]: info: ------------------------------ 3ms Oct 01 16:30:15 volumio volumio[1260]: info: Starting UPNP Playback Oct 01 16:30:15 volumio volumio[1260]: info: Preparing playback through UPNP Oct 01 16:30:15 volumio volumio[1260]: info: CoreCommandRouter::volumioGetState Oct 01 16:30:15 volumio volumio[1260]: info: CorePlayQueue::getTrack 0 Oct 01 16:30:15 volumio volumio[1260]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 01 16:30:16 volumio volumio[1260]: info: Oct 01 16:30:16 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:16 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:16 volumio volumio[1260]: info: Oct 01 16:30:16 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:16 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:16 volumio volumio[1260]: info: Oct 01 16:30:16 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:16 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:16 volumio volumio[1260]: info: Oct 01 16:30:16 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:16 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:16 volumio volumio[1260]: info: ------------------------------ 7ms Oct 01 16:30:16 volumio volumio[1260]: info: ------------------------------ 6ms Oct 01 16:30:16 volumio volumio[1260]: info: ------------------------------ 4ms Oct 01 16:30:16 volumio volumio[1260]: info: Oct 01 16:30:16 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:16 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:16 volumio volumio[1260]: info: Oct 01 16:30:16 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:16 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:16 volumio volumio[1260]: info: ------------------------------ 4ms Oct 01 16:30:16 volumio volumio[1260]: info: ------------------------------ 3ms Oct 01 16:30:16 volumio volumio[1260]: info: ------------------------------ 2ms Oct 01 16:30:16 volumio volumio[1260]: info: Oct 01 16:30:16 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:16 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:16 volumio volumio[1260]: info: Oct 01 16:30:16 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:16 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:16 volumio volumio[1260]: info: Oct 01 16:30:16 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:16 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:16 volumio volumio[1260]: info: ------------------------------ 4ms Oct 01 16:30:16 volumio volumio[1260]: info: ------------------------------ 3ms Oct 01 16:30:16 volumio volumio[1260]: info: ------------------------------ 2ms Oct 01 16:30:16 volumio volumio[1260]: info: Oct 01 16:30:16 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:16 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:16 volumio volumio[1260]: info: Oct 01 16:30:16 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:16 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:16 volumio volumio[1260]: info: Oct 01 16:30:16 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:16 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:16 volumio volumio[1260]: info: ------------------------------ 2ms Oct 01 16:30:16 volumio volumio[1260]: info: ------------------------------ 2ms Oct 01 16:30:16 volumio volumio[1260]: info: ------------------------------ 2ms Oct 01 16:30:16 volumio volumio[1260]: info: Oct 01 16:30:16 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:16 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:16 volumio volumio[1260]: info: Oct 01 16:30:16 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:16 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:16 volumio volumio[1260]: info: Oct 01 16:30:16 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:16 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:16 volumio volumio[1260]: info: ------------------------------ 7ms Oct 01 16:30:16 volumio volumio[1260]: info: ------------------------------ 6ms Oct 01 16:30:16 volumio volumio[1260]: info: ------------------------------ 2ms Oct 01 16:30:16 volumio volumio[1260]: info: Oct 01 16:30:16 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:16 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:16 volumio volumio[1260]: info: Oct 01 16:30:16 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:16 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:16 volumio volumio[1260]: info: Oct 01 16:30:16 volumio volumio[1260]: ---------------------------- MPD announces system playlist update Oct 01 16:30:16 volumio volumio[1260]: info: Ignoring MPD Status Update Oct 01 16:30:16 volumio volumio[1260]: info: ------------------------------ 4ms Oct 01 16:30:16 volumio volumio[1260]: info: ------------------------------ 3ms Oct 01 16:30:16 volumio volumio[1260]: info: ------------------------------ 2ms Oct 01 16:30:17 volumio volumio[1260]: info: Oct 01 16:30:17 volumio volumio[1260]: ---------------------------- MPD announces state update: player Oct 01 16:30:17 volumio volumio[1260]: info: ControllerMpd::getState Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::sendMpdCommand status Oct 01 16:30:17 volumio volumio[1260]: info: Oct 01 16:30:17 volumio volumio[1260]: ---------------------------- MPD announces state update: player Oct 01 16:30:17 volumio volumio[1260]: info: ControllerMpd::getState Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::sendMpdCommand status Oct 01 16:30:17 volumio volumio[1260]: info: Oct 01 16:30:17 volumio volumio[1260]: ---------------------------- MPD announces state update: player Oct 01 16:30:17 volumio volumio[1260]: info: ControllerMpd::getState Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::sendMpdCommand status Oct 01 16:30:17 volumio volumio[1260]: info: Oct 01 16:30:17 volumio volumio[1260]: ---------------------------- MPD announces state update: player Oct 01 16:30:17 volumio volumio[1260]: info: sendMpdCommand status took 5 milliseconds Oct 01 16:30:17 volumio volumio[1260]: info: ControllerMpd::getState Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::sendMpdCommand status Oct 01 16:30:17 volumio volumio[1260]: info: sendMpdCommand status took 5 milliseconds Oct 01 16:30:17 volumio volumio[1260]: info: sendMpdCommand status took 3 milliseconds Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::parseState Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::parseState Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::parseState Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 16:30:17 volumio volumio[1260]: info: Oct 01 16:30:17 volumio volumio[1260]: ---------------------------- MPD announces state update: player Oct 01 16:30:17 volumio volumio[1260]: info: ControllerMpd::getState Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::sendMpdCommand status Oct 01 16:30:17 volumio volumio[1260]: info: Oct 01 16:30:17 volumio volumio[1260]: ---------------------------- MPD announces state update: player Oct 01 16:30:17 volumio volumio[1260]: info: ControllerMpd::getState Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::sendMpdCommand status Oct 01 16:30:17 volumio volumio[1260]: info: sendMpdCommand status took 9 milliseconds Oct 01 16:30:17 volumio volumio[1260]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 01 16:30:17 volumio volumio[1260]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 01 16:30:17 volumio volumio[1260]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 01 16:30:17 volumio volumio[1260]: info: sendMpdCommand status took 5 milliseconds Oct 01 16:30:17 volumio volumio[1260]: info: sendMpdCommand status took 4 milliseconds Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::parseState Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::parseTrackInfo Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::parseTrackInfo Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::parseTrackInfo Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::parseState Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::parseState Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 16:30:17 volumio volumio[1260]: info: ControllerMpd::pushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::servicePushState Oct 01 16:30:17 volumio volumio[1260]: verbose: In UPNP mode Oct 01 16:30:17 volumio volumio[1260]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Pompeii Intro ","artist":"Pink Floyd","album":"Pink Floyd at Pompeii - MCMLXXII ","uri":"http://192.168.1.207:11476/qobuz/317986725.flac","trackType":"qobuz"} Oct 01 16:30:17 volumio volumio[1260]: verbose: CURRENT POSITION 0 Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::syncState stateService play Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::syncState currentStatus stop Oct 01 16:30:17 volumio volumio[1260]: info: ControllerMpd::pushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::servicePushState Oct 01 16:30:17 volumio volumio[1260]: verbose: In UPNP mode Oct 01 16:30:17 volumio volumio[1260]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Pompeii Intro ","artist":"Pink Floyd","album":"Pink Floyd at Pompeii - MCMLXXII ","uri":"http://192.168.1.207:11476/qobuz/317986725.flac","trackType":"qobuz"} Oct 01 16:30:17 volumio volumio[1260]: verbose: CURRENT POSITION 0 Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::syncState stateService play Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::syncState currentStatus play Oct 01 16:30:17 volumio volumio[1260]: info: Received an update from plugin. extracting info from payload Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::pushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioPushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::pushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioPushState Oct 01 16:30:17 volumio volumio[1260]: info: ControllerMpd::pushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::servicePushState Oct 01 16:30:17 volumio volumio[1260]: verbose: In UPNP mode Oct 01 16:30:17 volumio volumio[1260]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Pompeii Intro ","artist":"Pink Floyd","album":"Pink Floyd at Pompeii - MCMLXXII ","uri":"http://192.168.1.207:11476/qobuz/317986725.flac","trackType":"qobuz"} Oct 01 16:30:17 volumio volumio[1260]: verbose: CURRENT POSITION 0 Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::syncState stateService play Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::syncState currentStatus play Oct 01 16:30:17 volumio volumio[1260]: info: Received an update from plugin. extracting info from payload Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::pushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioPushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::pushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioPushState Oct 01 16:30:17 volumio volumio[1260]: info: ------------------------------ 41ms Oct 01 16:30:17 volumio volumio[1260]: info: ------------------------------ 55ms Oct 01 16:30:17 volumio volumio[1260]: info: sendMpdCommand playlistinfo took 46 milliseconds Oct 01 16:30:17 volumio volumio[1260]: info: sendMpdCommand playlistinfo took 45 milliseconds Oct 01 16:30:17 volumio volumio[1260]: info: sendMpdCommand playlistinfo took 45 milliseconds Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::parseTrackInfo Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::parseTrackInfo Oct 01 16:30:17 volumio volumio[1260]: verbose: ControllerMpd::parseTrackInfo Oct 01 16:30:17 volumio volumio[1260]: info: ControllerMpd::pushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::servicePushState Oct 01 16:30:17 volumio volumio[1260]: verbose: In UPNP mode Oct 01 16:30:17 volumio volumio[1260]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Pompeii Intro ","artist":"Pink Floyd","album":"Pink Floyd at Pompeii - MCMLXXII ","uri":"http://192.168.1.207:11476/qobuz/317986725.flac","trackType":"qobuz"} Oct 01 16:30:17 volumio volumio[1260]: verbose: CURRENT POSITION 0 Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::syncState stateService play Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::syncState currentStatus play Oct 01 16:30:17 volumio volumio[1260]: info: Received an update from plugin. extracting info from payload Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::pushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioPushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::pushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioPushState Oct 01 16:30:17 volumio volumio[1260]: info: ControllerMpd::pushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::servicePushState Oct 01 16:30:17 volumio volumio[1260]: verbose: In UPNP mode Oct 01 16:30:17 volumio volumio[1260]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Pompeii Intro ","artist":"Pink Floyd","album":"Pink Floyd at Pompeii - MCMLXXII ","uri":"http://192.168.1.207:11476/qobuz/317986725.flac","trackType":"qobuz"} Oct 01 16:30:17 volumio volumio[1260]: verbose: CURRENT POSITION 0 Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::syncState stateService play Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::syncState currentStatus play Oct 01 16:30:17 volumio volumio[1260]: info: Received an update from plugin. extracting info from payload Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::pushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioPushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::pushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioPushState Oct 01 16:30:17 volumio volumio[1260]: info: ControllerMpd::pushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::servicePushState Oct 01 16:30:17 volumio volumio[1260]: verbose: In UPNP mode Oct 01 16:30:17 volumio volumio[1260]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Pompeii Intro ","artist":"Pink Floyd","album":"Pink Floyd at Pompeii - MCMLXXII ","uri":"http://192.168.1.207:11476/qobuz/317986725.flac","trackType":"qobuz"} Oct 01 16:30:17 volumio volumio[1260]: verbose: CURRENT POSITION 0 Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::syncState stateService play Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::syncState currentStatus play Oct 01 16:30:17 volumio volumio[1260]: info: Received an update from plugin. extracting info from payload Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::pushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioPushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::pushState Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioPushState Oct 01 16:30:17 volumio volumio[1260]: info: ------------------------------ 112ms Oct 01 16:30:17 volumio volumio[1260]: info: ------------------------------ 106ms Oct 01 16:30:17 volumio volumio[1260]: info: ------------------------------ 106ms Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioGetQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CorePlayQueue::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioGetQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CorePlayQueue::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioGetQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CorePlayQueue::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioGetQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CorePlayQueue::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioGetQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CorePlayQueue::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioGetQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CorePlayQueue::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioGetQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CorePlayQueue::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioGetQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CorePlayQueue::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioGetQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CorePlayQueue::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreCommandRouter::volumioGetQueue Oct 01 16:30:17 volumio volumio[1260]: info: CoreStateMachine::getQueue Oct 01 16:30:17 volumio volumio[1260]: info: CorePlayQueue::getQueue Oct 01 16:30:17 volumio volumio[1260]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 01 16:30:17 volumio volumio[1260]: Error: certificate is not yet valid Oct 01 16:30:17 volumio volumio[1260]: at TLSSocket.onConnectSecure (_tls_wrap.js:1515:34) Oct 01 16:30:17 volumio volumio[1260]: at TLSSocket.emit (events.js:400:28) Oct 01 16:30:17 volumio volumio[1260]: at TLSSocket._finishInit (_tls_wrap.js:937:8) Oct 01 16:30:17 volumio volumio[1260]: at TLSWrap.ssl.onhandshakedone (_tls_wrap.js:709:12) { Oct 01 16:30:17 volumio volumio[1260]: code: 'CERT_NOT_YET_VALID' Oct 01 16:30:17 volumio volumio[1260]: } Oct 01 16:30:17 volumio volumio[1260]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 01 16:30:18 volumio sudo[1942]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2022-10-01 16:29 Oct 01 16:30:18 volumio sudo[1942]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:35:31 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="8e206762eb84baf3ce9616e2bda58682"