Wed Apr 21 15:34:29 UTC 2021 Description="'When controlling playback via websocket, emitting Play after Pause restarts the track at the beginning. This is not the behaviour when using the browser UI'" # cat /proc/version --------------- Linux version 5.4.83-v7+ (dom@buildbot) (gcc version 8.4.0 (Ubuntu/Linaro 8.4.0-3ubuntu1)) #1379 SMP Mon Dec 14 13:08:57 GMT 2020 # cat /etc/os-release --------------- PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="62a21f1a4f8d8e5a6e7a88f1d3bab9e122100505" VOLUMIO_FE_VERSION="74f64fbba9dc8053dc27ed7125863d6ad6533965" VOLUMIO_FE3_VERSION="29e51f0b5353f111b46c7e7219adf488967842ca" VOLUMIO_BE_VERSION="42206ce15c299272f1e111022e7d5dce3e991321" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumiobuster" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 15 Apr 2021 06:48:50 PM CEST" VOLUMIO_VERSION="3.066" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="1cd2b2ea4e4f751afe42d521889ac8e3" # ifconfig --------------- lo: flags=73 mtu 65536 inet 127.0.0.1 netmask 255.0.0.0 loop txqueuelen 1000 (Local Loopback) RX packets 2045 bytes 286287 (279.5 KiB) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 2045 bytes 286287 (279.5 KiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 wlan0: flags=4163 mtu 1500 inet 192.168.0.125 netmask 255.255.255.0 broadcast 192.168.0.255 ether b8:27:eb:fd:49:d1 txqueuelen 1000 (Ethernet) RX packets 8882 bytes 9598093 (9.1 MiB) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 4796 bytes 1163293 (1.1 MiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 # sudo iwconfig --------------- lo no wireless extensions. wlan0 IEEE 802.11 ESSID:"Mozart" Mode:Managed Frequency:5.2 GHz Access Point: 68:FF:7B:32:23:E3 Bit Rate=87.7 Mb/s Tx-Power=31 dBm Retry short limit:7 RTS thr:off Fragment thr:off Encryption key:off Power Management:off Link Quality=52/70 Signal level=-58 dBm Rx invalid nwid:0 Rx invalid crypt:0 Rx invalid frag:0 Tx excessive retries:0 Invalid misc:0 Missed beacon:0 # aplay -l --------------- **** List of PLAYBACK Hardware Devices **** card 0: b1 [bcm2835 HDMI 1], device 0: bcm2835 HDMI 1 [bcm2835 HDMI 1] Subdevices: 4/4 Subdevice #0: subdevice #0 Subdevice #1: subdevice #1 Subdevice #2: subdevice #2 Subdevice #3: subdevice #3 card 1: Headphones [bcm2835 Headphones], device 0: bcm2835 Headphones [bcm2835 Headphones] Subdevices: 4/4 Subdevice #0: subdevice #0 Subdevice #1: subdevice #1 Subdevice #2: subdevice #2 Subdevice #3: subdevice #3 card 2: sndrpihifiberry [snd_rpi_hifiberry_dacplus], device 0: HiFiBerry DAC+ HiFi pcm512x-hifi-0 [HiFiBerry DAC+ HiFi pcm512x-hifi-0] Subdevices: 1/1 Subdevice #0: subdevice #0 # ps -ef --------------- UID PID PPID C STIME TTY TIME CMD root 1 0 5 15:30 ? 00:00:11 /sbin/init root 2 0 0 15:30 ? 00:00:00 [kthreadd] root 3 2 0 15:30 ? 00:00:00 [rcu_gp] root 4 2 0 15:30 ? 00:00:00 [rcu_par_gp] root 5 2 0 15:30 ? 00:00:00 [kworker/0:0-events] root 6 2 0 15:30 ? 00:00:00 [kworker/0:0H-kblockd] root 7 2 0 15:30 ? 00:00:00 [kworker/u8:0-events_unbound] root 8 2 0 15:30 ? 00:00:00 [mm_percpu_wq] root 9 2 0 15:30 ? 00:00:00 [ksoftirqd/0] root 10 2 0 15:30 ? 00:00:00 [rcu_sched] root 11 2 0 15:30 ? 00:00:00 [migration/0] root 12 2 0 15:30 ? 00:00:00 [cpuhp/0] root 13 2 0 15:30 ? 00:00:00 [cpuhp/1] root 14 2 0 15:30 ? 00:00:00 [migration/1] root 15 2 0 15:30 ? 00:00:00 [ksoftirqd/1] root 16 2 0 15:30 ? 00:00:00 [kworker/1:0-events_power_efficient] root 17 2 0 15:30 ? 00:00:00 [kworker/1:0H-kblockd] root 18 2 0 15:30 ? 00:00:00 [cpuhp/2] root 19 2 0 15:30 ? 00:00:00 [migration/2] root 20 2 0 15:30 ? 00:00:00 [ksoftirqd/2] root 21 2 0 15:30 ? 00:00:00 [kworker/2:0-events_power_efficient] root 22 2 0 15:30 ? 00:00:00 [kworker/2:0H-kblockd] root 23 2 0 15:30 ? 00:00:00 [cpuhp/3] root 24 2 0 15:30 ? 00:00:00 [migration/3] root 25 2 0 15:30 ? 00:00:00 [ksoftirqd/3] root 26 2 0 15:30 ? 00:00:00 [kworker/3:0-events] root 27 2 0 15:30 ? 00:00:00 [kworker/3:0H-kblockd] root 28 2 0 15:30 ? 00:00:00 [kdevtmpfs] root 29 2 0 15:30 ? 00:00:00 [netns] root 30 2 0 15:30 ? 00:00:01 [kworker/0:1-events] root 31 2 0 15:30 ? 00:00:00 [kworker/1:1-events] root 32 2 0 15:30 ? 00:00:00 [kauditd] root 33 2 0 15:30 ? 00:00:00 [khungtaskd] root 34 2 0 15:30 ? 00:00:00 [oom_reaper] root 35 2 0 15:30 ? 00:00:00 [writeback] root 36 2 0 15:30 ? 00:00:00 [kcompactd0] root 54 2 0 15:30 ? 00:00:00 [kblockd] root 55 2 0 15:30 ? 00:00:00 [blkcg_punt_bio] root 56 2 0 15:30 ? 00:00:00 [watchdogd] root 57 2 0 15:30 ? 00:00:00 [kworker/2:1-events] root 58 2 0 15:30 ? 00:00:00 [kworker/3:1-events] root 59 2 0 15:30 ? 00:00:00 [rpciod] root 60 2 0 15:30 ? 00:00:00 [kworker/u9:0-hci0] root 61 2 0 15:30 ? 00:00:00 [xprtiod] root 62 2 0 15:30 ? 00:00:00 [kswapd0] root 63 2 0 15:30 ? 00:00:00 [nfsiod] root 64 2 0 15:30 ? 00:00:00 [iscsi_eh] root 65 2 0 15:30 ? 00:00:00 [dwc_otg] root 66 2 0 15:30 ? 00:00:00 [DWC Notificatio] root 67 2 0 15:30 ? 00:00:00 [kworker/0:2-events] root 68 2 0 15:30 ? 00:00:00 [vchiq-slot/0] root 69 2 0 15:30 ? 00:00:00 [vchiq-recy/0] root 70 2 0 15:30 ? 00:00:00 [vchiq-sync/0] root 71 2 0 15:30 ? 00:00:00 [vchiq-keep/0] root 72 2 0 15:30 ? 00:00:00 [SMIO] root 73 2 0 15:30 ? 00:00:00 [kworker/0:3-events] root 81 2 0 15:30 ? 00:00:00 [mmc_complete] root 82 2 0 15:30 ? 00:00:00 [kworker/0:1H-kblockd] root 100 2 0 15:30 ? 00:00:00 [kworker/1:2-events] root 105 2 0 15:30 ? 00:00:00 [kworker/3:1H-kblockd] root 106 2 0 15:30 ? 00:00:00 [kworker/3:2H-kblockd] root 110 2 0 15:30 ? 00:00:00 [kworker/1:1H-kblockd] root 111 2 0 15:30 ? 00:00:00 [kworker/1:2H-kblockd] root 112 2 0 15:30 ? 00:00:00 [jbd2/mmcblk0p2-] root 113 2 0 15:30 ? 00:00:00 [ext4-rsv-conver] root 115 2 0 15:31 ? 00:00:00 [kworker/u8:1-events_unbound] root 121 2 0 15:31 ? 00:00:01 [loop0] root 124 2 0 15:31 ? 00:00:00 [kworker/2:1H-kblockd] root 148 2 0 15:31 ? 00:00:00 [jbd2/mmcblk0p3-] root 149 2 0 15:31 ? 00:00:00 [ext4-rsv-conver] root 156 2 0 15:31 ? 00:00:00 [kworker/2:2H-kblockd] root 157 2 0 15:31 ? 00:00:00 [kworker/0:2H-mmc_complete] root 158 2 0 15:31 ? 00:00:00 [ipv6_addrconf] root 180 1 0 15:31 ? 00:00:01 /lib/systemd/systemd-journald root 193 2 0 15:31 ? 00:00:00 [kworker/3:2-events] root 211 1 0 15:31 ? 00:00:00 /lib/systemd/systemd-udevd root 214 2 0 15:31 ? 00:00:00 [kworker/u8:2-flush-179:0] root 232 2 0 15:31 ? 00:00:00 [SMIO] root 248 2 0 15:31 ? 00:00:00 [mmal-vchiq] root 250 2 0 15:31 ? 00:00:00 [mmal-vchiq] root 251 2 0 15:31 ? 00:00:00 [mmal-vchiq] root 253 2 0 15:31 ? 00:00:00 [mmal-vchiq] root 265 2 0 15:31 ? 00:00:00 [kworker/1:3-mm_percpu_wq] root 295 2 0 15:31 ? 00:00:00 [cfg80211] root 297 2 0 15:31 ? 00:00:00 [kworker/2:2] root 304 2 0 15:31 ? 00:00:00 [kworker/2:3-events_power_efficient] root 305 2 0 15:31 ? 00:00:00 [brcmf_wq/mmc1:0] root 306 2 0 15:31 ? 00:00:00 [brcmf_wdog/mmc1] root 307 2 0 15:31 ? 00:00:00 [kworker/2:4-cgroup_destroy] _rpc 359 1 0 15:31 ? 00:00:00 /sbin/rpcbind -f -w root 365 1 0 15:31 ? 00:00:01 /usr/sbin/haveged --Foreground --verbose=1 -w 1024 message+ 387 1 0 15:31 ? 00:00:00 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation --syslog-only root 395 1 0 15:31 ? 00:00:00 /usr/sbin/alsactl -E HOME=/run/alsa -s -n 19 -c rdaemon root 396 1 0 15:31 ? 00:00:00 /lib/systemd/systemd-logind root 397 1 0 15:31 ? 00:00:00 /sbin/wpa_supplicant -u -s -O /run/wpa_supplicant nobody 399 1 0 15:31 ? 00:00:00 /usr/sbin/thd --triggers /etc/triggerhappy/triggers.d/ --socket /run/thd.socket --user nobody --deviceglob /dev/input/event* root 401 2 0 15:31 ? 00:00:00 [kworker/3:3-events] volumio 411 1 0 15:31 ? 00:00:00 /usr/local/bin/volumio-remote-updater avahi 423 1 0 15:31 ? 00:00:00 avahi-daemon: running [volumio3-lr.local] avahi 461 423 0 15:31 ? 00:00:00 avahi-daemon: chroot helper root 492 2 0 15:31 ? 00:00:00 [kworker/u8:3-brcmf_wq/mmc1:0001:1] root 544 1 0 15:31 ? 00:00:00 /usr/sbin/nmbd --foreground --no-process-group root 550 1 0 15:31 ? 00:00:00 /sbin/agetty -o -p -- \u --keep-baud 115200,38400,9600 ttyAMA0 vt220 root 552 1 0 15:31 tty1 00:00:00 /sbin/agetty -o -p -- \u --noclear tty1 linux ntp 553 1 0 15:31 ? 00:00:00 /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 root 574 544 0 15:31 ? 00:00:00 /usr/sbin/nmbd --foreground --no-process-group root 575 1 0 15:31 ? 00:00:00 /usr/sbin/sshd -D root 594 2 0 15:31 ? 00:00:00 [kworker/1:4-events] root 595 2 0 15:31 ? 00:00:00 [kworker/1:5] root 610 2 0 15:31 ? 00:00:00 [kworker/0:4-events] root 611 2 0 15:31 ? 00:00:00 [kworker/0:5] root 615 2 0 15:31 ? 00:00:00 [kworker/0:6-mm_percpu_wq] root 649 1 0 15:31 ? 00:00:00 wpa_supplicant -s -B -Dnl80211,wext -c/etc/wpa_supplicant/wpa_supplicant.conf -iwlan0 root 665 1 0 15:31 ? 00:00:00 /sbin/dhcpcd root 669 2 0 15:31 ? 00:00:00 [kworker/3:4-mm_percpu_wq] root 670 2 0 15:31 ? 00:00:00 [kworker/3:5-mm_percpu_wq] root 671 2 0 15:31 ? 00:00:00 [kworker/3:6-cgroup_destroy] root 672 2 0 15:31 ? 00:00:00 [kworker/3:7] root 676 1 0 15:31 ? 00:00:00 /usr/bin/hciattach /dev/serial1 bcm43xx 460800 noflow - b8:27:eb:02:b6:2e root 679 2 0 15:31 ? 00:00:00 [kworker/u9:1-hci0] root 680 2 0 15:31 ? 00:00:00 [kworker/u9:2-hci0] root 683 1 0 15:31 ? 00:00:00 /usr/lib/bluetooth/bluetoothd --noplugin=sap volumio 807 1 8 15:31 ? 00:00:15 /usr/bin/node /volumio/index.js root 820 1 0 15:31 ? 00:00:00 /usr/sbin/winbindd --foreground --no-process-group root 823 820 0 15:31 ? 00:00:00 winbindd: domain child [VOLUMIO3-LR] root 825 1 0 15:31 ? 00:00:00 /usr/sbin/smbd --foreground --no-process-group root 827 825 0 15:31 ? 00:00:00 /usr/sbin/smbd --foreground --no-process-group root 828 825 0 15:31 ? 00:00:00 /usr/sbin/smbd --foreground --no-process-group root 829 820 0 15:31 ? 00:00:00 winbindd: idmap child root 830 820 0 15:31 ? 00:00:00 winbindd: domain child [BUILTIN] root 832 825 0 15:31 ? 00:00:00 /usr/sbin/smbd --foreground --no-process-group root 872 2 0 15:31 ? 00:00:00 [cifsiod] root 873 2 0 15:31 ? 00:00:00 [smb3decryptd] root 874 2 0 15:31 ? 00:00:00 [cifsfileinfoput] root 875 2 0 15:31 ? 00:00:00 [cifsoplockd] root 877 2 0 15:31 ? 00:00:00 [cifsd] volumio 894 807 0 15:31 ? 00:00:00 /usr/bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 907 894 1 15:31 ? 00:00:01 /usr/bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 909 894 1 15:31 ? 00:00:01 /usr/bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 910 894 1 15:31 ? 00:00:01 /usr/bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart mpd 1002 1 2 15:31 ? 00:00:03 /usr/bin/mpd --no-daemon shairpo+ 1014 1 0 15:31 ? 00:00:00 /usr/bin/shairport-sync --configfile=/tmp/shairport-sync.conf volumio 1033 1 0 15:31 ? 00:00:00 /usr/bin/upmpdcli -c /tmp/upmpdcli.conf volumio 1057 1 0 15:31 ? 00:00:00 /bin/streaming-daemon volumio 1250 807 0 15:34 ? 00:00:00 /bin/sh -c /usr/bin/node /volumio/logsubmit.js 'When controlling playback via websocket, emitting Play after Pause restarts the track at the beginning. This is not the behaviour when using the browser UI' volumio 1251 1250 33 15:34 ? 00:00:00 /usr/bin/node /volumio/logsubmit.js When controlling playback via websocket, emitting Play after Pause restarts the track at the beginning. This is not the behaviour when using the browser UI volumio 1271 1251 0 15:34 ? 00:00:00 /bin/sh -c ps -ef >>/tmp/logondemand 2>&1 volumio 1272 1271 0 15:34 ? 00:00:00 ps -ef # df -h --------------- Filesystem Size Used Avail Use% Mounted on /dev/mmcblk0p2 2.5G 426M 1.9G 19% /imgpart /dev/loop0 358M 358M 0 100% /static overlay 12G 535M 11G 5% / devtmpfs 188M 0 188M 0% /dev tmpfs 231M 0 231M 0% /dev/shm tmpfs 231M 8.9M 222M 4% /run tmpfs 5.0M 4.0K 5.0M 1% /run/lock tmpfs 231M 0 231M 0% /sys/fs/cgroup tmpfs 20M 28K 20M 1% /var/log tmpfs 231M 0 231M 0% /var/spool/cups tmpfs 231M 52K 231M 1% /tmp tmpfs 231M 0 231M 0% /var/spool/cups/tmp /dev/mmcblk0p3 12G 535M 11G 5% /swap /dev/mmcblk0p1 92M 61M 31M 67% /boot //192.168.0.100/itunes 3.6T 1.1T 2.6T 29% /mnt/NAS/iTunes # mount --------------- /dev/mmcblk0p2 on /imgpart type ext4 (rw,relatime) /dev/loop0 on /static type squashfs (ro,relatime) overlay on / type overlay (rw,relatime,lowerdir=/mnt/static,upperdir=/mnt/ext/dyn,workdir=/mnt/ext/work) sysfs on /sys type sysfs (rw,nosuid,nodev,noexec,relatime) proc on /proc type proc (rw,relatime) devtmpfs on /dev type devtmpfs (rw,nosuid,size=191668k,nr_inodes=47917,mode=755) securityfs on /sys/kernel/security type securityfs (rw,nosuid,nodev,noexec,relatime) tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev,noexec) devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000) tmpfs on /run type tmpfs (rw,nosuid,nodev,mode=755) tmpfs on /run/lock type tmpfs (rw,nosuid,nodev,noexec,relatime,size=5120k) tmpfs on /sys/fs/cgroup type tmpfs (ro,nosuid,nodev,noexec,mode=755) cgroup2 on /sys/fs/cgroup/unified type cgroup2 (rw,nosuid,nodev,noexec,relatime,nsdelegate) cgroup on /sys/fs/cgroup/systemd type cgroup (rw,nosuid,nodev,noexec,relatime,xattr,name=systemd) none on /sys/fs/bpf type bpf (rw,nosuid,nodev,noexec,relatime,mode=700) cgroup on /sys/fs/cgroup/pids type cgroup (rw,nosuid,nodev,noexec,relatime,pids) cgroup on /sys/fs/cgroup/net_cls,net_prio type cgroup (rw,nosuid,nodev,noexec,relatime,net_cls,net_prio) cgroup on /sys/fs/cgroup/freezer type cgroup (rw,nosuid,nodev,noexec,relatime,freezer) cgroup on /sys/fs/cgroup/cpuset type cgroup (rw,nosuid,nodev,noexec,relatime,cpuset) cgroup on /sys/fs/cgroup/cpu,cpuacct type cgroup (rw,nosuid,nodev,noexec,relatime,cpu,cpuacct) cgroup on /sys/fs/cgroup/devices type cgroup (rw,nosuid,nodev,noexec,relatime,devices) cgroup on /sys/fs/cgroup/perf_event type cgroup (rw,nosuid,nodev,noexec,relatime,perf_event) cgroup on /sys/fs/cgroup/blkio type cgroup (rw,nosuid,nodev,noexec,relatime,blkio) systemd-1 on /proc/sys/fs/binfmt_misc type autofs (rw,relatime,fd=29,pgrp=1,timeout=0,minproto=5,maxproto=5,direct) debugfs on /sys/kernel/debug type debugfs (rw,relatime) mqueue on /dev/mqueue type mqueue (rw,relatime) sunrpc on /run/rpc_pipefs type rpc_pipefs (rw,relatime) configfs on /sys/kernel/config type configfs (rw,relatime) tmpfs on /var/log type tmpfs (rw,nodev,relatime,size=20480k,mode=777,uid=1000,gid=4) tmpfs on /var/spool/cups type tmpfs (rw,noatime,mode=755) tmpfs on /tmp type tmpfs (rw,noatime,mode=755) tmpfs on /var/spool/cups/tmp type tmpfs (rw,noatime,mode=755) /dev/mmcblk0p3 on /swap type ext4 (rw,relatime) /dev/mmcblk0p1 on /boot type vfat (rw,nosuid,nodev,noexec,relatime,fmask=0111,dmask=0000,allow_utime=0022,codepage=437,iocharset=ascii,shortname=mixed,utf8,errors=remount-ro,user) //192.168.0.100/itunes on /mnt/NAS/iTunes type cifs (ro,relatime,vers=3.1.1,sec=none,cache=strict,uid=0,noforceuid,gid=0,noforcegid,addr=192.168.0.100,file_mode=0666,dir_mode=0777,soft,nounix,serverino,mapposix,rsize=4194304,wsize=4194304,bsize=1048576,echo_interval=60,actimeo=1) # sudo journalctl -p 7 --------------- -- Logs begin at Thu 2019-02-14 10:11:59 UTC, end at Wed 2021-04-21 15:34:30 UTC. -- Feb 14 10:11:59 volumio3-lr kernel: Booting Linux on physical CPU 0x0 Feb 14 10:11:59 volumio3-lr kernel: Linux version 5.4.83-v7+ (dom@buildbot) (gcc version 8.4.0 (Ubuntu/Linaro 8.4.0-3ubuntu1)) #1379 SMP Mon Dec 14 13:08:57 GMT 2020 Feb 14 10:11:59 volumio3-lr kernel: CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d Feb 14 10:11:59 volumio3-lr kernel: CPU: div instructions available: patching division code Feb 14 10:11:59 volumio3-lr kernel: CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache Feb 14 10:11:59 volumio3-lr kernel: OF: fdt: Machine model: Raspberry Pi 3 Model A Plus Rev 1.0 Feb 14 10:11:59 volumio3-lr kernel: Memory policy: Data cache writealloc Feb 14 10:11:59 volumio3-lr kernel: Reserved memory: created CMA memory pool at 0x18800000, size 64 MiB Feb 14 10:11:59 volumio3-lr kernel: OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool Feb 14 10:11:59 volumio3-lr kernel: On node 0 totalpages: 122880 Feb 14 10:11:59 volumio3-lr kernel: Normal zone: 1080 pages used for memmap Feb 14 10:11:59 volumio3-lr kernel: Normal zone: 0 pages reserved Feb 14 10:11:59 volumio3-lr kernel: Normal zone: 122880 pages, LIFO batch:31 Feb 14 10:11:59 volumio3-lr kernel: percpu: Embedded 20 pages/cpu s49740 r8192 d23988 u81920 Feb 14 10:11:59 volumio3-lr kernel: pcpu-alloc: s49740 r8192 d23988 u81920 alloc=20*4096 Feb 14 10:11:59 volumio3-lr kernel: pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 Feb 14 10:11:59 volumio3-lr kernel: Built 1 zonelists, mobility grouping on. Total pages: 121800 Feb 14 10:11:59 volumio3-lr kernel: Kernel command line: coherent_pool=1M 8250.nr_uarts=1 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=640 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x1ec00000 vc_mem.mem_size=0x20000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyAMA0,115200 console=tty1 imgpart=/dev/mmcblk0p2 imgfile=/volumio_current.sqsh rootwait bootdelay=5 elevator=noop logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 loglevel=8 Feb 14 10:11:59 volumio3-lr kernel: Dentry cache hash table entries: 65536 (order: 6, 262144 bytes, linear) Feb 14 10:11:59 volumio3-lr kernel: Inode-cache hash table entries: 32768 (order: 5, 131072 bytes, linear) Feb 14 10:11:59 volumio3-lr kernel: mem auto-init: stack:off, heap alloc:off, heap free:off Feb 14 10:11:59 volumio3-lr kernel: Memory: 383336K/491520K available (9216K kernel code, 698K rwdata, 2608K rodata, 1024K init, 827K bss, 42648K reserved, 65536K cma-reserved) Feb 14 10:11:59 volumio3-lr kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Feb 14 10:11:59 volumio3-lr kernel: ftrace: allocating 29205 entries in 58 pages Feb 14 10:11:59 volumio3-lr kernel: rcu: Hierarchical RCU implementation. Feb 14 10:11:59 volumio3-lr kernel: rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies. Feb 14 10:11:59 volumio3-lr kernel: NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 Feb 14 10:11:59 volumio3-lr kernel: random: get_random_bytes called from start_kernel+0x324/0x4f8 with crng_init=0 Feb 14 10:11:59 volumio3-lr kernel: arch_timer: cp15 timer(s) running at 19.20MHz (phys). Feb 14 10:11:59 volumio3-lr kernel: clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns Feb 14 10:11:59 volumio3-lr kernel: sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns Feb 14 10:11:59 volumio3-lr kernel: Switching to timer-based delay loop, resolution 52ns Feb 14 10:11:59 volumio3-lr kernel: Console: colour dummy device 80x30 Feb 14 10:11:59 volumio3-lr kernel: printk: console [tty1] enabled Feb 14 10:11:59 volumio3-lr kernel: Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000) Feb 14 10:11:59 volumio3-lr kernel: pid_max: default: 32768 minimum: 301 Feb 14 10:11:59 volumio3-lr kernel: LSM: Security Framework initializing Feb 14 10:11:59 volumio3-lr kernel: Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear) Feb 14 10:11:59 volumio3-lr kernel: Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear) Feb 14 10:11:59 volumio3-lr kernel: Disabling memory control group subsystem Feb 14 10:11:59 volumio3-lr kernel: CPU: Testing write buffer coherency: ok Feb 14 10:11:59 volumio3-lr kernel: CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 Feb 14 10:11:59 volumio3-lr kernel: Setting up static identity map for 0x100000 - 0x10003c Feb 14 10:11:59 volumio3-lr kernel: rcu: Hierarchical SRCU implementation. Feb 14 10:11:59 volumio3-lr kernel: smp: Bringing up secondary CPUs ... Feb 14 10:11:59 volumio3-lr kernel: CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 Feb 14 10:11:59 volumio3-lr kernel: CPU2: thread -1, cpu 2, socket 0, mpidr 80000002 Feb 14 10:11:59 volumio3-lr kernel: CPU3: thread -1, cpu 3, socket 0, mpidr 80000003 Feb 14 10:11:59 volumio3-lr kernel: smp: Brought up 1 node, 4 CPUs Feb 14 10:11:59 volumio3-lr kernel: SMP: Total of 4 processors activated (153.60 BogoMIPS). Feb 14 10:11:59 volumio3-lr kernel: CPU: All CPU(s) started in HYP mode. Feb 14 10:11:59 volumio3-lr kernel: CPU: Virtualization extensions available. Feb 14 10:11:59 volumio3-lr kernel: devtmpfs: initialized Feb 14 10:11:59 volumio3-lr kernel: VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4 Feb 14 10:11:59 volumio3-lr kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns Feb 14 10:11:59 volumio3-lr kernel: futex hash table entries: 1024 (order: 4, 65536 bytes, linear) Feb 14 10:11:59 volumio3-lr kernel: pinctrl core: initialized pinctrl subsystem Feb 14 10:11:59 volumio3-lr kernel: NET: Registered protocol family 16 Feb 14 10:11:59 volumio3-lr kernel: DMA: preallocated 1024 KiB pool for atomic coherent allocations Feb 14 10:11:59 volumio3-lr kernel: audit: initializing netlink subsys (disabled) Feb 14 10:11:59 volumio3-lr kernel: audit: type=2000 audit(0.040:1): state=initialized audit_enabled=0 res=1 Feb 14 10:11:59 volumio3-lr kernel: hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. Feb 14 10:11:59 volumio3-lr kernel: hw-breakpoint: maximum watchpoint size is 8 bytes. Feb 14 10:11:59 volumio3-lr kernel: Serial: AMBA PL011 UART driver Feb 14 10:11:59 volumio3-lr kernel: bcm2835-mbox 3f00b880.mailbox: mailbox enabled Feb 14 10:11:59 volumio3-lr kernel: raspberrypi-firmware soc:firmware: Attached to firmware from 2021-01-08 14:33, variant start Feb 14 10:11:59 volumio3-lr kernel: raspberrypi-firmware soc:firmware: Firmware hash is 194a85abd768c7334bbadc3f1911c10a7d18ed14 Feb 14 10:11:59 volumio3-lr kernel: bcm2835-dma 3f007000.dma: DMA legacy API manager, dmachans=0x1 Feb 14 10:11:59 volumio3-lr kernel: SCSI subsystem initialized Feb 14 10:11:59 volumio3-lr kernel: usbcore: registered new interface driver usbfs Feb 14 10:11:59 volumio3-lr kernel: usbcore: registered new interface driver hub Feb 14 10:11:59 volumio3-lr kernel: usbcore: registered new device driver usb Feb 14 10:11:59 volumio3-lr kernel: clocksource: Switched to clocksource arch_sys_counter Feb 14 10:11:59 volumio3-lr kernel: VFS: Disk quotas dquot_6.6.0 Feb 14 10:11:59 volumio3-lr kernel: VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) Feb 14 10:11:59 volumio3-lr kernel: FS-Cache: Loaded Feb 14 10:11:59 volumio3-lr kernel: CacheFiles: Loaded Feb 14 10:11:59 volumio3-lr kernel: thermal_sys: Registered thermal governor 'step_wise' Feb 14 10:11:59 volumio3-lr kernel: NET: Registered protocol family 2 Feb 14 10:11:59 volumio3-lr kernel: tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear) Feb 14 10:11:59 volumio3-lr kernel: TCP established hash table entries: 4096 (order: 2, 16384 bytes, linear) Feb 14 10:11:59 volumio3-lr kernel: TCP bind hash table entries: 4096 (order: 3, 32768 bytes, linear) Feb 14 10:11:59 volumio3-lr kernel: TCP: Hash tables configured (established 4096 bind 4096) Feb 14 10:11:59 volumio3-lr kernel: UDP hash table entries: 256 (order: 1, 8192 bytes, linear) Feb 14 10:11:59 volumio3-lr kernel: UDP-Lite hash table entries: 256 (order: 1, 8192 bytes, linear) Feb 14 10:11:59 volumio3-lr kernel: NET: Registered protocol family 1 Feb 14 10:11:59 volumio3-lr kernel: RPC: Registered named UNIX socket transport module. Feb 14 10:11:59 volumio3-lr kernel: RPC: Registered udp transport module. Feb 14 10:11:59 volumio3-lr kernel: RPC: Registered tcp transport module. Feb 14 10:11:59 volumio3-lr kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Feb 14 10:11:59 volumio3-lr kernel: Trying to unpack rootfs image as initramfs... Feb 14 10:11:59 volumio3-lr kernel: Freeing initrd memory: 22504K Feb 14 10:11:59 volumio3-lr kernel: hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available Feb 14 10:11:59 volumio3-lr kernel: Initialise system trusted keyrings Feb 14 10:11:59 volumio3-lr kernel: workingset: timestamp_bits=14 max_order=17 bucket_order=3 Feb 14 10:11:59 volumio3-lr kernel: FS-Cache: Netfs 'nfs' registered for caching Feb 14 10:11:59 volumio3-lr kernel: NFS: Registering the id_resolver key type Feb 14 10:11:59 volumio3-lr kernel: Key type id_resolver registered Feb 14 10:11:59 volumio3-lr kernel: Key type id_legacy registered Feb 14 10:11:59 volumio3-lr kernel: nfs4filelayout_init: NFSv4 File Layout Driver Registering... Feb 14 10:11:59 volumio3-lr kernel: Key type asymmetric registered Feb 14 10:11:59 volumio3-lr kernel: Asymmetric key parser 'x509' registered Feb 14 10:11:59 volumio3-lr kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249) Feb 14 10:11:59 volumio3-lr kernel: io scheduler mq-deadline registered Feb 14 10:11:59 volumio3-lr kernel: io scheduler kyber registered Feb 14 10:11:59 volumio3-lr kernel: bcm2708_fb soc:fb: FB found 1 display(s) Feb 14 10:11:59 volumio3-lr kernel: Console: switching to colour frame buffer device 80x30 Feb 14 10:11:59 volumio3-lr kernel: bcm2708_fb soc:fb: Registered framebuffer for display 0, size 640x480 Feb 14 10:11:59 volumio3-lr kernel: Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled Feb 14 10:11:59 volumio3-lr kernel: bcm2835-rng 3f104000.rng: hwrng registered Feb 14 10:11:59 volumio3-lr kernel: vc-mem: phys_addr:0x00000000 mem_base=0x1ec00000 mem_size:0x20000000(512 MiB) Feb 14 10:11:59 volumio3-lr kernel: vc-sm: Videocore shared memory driver Feb 14 10:11:59 volumio3-lr kernel: gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000 Feb 14 10:11:59 volumio3-lr kernel: brd: module loaded Feb 14 10:11:59 volumio3-lr kernel: loop: module loaded Feb 14 10:11:59 volumio3-lr kernel: Loading iSCSI transport class v2.0-870. Feb 14 10:11:59 volumio3-lr kernel: libphy: Fixed MDIO Bus: probed Feb 14 10:11:59 volumio3-lr kernel: usbcore: registered new interface driver lan78xx Feb 14 10:11:59 volumio3-lr kernel: usbcore: registered new interface driver smsc95xx Feb 14 10:11:59 volumio3-lr kernel: dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Feb 14 10:11:59 volumio3-lr kernel: Core Release: 2.80a Feb 14 10:11:59 volumio3-lr kernel: Setting default values for core params Feb 14 10:11:59 volumio3-lr kernel: Finished setting default values for core params Feb 14 10:11:59 volumio3-lr kernel: Using Buffer DMA mode Feb 14 10:11:59 volumio3-lr kernel: Periodic Transfer Interrupt Enhancement - disabled Feb 14 10:11:59 volumio3-lr kernel: Multiprocessor Interrupt Enhancement - disabled Feb 14 10:11:59 volumio3-lr kernel: OTG VER PARAM: 0, OTG VER FLAG: 0 Feb 14 10:11:59 volumio3-lr kernel: Dedicated Tx FIFOs mode Feb 14 10:11:59 volumio3-lr kernel: WARN::dwc_otg_hcd_init:1074: FIQ DMA bounce buffers: virt = 98914000 dma = 0xd8914000 len=9024 Feb 14 10:11:59 volumio3-lr kernel: FIQ FSM acceleration enabled for : Non-periodic Split Transactions Periodic Split Transactions High-Speed Isochronous Endpoints Interrupt/Control Split Transaction hack enabled Feb 14 10:11:59 volumio3-lr kernel: dwc_otg: Microframe scheduler enabled Feb 14 10:11:59 volumio3-lr kernel: WARN::hcd_init_fiq:457: FIQ on core 1 Feb 14 10:11:59 volumio3-lr kernel: WARN::hcd_init_fiq:458: FIQ ASM at 8070bf24 length 36 Feb 14 10:11:59 volumio3-lr kernel: WARN::hcd_init_fiq:497: MPHI regs_base at 9e810000 Feb 14 10:11:59 volumio3-lr kernel: dwc_otg 3f980000.usb: DWC OTG Controller Feb 14 10:11:59 volumio3-lr kernel: dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1 Feb 14 10:11:59 volumio3-lr kernel: dwc_otg 3f980000.usb: irq 56, io mem 0x00000000 Feb 14 10:11:59 volumio3-lr kernel: Init: Port Power? op_state=1 Feb 14 10:11:59 volumio3-lr kernel: Init: Power Port (0) Feb 14 10:11:59 volumio3-lr kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.04 Feb 14 10:11:59 volumio3-lr kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Feb 14 10:11:59 volumio3-lr kernel: usb usb1: Product: DWC OTG Controller Feb 14 10:11:59 volumio3-lr kernel: usb usb1: Manufacturer: Linux 5.4.83-v7+ dwc_otg_hcd Feb 14 10:11:59 volumio3-lr kernel: usb usb1: SerialNumber: 3f980000.usb Feb 14 10:11:59 volumio3-lr kernel: hub 1-0:1.0: USB hub found Feb 14 10:11:59 volumio3-lr kernel: hub 1-0:1.0: 1 port detected Feb 14 10:11:59 volumio3-lr kernel: dwc_otg: FIQ enabled Feb 14 10:11:59 volumio3-lr kernel: dwc_otg: NAK holdoff enabled Feb 14 10:11:59 volumio3-lr kernel: dwc_otg: FIQ split-transaction FSM enabled Feb 14 10:11:59 volumio3-lr kernel: Module dwc_common_port init Feb 14 10:11:59 volumio3-lr kernel: usbcore: registered new interface driver usb-storage Feb 14 10:11:59 volumio3-lr kernel: mousedev: PS/2 mouse device common for all mice Feb 14 10:11:59 volumio3-lr kernel: bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Feb 14 10:11:59 volumio3-lr kernel: sdhci: Secure Digital Host Controller Interface driver Feb 14 10:11:59 volumio3-lr kernel: sdhci: Copyright(c) Pierre Ossman Feb 14 10:11:59 volumio3-lr kernel: mmc-bcm2835 3f300000.mmcnr: could not get clk, deferring probe Feb 14 10:11:59 volumio3-lr kernel: sdhost-bcm2835 3f202000.mmc: could not get clk, deferring probe Feb 14 10:11:59 volumio3-lr kernel: sdhci-pltfm: SDHCI platform and OF driver helper Feb 14 10:11:59 volumio3-lr kernel: ledtrig-cpu: registered to indicate activity on CPUs Feb 14 10:11:59 volumio3-lr kernel: hidraw: raw HID events driver (C) Jiri Kosina Feb 14 10:11:59 volumio3-lr kernel: usbcore: registered new interface driver usbhid Feb 14 10:11:59 volumio3-lr kernel: usbhid: USB HID core driver Feb 14 10:11:59 volumio3-lr kernel: vchiq: vchiq_init_state: slot_zero = (ptrval) Feb 14 10:11:59 volumio3-lr kernel: [vc_sm_connected_init]: start Feb 14 10:11:59 volumio3-lr kernel: [vc_sm_connected_init]: end - returning 0 Feb 14 10:11:59 volumio3-lr kernel: Initializing XFRM netlink socket Feb 14 10:11:59 volumio3-lr kernel: NET: Registered protocol family 17 Feb 14 10:11:59 volumio3-lr kernel: Key type dns_resolver registered Feb 14 10:11:59 volumio3-lr kernel: Registering SWP/SWPB emulation handler Feb 14 10:11:59 volumio3-lr kernel: registered taskstats version 1 Feb 14 10:11:59 volumio3-lr kernel: Loading compiled-in X.509 certificates Feb 14 10:11:59 volumio3-lr kernel: Key type ._fscrypt registered Feb 14 10:11:59 volumio3-lr kernel: Key type .fscrypt registered Feb 14 10:11:59 volumio3-lr kernel: uart-pl011 3f201000.serial: cts_event_workaround enabled Feb 14 10:11:59 volumio3-lr kernel: 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 81, base_baud = 0) is a PL011 rev2 Feb 14 10:11:59 volumio3-lr kernel: printk: console [ttyAMA0] enabled Feb 14 10:11:59 volumio3-lr kernel: 3f215040.serial: ttyS0 at MMIO 0x0 (irq = 53, base_baud = 50000000) is a 16550 Feb 14 10:11:59 volumio3-lr kernel: bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Feb 14 10:11:59 volumio3-lr kernel: mmc-bcm2835 3f300000.mmcnr: mmc_debug:0 mmc_debug2:0 Feb 14 10:11:59 volumio3-lr kernel: mmc-bcm2835 3f300000.mmcnr: DMA channel allocated Feb 14 10:11:59 volumio3-lr kernel: sdhost: log_buf @ (ptrval) (d8913000) Feb 14 10:11:59 volumio3-lr kernel: mmc1: queuing unknown CIS tuple 0x80 (2 bytes) Feb 14 10:11:59 volumio3-lr kernel: mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Feb 14 10:11:59 volumio3-lr kernel: mmc0: sdhost-bcm2835 loaded - DMA enabled (>1) Feb 14 10:11:59 volumio3-lr kernel: of_cfs_init Feb 14 10:11:59 volumio3-lr kernel: of_cfs_init: OK Feb 14 10:11:59 volumio3-lr kernel: mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Feb 14 10:11:59 volumio3-lr kernel: Freeing unused kernel memory: 1024K Feb 14 10:11:59 volumio3-lr kernel: mmc1: queuing unknown CIS tuple 0x80 (7 bytes) Feb 14 10:11:59 volumio3-lr kernel: Run /init as init process Feb 14 10:11:59 volumio3-lr kernel: random: fast init done Feb 14 10:11:59 volumio3-lr kernel: mmc0: host does not support reading read-only switch, assuming write-enable Feb 14 10:11:59 volumio3-lr kernel: mmc0: new high speed SDHC card at address e624 Feb 14 10:11:59 volumio3-lr kernel: mmcblk0: mmc0:e624 SB16G 14.8 GiB Feb 14 10:11:59 volumio3-lr kernel: mmc1: new high speed SDIO card at address 0001 Feb 14 10:11:59 volumio3-lr kernel: mmcblk0: p1 p2 p3 Feb 14 10:11:59 volumio3-lr initramfs: Booting Volumio for BCM2835 Feb 14 10:11:59 volumio3-lr initramfs: This script mounts rootfs RO with an overlay RW layer. Feb 14 10:11:59 volumio3-lr kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Feb 14 10:11:59 volumio3-lr initramfs: IMGPART=/dev/mmcblk0p2 Feb 14 10:11:59 volumio3-lr initramfs: IMGFILE=/volumio_current.sqsh Feb 14 10:11:59 volumio3-lr initramfs: Boot delay (except first time) will be 5 seconds Feb 14 10:11:59 volumio3-lr initramfs: /dev/mmcblk0p2 not detected,retrying mdev in 5 seconds Feb 14 10:11:59 volumio3-lr initramfs: /dev/mmcblk0p2: Feb 14 10:11:59 volumio3-lr kernel: EXT4-fs (mmcblk0p2): recovery complete Feb 14 10:11:59 volumio3-lr kernel: EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null) Feb 14 10:11:59 volumio3-lr initramfs: Doing a 5 second delay here to give kernel load a headstart Feb 14 10:11:59 volumio3-lr initramfs: Checking for USB updates Feb 14 10:11:59 volumio3-lr initramfs: No USB device detected (when incorrect, try adding 'bootdelay=5' to your boot cmdline) Feb 14 10:11:59 volumio3-lr kernel: EXT4-fs (mmcblk0p3): recovery complete Feb 14 10:11:59 volumio3-lr kernel: EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Opts: (null) Feb 14 10:11:59 volumio3-lr initramfs: With Option: Feb 14 10:11:59 volumio3-lr initramfs: VOLUMIO_VERSION="3.066" Feb 14 10:11:59 volumio3-lr initramfs: Finish initramfs, continue booting Volumio Feb 14 10:11:59 volumio3-lr systemd[1]: System time before build time, advancing clock. Feb 14 10:11:59 volumio3-lr kernel: NET: Registered protocol family 10 Feb 14 10:11:59 volumio3-lr kernel: Segment Routing with IPv6 Feb 14 10:11:59 volumio3-lr systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid) Feb 14 10:11:59 volumio3-lr systemd[1]: Detected architecture arm. Feb 14 10:11:59 volumio3-lr systemd[1]: Set hostname to . Feb 14 10:11:59 volumio3-lr kernel: uart-pl011 3f201000.serial: no DMA platform data Feb 14 10:11:59 volumio3-lr systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Feb 14 10:11:59 volumio3-lr kernel: random: systemd: uninitialized urandom read (16 bytes read) Feb 14 10:11:59 volumio3-lr kernel: random: systemd: uninitialized urandom read (16 bytes read) Feb 14 10:11:59 volumio3-lr kernel: random: systemd: uninitialized urandom read (16 bytes read) Feb 14 10:11:59 volumio3-lr systemd[1]: Created slice system-getty.slice. Feb 14 10:11:59 volumio3-lr systemd[1]: Listening on fsck to fsckd communication Socket. Feb 14 10:11:59 volumio3-lr systemd[1]: Listening on initctl Compatibility Named Pipe. Feb 14 10:11:59 volumio3-lr systemd[1]: Listening on udev Kernel Socket. Feb 14 10:11:59 volumio3-lr systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point. Feb 14 10:11:59 volumio3-lr systemd[1]: Listening on udev Control Socket. Feb 14 10:11:59 volumio3-lr kernel: i2c /dev entries driver Feb 14 10:11:59 volumio3-lr systemd-journald[180]: Journal started Feb 14 10:11:59 volumio3-lr systemd-journald[180]: Runtime journal (/run/log/journal/957a92d3c627cc72862b5a1c60786df2) is 3.7M, max 30.0M, 26.2M free. Feb 14 10:11:59 volumio3-lr systemd-modules-load[172]: Inserted module 'i2c_dev' Feb 14 10:11:59 volumio3-lr systemd[1]: Mounted RPC Pipe File System. Apr 21 15:30:44 volumio3-lr fake-hwclock[177]: Wed Apr 21 15:30:44 UTC 2021 Apr 21 15:30:44 volumio3-lr systemd[1]: Started Remount Root and Kernel File Systems. Apr 21 15:30:44 volumio3-lr systemd[1]: Mounted Kernel Configuration File System. Apr 21 15:30:44 volumio3-lr systemd[1]: Started Apply Kernel Variables. Apr 21 15:30:44 volumio3-lr systemd[1]: Started Restore / save the current clock. Apr 21 15:30:44 volumio3-lr systemd[1]: Starting Create System Users... Apr 21 15:30:44 volumio3-lr systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Apr 21 15:30:44 volumio3-lr systemd[1]: Starting Load/Save Random Seed... Apr 21 15:30:44 volumio3-lr systemd[1]: Started Load/Save Random Seed. Apr 21 15:30:44 volumio3-lr volumio[178]: 512 MB or less RAM Detected, need to enable swap Apr 21 15:30:44 volumio3-lr systemd[1]: Started Create System Users. Apr 21 15:30:44 volumio3-lr systemd[1]: Starting Create Static Device Nodes in /dev... Apr 21 15:30:44 volumio3-lr systemd[1]: Started udev Coldplug all Devices. Apr 21 15:30:44 volumio3-lr systemd[1]: Starting Helper to synchronize boot up for ifupdown... Apr 21 15:30:44 volumio3-lr systemd[1]: Started Create Static Device Nodes in /dev. Apr 21 15:30:44 volumio3-lr systemd[1]: Reached target Local File Systems (Pre). Apr 21 15:30:44 volumio3-lr systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Apr 21 15:30:44 volumio3-lr systemd[1]: Mounting /var/log... Apr 21 15:30:44 volumio3-lr systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Apr 21 15:30:44 volumio3-lr systemd[1]: Mounting /tmp... Apr 21 15:30:44 volumio3-lr systemd[1]: Mounting /var/spool/cups... Apr 21 15:30:44 volumio3-lr systemd[1]: Starting udev Kernel Device Manager... Apr 21 15:30:44 volumio3-lr systemd[1]: Started Helper to synchronize boot up for ifupdown. Apr 21 15:30:44 volumio3-lr systemd[1]: Mounted /var/log. Apr 21 15:30:44 volumio3-lr systemd[1]: Starting Flush Journal to Persistent Storage... Apr 21 15:30:44 volumio3-lr systemd[1]: Mounted /tmp. Apr 21 15:30:44 volumio3-lr systemd[1]: Mounted /var/spool/cups. Apr 21 15:30:44 volumio3-lr systemd[1]: Mounting /var/spool/cups/tmp... Apr 21 15:30:44 volumio3-lr systemd[1]: Mounted /var/spool/cups/tmp. Apr 21 15:30:44 volumio3-lr systemd-udevd[211]: Network interface NamePolicy= disabled on kernel command line, ignoring. Apr 21 15:30:44 volumio3-lr systemd-journald[180]: Runtime journal (/run/log/journal/957a92d3c627cc72862b5a1c60786df2) is 7.5M, max 30.0M, 22.5M free. Apr 21 15:30:44 volumio3-lr systemd[1]: Started Flush Journal to Persistent Storage. Apr 21 15:30:44 volumio3-lr systemd[1]: Started udev Kernel Device Manager. Apr 21 15:30:44 volumio3-lr systemd[1]: Starting Show Plymouth Boot Screen... Apr 21 15:30:44 volumio3-lr kernel: ext4 filesystem being mounted at /swap supports timestamps until 2038 (0x7fffffff) Apr 21 15:30:44 volumio3-lr volumio[178]: Enabling Swap Apr 21 15:30:44 volumio3-lr systemd[1]: Received SIGRTMIN+20 from PID 223 (plymouthd). Apr 21 15:30:44 volumio3-lr systemd[1]: Started Show Plymouth Boot Screen. Apr 21 15:30:44 volumio3-lr systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Apr 21 15:30:44 volumio3-lr systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Apr 21 15:30:44 volumio3-lr systemd[1]: Reached target Local Encrypted Volumes. Apr 21 15:30:44 volumio3-lr systemd[1]: Reached target Paths. Apr 21 15:30:44 volumio3-lr kernel: mc: Linux media interface: v0.10 Apr 21 15:30:44 volumio3-lr kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Apr 21 15:30:44 volumio3-lr kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Apr 21 15:30:44 volumio3-lr kernel: [vc_sm_connected_init]: start Apr 21 15:30:44 volumio3-lr kernel: [vc_sm_connected_init]: installed successfully Apr 21 15:30:44 volumio3-lr kernel: videodev: Linux video capture interface: v2.00 Apr 21 15:30:45 volumio3-lr kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Apr 21 15:30:45 volumio3-lr kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Apr 21 15:30:45 volumio3-lr kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Apr 21 15:30:45 volumio3-lr kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Apr 21 15:30:45 volumio3-lr kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Apr 21 15:30:45 volumio3-lr kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Apr 21 15:30:45 volumio3-lr kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Apr 21 15:30:45 volumio3-lr kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Apr 21 15:30:45 volumio3-lr kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Apr 21 15:30:45 volumio3-lr kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Apr 21 15:30:45 volumio3-lr kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Apr 21 15:30:45 volumio3-lr kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Apr 21 15:30:45 volumio3-lr kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Apr 21 15:30:45 volumio3-lr kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Apr 21 15:30:45 volumio3-lr kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Apr 21 15:30:45 volumio3-lr kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Apr 21 15:30:45 volumio3-lr kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Apr 21 15:30:45 volumio3-lr kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Apr 21 15:30:45 volumio3-lr kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Apr 21 15:30:45 volumio3-lr kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Apr 21 15:30:45 volumio3-lr kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Apr 21 15:30:45 volumio3-lr systemd[1]: Found device /dev/ttyAMA0. Apr 21 15:30:45 volumio3-lr kernel: Adding 524236k swap on /swap/swapfile. Priority:-2 extents:12 across:575480k SSFS Apr 21 15:30:45 volumio3-lr volumio[178]: Setting swappiness to 40 Apr 21 15:30:45 volumio3-lr systemd[1]: Found device /dev/serial1. Apr 21 15:30:45 volumio3-lr volumio[178]: vm.swappiness = 40 Apr 21 15:30:45 volumio3-lr kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Apr 21 15:30:45 volumio3-lr kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Apr 21 15:30:45 volumio3-lr kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Apr 21 15:30:45 volumio3-lr systemd[1]: dynamicswap.service: Succeeded. Apr 21 15:30:45 volumio3-lr kernel: snd-rpi-hifiberry-dacplus soc:sound: ASoC: failed to init link HiFiBerry DAC+: -517 Apr 21 15:30:45 volumio3-lr systemd-udevd[215]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Apr 21 15:30:45 volumio3-lr systemd[1]: Found device /dev/mmcblk0p1. Apr 21 15:30:45 volumio3-lr kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Apr 21 15:30:46 volumio3-lr kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Apr 21 15:30:46 volumio3-lr kernel: snd-rpi-hifiberry-dacplus soc:sound: ASoC: failed to init link HiFiBerry DAC+: -517 Apr 21 15:30:46 volumio3-lr kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Apr 21 15:30:46 volumio3-lr kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Apr 21 15:30:46 volumio3-lr kernel: usbcore: registered new interface driver brcmfmac Apr 21 15:30:46 volumio3-lr kernel: snd-rpi-hifiberry-dacplus soc:sound: ASoC: failed to init link HiFiBerry DAC+: -517 Apr 21 15:30:46 volumio3-lr kernel: brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.raspberrypi,3-model-b-plus.txt failed with error -2 Apr 21 15:30:46 volumio3-lr kernel: snd-rpi-hifiberry-dacplus soc:sound: pcm512x-hifi <-> 3f203000.i2s mapping ok Apr 21 15:30:46 volumio3-lr kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Apr 21 15:30:46 volumio3-lr kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Jan 4 2021 19:56:29 version 7.45.229 (617f1f5 CY) FWID 01-2dbd9d2e Apr 21 15:30:46 volumio3-lr systemd-udevd[226]: Using default interface naming scheme 'v240'. Apr 21 15:30:46 volumio3-lr systemd-udevd[226]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Apr 21 15:30:47 volumio3-lr systemd[1]: Condition check resulted in Huge Pages File System being skipped. Apr 21 15:30:47 volumio3-lr systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Apr 21 15:30:47 volumio3-lr systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Apr 21 15:30:47 volumio3-lr systemd[1]: Condition check resulted in FUSE Control File System being skipped. Apr 21 15:30:47 volumio3-lr systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Apr 21 15:30:47 volumio3-lr systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Apr 21 15:30:47 volumio3-lr systemd[1]: Starting File System Check on /dev/mmcblk0p1... Apr 21 15:30:47 volumio3-lr systemd[1]: Starting Load/Save RF Kill Switch Status... Apr 21 15:30:47 volumio3-lr systemd[1]: Started Load/Save RF Kill Switch Status. Apr 21 15:30:47 volumio3-lr systemd[1]: Started File System Check Daemon to report status. Apr 21 15:30:47 volumio3-lr systemd-fsck[325]: fsck.fat 4.1 (2017-01-24) Apr 21 15:30:47 volumio3-lr systemd-fsck[325]: /dev/mmcblk0p1: 257 files, 31127/46774 clusters Apr 21 15:30:47 volumio3-lr systemd[1]: Started File System Check on /dev/mmcblk0p1. Apr 21 15:30:47 volumio3-lr systemd[1]: Mounting /boot... Apr 21 15:30:47 volumio3-lr systemd[1]: Found device /sys/subsystem/net/devices/wlan0. Apr 21 15:30:47 volumio3-lr systemd[1]: Mounted /boot. Apr 21 15:30:47 volumio3-lr systemd[1]: Reached target Local File Systems. Apr 21 15:30:47 volumio3-lr systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Apr 21 15:30:47 volumio3-lr systemd[1]: Started ifup for wlan0. Apr 21 15:30:47 volumio3-lr systemd[1]: Starting Create Volatile Files and Directories... Apr 21 15:30:47 volumio3-lr systemd[1]: Starting Raise network interfaces... Apr 21 15:30:47 volumio3-lr systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Apr 21 15:30:47 volumio3-lr systemd[1]: Starting Preprocess NFS configuration... Apr 21 15:30:47 volumio3-lr systemd[1]: Received SIGRTMIN+20 from PID 223 (plymouthd). Apr 21 15:30:47 volumio3-lr systemd[1]: plymouth-read-write.service: Succeeded. Apr 21 15:30:47 volumio3-lr systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Apr 21 15:30:47 volumio3-lr systemd[1]: nfs-config.service: Succeeded. Apr 21 15:30:47 volumio3-lr systemd[1]: Started Preprocess NFS configuration. Apr 21 15:30:47 volumio3-lr systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Apr 21 15:30:47 volumio3-lr systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Apr 21 15:30:47 volumio3-lr systemd[1]: Reached target NFS client services. Apr 21 15:30:47 volumio3-lr systemd[1]: Started Create Volatile Files and Directories. Apr 21 15:30:47 volumio3-lr systemd[1]: Starting Update UTMP about System Boot/Shutdown... Apr 21 15:30:47 volumio3-lr systemd[1]: Starting RPC bind portmap service... Apr 21 15:30:47 volumio3-lr systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Apr 21 15:30:47 volumio3-lr systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Apr 21 15:30:47 volumio3-lr systemd[1]: Started Update UTMP about System Boot/Shutdown. Apr 21 15:30:47 volumio3-lr systemd[1]: Reached target System Initialization. Apr 21 15:30:47 volumio3-lr systemd[1]: Listening on D-Bus System Message Bus Socket. Apr 21 15:30:47 volumio3-lr systemd[1]: Started Daily Cleanup of Temporary Directories. Apr 21 15:30:47 volumio3-lr systemd[1]: Started Daily apt download activities. Apr 21 15:30:47 volumio3-lr systemd[1]: Started Daily apt upgrade and clean activities. Apr 21 15:30:47 volumio3-lr systemd[1]: Reached target Timers. Apr 21 15:30:47 volumio3-lr systemd[1]: Listening on mpd.socket. Apr 21 15:30:47 volumio3-lr systemd[1]: Listening on triggerhappy.socket. Apr 21 15:30:47 volumio3-lr systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Apr 21 15:30:47 volumio3-lr systemd[1]: Reached target Sockets. Apr 21 15:30:47 volumio3-lr systemd[1]: Reached target Basic System. Apr 21 15:30:47 volumio3-lr systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Apr 21 15:30:47 volumio3-lr systemd[1]: Starting dhcpcd on all interfaces... Apr 21 15:30:47 volumio3-lr systemd[1]: Started D-Bus System Message Bus. Apr 21 15:30:47 volumio3-lr dhcpcd[386]: Not running dhcpcd because /etc/network/interfaces Apr 21 15:30:47 volumio3-lr dhcpcd[386]: defines some interfaces that will use a Apr 21 15:30:47 volumio3-lr dhcpcd[386]: DHCP client or static address Apr 21 15:30:47 volumio3-lr systemd[1]: Started Manage Sound Card State (restore and store). Apr 21 15:30:47 volumio3-lr systemd[1]: Starting Login Service... Apr 21 15:30:47 volumio3-lr systemd[1]: Starting WPA supplicant... Apr 21 15:30:47 volumio3-lr alsactl[395]: alsactl 1.1.8 daemon started Apr 21 15:30:47 volumio3-lr systemd[1]: Started UPnP Renderer front-end to MPD. Apr 21 15:30:48 volumio3-lr systemd[1]: Starting triggerhappy global hotkey daemon... Apr 21 15:30:48 volumio3-lr systemd[1]: Starting Configure Bluetooth Modems connected by UART... Apr 21 15:30:48 volumio3-lr kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 21 15:30:48 volumio3-lr systemd[1]: Starting Volumio SSH enabler... Apr 21 15:30:48 volumio3-lr systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Apr 21 15:30:48 volumio3-lr systemd[1]: Started Volumio Iptables Module. Apr 21 15:30:48 volumio3-lr thd[399]: Unable to parse trigger line: Apr 21 15:30:48 volumio3-lr systemd[1]: Started volumio-remote-updater.service. Apr 21 15:30:48 volumio3-lr thd[399]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Apr 21 15:30:48 volumio3-lr thd[399]: Unable to parse trigger line: Apr 21 15:30:48 volumio3-lr thd[399]: Unable to parse trigger line: Apr 21 15:30:48 volumio3-lr volumiossh[406]: SSH file found, enabling SSH Apr 21 15:30:48 volumio3-lr thd[399]: Found socket passed from systemd Apr 21 15:30:48 volumio3-lr systemd[1]: Starting Save/Restore Sound Card State... Apr 21 15:30:48 volumio3-lr systemd[1]: Starting Wireless Services... Apr 21 15:30:48 volumio3-lr systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Apr 21 15:30:48 volumio3-lr systemd[1]: Started RPC bind portmap service. Apr 21 15:30:48 volumio3-lr systemd[1]: Started triggerhappy global hotkey daemon. Apr 21 15:30:48 volumio3-lr systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Apr 21 15:30:48 volumio3-lr systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Apr 21 15:30:48 volumio3-lr systemd[1]: Failed to start dhcpcd on all interfaces. Apr 21 15:30:48 volumio3-lr systemd-logind[396]: New seat seat0. Apr 21 15:30:48 volumio3-lr volumiossh[439]: Synchronizing state of ssh.service with SysV service script with /lib/systemd/systemd-sysv-install. Apr 21 15:30:48 volumio3-lr volumiossh[439]: Executing: /lib/systemd/systemd-sysv-install enable ssh Apr 21 15:30:48 volumio3-lr systemd[1]: Started Save/Restore Sound Card State. Apr 21 15:30:48 volumio3-lr systemd[1]: Reached target Sound Card. Apr 21 15:30:48 volumio3-lr systemd[1]: Reached target Remote File Systems (Pre). Apr 21 15:30:48 volumio3-lr systemd[1]: Reached target Remote File Systems. Apr 21 15:30:48 volumio3-lr systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Apr 21 15:30:48 volumio3-lr systemd[1]: Reached target RPC Port Mapper. Apr 21 15:30:48 volumio3-lr sh[332]: wlan0=wlan0 Apr 21 15:30:48 volumio3-lr avahi-daemon[423]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Apr 21 15:30:48 volumio3-lr avahi-daemon[423]: Successfully dropped root privileges. Apr 21 15:30:48 volumio3-lr avahi-daemon[423]: avahi-daemon 0.7 starting up. Apr 21 15:30:48 volumio3-lr dbus-daemon[387]: [system] Successfully activated service 'org.freedesktop.systemd1' Apr 21 15:30:48 volumio3-lr systemd[1]: Started Login Service. Apr 21 15:30:48 volumio3-lr systemd[1]: Started Avahi mDNS/DNS-SD Stack. Apr 21 15:30:48 volumio3-lr avahi-daemon[423]: Successfully called chroot(). Apr 21 15:30:48 volumio3-lr avahi-daemon[423]: Successfully dropped remaining capabilities. Apr 21 15:30:48 volumio3-lr avahi-daemon[423]: Loading service file /services/volumio.service. Apr 21 15:30:48 volumio3-lr avahi-daemon[423]: Network interface enumeration completed. Apr 21 15:30:48 volumio3-lr avahi-daemon[423]: Server startup complete. Host name is volumio3-lr.local. Local service cookie is 1342603320. Apr 21 15:30:48 volumio3-lr avahi-daemon[423]: Service "volumio3-lr" (/services/volumio.service) successfully established. Apr 21 15:30:48 volumio3-lr systemd[1]: Started Raise network interfaces. Apr 21 15:30:49 volumio3-lr loadcpufreq[450]: Loading cpufreq kernel modules...done (none). Apr 21 15:30:49 volumio3-lr systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Apr 21 15:30:49 volumio3-lr systemd[1]: Starting LSB: set CPUFreq kernel parameters... Apr 21 15:30:49 volumio3-lr cpufrequtils[509]: CPUFreq Utilities: Setting performance CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Apr 21 15:30:49 volumio3-lr systemd[1]: Started LSB: set CPUFreq kernel parameters. Apr 21 15:30:49 volumio3-lr systemd[1]: Started WPA supplicant. Apr 21 15:30:49 volumio3-lr systemd[1]: Reached target Network. Apr 21 15:30:49 volumio3-lr systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Apr 21 15:30:49 volumio3-lr wpa_supplicant[397]: Successfully initialized wpa_supplicant Apr 21 15:30:49 volumio3-lr systemd[1]: Starting Music Player Daemon... Apr 21 15:30:49 volumio3-lr systemd[1]: Starting Permit User Sessions... Apr 21 15:30:49 volumio3-lr systemd[1]: Starting Network Time Service... Apr 21 15:30:49 volumio3-lr systemd[1]: Reached target Network is Online. Apr 21 15:30:49 volumio3-lr systemd[1]: Starting LSB: Brings up/down network automatically... Apr 21 15:30:49 volumio3-lr systemd[1]: Starting Samba NMB Daemon... Apr 21 15:30:49 volumio3-lr systemd[1]: Starting /etc/rc.local Compatibility... Apr 21 15:30:49 volumio3-lr systemd[1]: Starting OpenBSD Secure Shell server... Apr 21 15:30:49 volumio3-lr systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 21 15:30:49 volumio3-lr systemd[1]: Started Permit User Sessions. Apr 21 15:30:49 volumio3-lr systemd[1]: Started /etc/rc.local Compatibility. Apr 21 15:30:49 volumio3-lr systemd[1]: iptables.service: Succeeded. Apr 21 15:30:49 volumio3-lr systemd[1]: Starting Terminate Plymouth Boot Screen... Apr 21 15:30:49 volumio3-lr systemd[1]: Starting Hold until boot process finishes up... Apr 21 15:30:49 volumio3-lr systemd[1]: Received SIGRTMIN+21 from PID 223 (plymouthd). Apr 21 15:30:49 volumio3-lr systemd[1]: plymouth-quit.service: Succeeded. Apr 21 15:30:49 volumio3-lr systemd[1]: Started Terminate Plymouth Boot Screen. Apr 21 15:30:49 volumio3-lr systemd[1]: plymouth-quit-wait.service: Succeeded. Apr 21 15:30:49 volumio3-lr systemd[1]: Started Hold until boot process finishes up. Apr 21 15:30:49 volumio3-lr ifplugd[529]: Network Interface Plugging Daemon...skip eth0...done. Apr 21 15:30:49 volumio3-lr systemd[1]: plymouth-start.service: Succeeded. Apr 21 15:30:49 volumio3-lr systemd[1]: Started LSB: Brings up/down network automatically. Apr 21 15:30:49 volumio3-lr systemd[1]: Received SIGRTMIN+21 from PID 223 (n/a). Apr 21 15:30:49 volumio3-lr systemd[1]: Started Serial Getty on ttyAMA0. Apr 21 15:30:49 volumio3-lr systemd[1]: Started Getty on tty1. Apr 21 15:30:49 volumio3-lr systemd[1]: Reached target Login Prompts. Apr 21 15:30:49 volumio3-lr ntpd[528]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 21 15:30:49 volumio3-lr ntpd[528]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Apr 21 15:30:49 volumio3-lr systemd[1]: Started Network Time Service. Apr 21 15:30:49 volumio3-lr volumio-remote-updater[411]: Error: No active session Apr 21 15:30:49 volumio3-lr volumio-remote-updater[411]: [2021-04-21 15:30:49] [info] asio async_connect error: system:111 (Connection refused) Apr 21 15:30:49 volumio3-lr volumio-remote-updater[411]: [2021-04-21 15:30:49] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 21 15:30:49 volumio3-lr volumio-remote-updater[411]: [2021-04-21 15:30:49] [error] handle_connect error: Underlying Transport Error Apr 21 15:30:49 volumio3-lr haveged[365]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Apr 21 15:30:49 volumio3-lr haveged[365]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Apr 21 15:30:49 volumio3-lr haveged[365]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99958 Apr 21 15:30:49 volumio3-lr haveged[365]: haveged: fills: 0, generated: 0 Apr 21 15:30:49 volumio3-lr ntpd[553]: proto: precision = 0.625 usec (-21) Apr 21 15:30:49 volumio3-lr ntpd[553]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 21 15:30:49 volumio3-lr ntpd[553]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2021-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 21 15:30:49 volumio3-lr kernel: random: crng init done Apr 21 15:30:49 volumio3-lr kernel: random: 7 urandom warning(s) missed due to ratelimiting Apr 21 15:30:49 volumio3-lr ntpd[553]: Listen and drop on 0 v6wildcard [::]:123 Apr 21 15:30:49 volumio3-lr ntpd[553]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 21 15:30:49 volumio3-lr ntpd[553]: Listen normally on 2 lo 127.0.0.1:123 Apr 21 15:30:49 volumio3-lr ntpd[553]: Listening on routing socket on fd #19 for interface updates Apr 21 15:30:49 volumio3-lr ntpd[553]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 21 15:30:49 volumio3-lr ntpd[553]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 21 15:30:50 volumio3-lr systemd[1]: Reloading. Apr 21 15:30:50 volumio3-lr volumio[398]: Could not open config: /tmp/upmpdcli.conf Apr 21 15:30:50 volumio3-lr systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Apr 21 15:30:50 volumio3-lr systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. Apr 21 15:30:50 volumio3-lr systemd[1]: serial-getty@ttyAMA0.service: Current command vanished from the unit file, execution of the command list won't be resumed. Apr 21 15:30:50 volumio3-lr systemd[1]: volumiossh.service: Current command vanished from the unit file, execution of the command list won't be resumed. Apr 21 15:30:50 volumio3-lr nmbd[544]: [2021/04/21 15:30:50.886034, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Apr 21 15:30:50 volumio3-lr nmbd[544]: started asyncdns process 574 Apr 21 15:30:50 volumio3-lr nmbd[544]: [2021/04/21 15:30:50.890123, 0] ../lib/util/become_daemon.c:149(daemon_status) Apr 21 15:30:50 volumio3-lr nmbd[544]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Apr 21 15:30:50 volumio3-lr nmbd[544]: [2021/04/21 15:30:50.890844, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Apr 21 15:30:50 volumio3-lr nmbd[544]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Apr 21 15:30:50 volumio3-lr systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 21 15:30:50 volumio3-lr systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 21 15:30:50 volumio3-lr ntpd[553]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Apr 21 15:30:50 volumio3-lr sshd[575]: Server listening on 0.0.0.0 port 22. Apr 21 15:30:50 volumio3-lr sshd[575]: Server listening on :: port 22. Apr 21 15:30:50 volumio3-lr systemd[1]: Started OpenBSD Secure Shell server. Apr 21 15:30:51 volumio3-lr systemd[1]: Reloading. Apr 21 15:30:51 volumio3-lr systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Apr 21 15:30:51 volumio3-lr systemd[1]: Reloading. Apr 21 15:30:51 volumio3-lr ntpd[553]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Apr 21 15:30:52 volumio3-lr systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Apr 21 15:30:52 volumio3-lr wireless.js[422]: WIRELESS DAEMON: start Apr 21 15:30:52 volumio3-lr wireless.js[422]: WIRELESS: Loaded configuration Apr 21 15:30:52 volumio3-lr wireless.js[422]: Cleaning previous... Apr 21 15:30:52 volumio3-lr systemd[1]: systemd-rfkill.service: Succeeded. Apr 21 15:30:52 volumio3-lr systemd[1]: volumiossh.service: Succeeded. Apr 21 15:30:52 volumio3-lr systemd[1]: Started Volumio SSH enabler. Apr 21 15:30:52 volumio3-lr sudo[619]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 21 15:30:52 volumio3-lr sudo[619]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:30:52 volumio3-lr sudo[619]: pam_unix(sudo:session): session closed for user root Apr 21 15:30:52 volumio3-lr sudo[621]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 21 15:30:52 volumio3-lr sudo[621]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:30:52 volumio3-lr ntpd[553]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Apr 21 15:30:52 volumio3-lr mpd[554]: Apr 21 15:30 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 21 15:30:53 volumio3-lr mpd[554]: Apr 21 15:30 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Apr 21 15:30:53 volumio3-lr mpd[554]: Apr 21 15:30 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Apr 21 15:30:53 volumio3-lr sudo[621]: pam_unix(sudo:session): session closed for user root Apr 21 15:30:53 volumio3-lr systemd[1]: Started Music Player Daemon. Apr 21 15:30:53 volumio3-lr wireless.js[422]: Stopped aP Apr 21 15:30:53 volumio3-lr wireless.js[422]: Start wireless flow Apr 21 15:30:53 volumio3-lr wireless.js[422]: Stopped hotspot (if there).. Apr 21 15:30:53 volumio3-lr sudo[630]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 21 15:30:53 volumio3-lr sudo[630]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:30:53 volumio3-lr sudo[630]: pam_unix(sudo:session): session closed for user root Apr 21 15:30:53 volumio3-lr sudo[632]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 21 15:30:53 volumio3-lr sudo[632]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:30:53 volumio3-lr sudo[632]: pam_unix(sudo:session): session closed for user root Apr 21 15:30:53 volumio3-lr wireless.js[422]: DHCP IP Apr 21 15:30:53 volumio3-lr wireless.js[422]: Start ap Apr 21 15:30:53 volumio3-lr wpa_supplicant[634]: Successfully initialized wpa_supplicant Apr 21 15:30:53 volumio3-lr sudo[635]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Apr 21 15:30:53 volumio3-lr sudo[635]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:30:53 volumio3-lr kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 21 15:30:53 volumio3-lr dhcpcd[636]: dev: loaded udev Apr 21 15:30:53 volumio3-lr kernel: 8021q: 802.1Q VLAN Support v1.8 Apr 21 15:30:53 volumio3-lr dhcpcd-run-hooks[645]: wlan0: starting wpa_supplicant Apr 21 15:30:53 volumio3-lr ntpd[553]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Apr 21 15:30:53 volumio3-lr dhcpcd-run-hooks[650]: wlan0: failed to start wpa_supplicant Apr 21 15:30:53 volumio3-lr dhcpcd-run-hooks[651]: wlan0: Successfully initialized wpa_supplicant ctrl_iface exists and seems to be in use - cannot override it Delete '/var/run/wpa_supplicant/wlan0' manually if it is not used anymore Failed to initialize control interface '/var/run/wpa_supplicant'. You may have another wpa_supplicant process already running or the file was left by an unclean termination of wpa_supplicant in which case you will need to manually remove this file before starting wpa_supplicant again. nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Apr 21 15:30:53 volumio3-lr dhcpcd[636]: wlan0: connected to Access Point `' Apr 21 15:30:54 volumio3-lr dhcpcd[636]: no interfaces have a carrier Apr 21 15:30:54 volumio3-lr dhcpcd[636]: forked to background, child pid 665 Apr 21 15:30:54 volumio3-lr dhcpcd[665]: wlan0: waiting for carrier Apr 21 15:30:54 volumio3-lr sudo[635]: pam_unix(sudo:session): session closed for user root Apr 21 15:30:54 volumio3-lr wireless.js[422]: trying... Apr 21 15:30:54 volumio3-lr sudo[667]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 21 15:30:54 volumio3-lr sudo[667]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:30:54 volumio3-lr sudo[667]: pam_unix(sudo:session): session closed for user root Apr 21 15:30:54 volumio3-lr volumio-remote-updater[411]: [2021-04-21 15:30:54] [info] asio async_connect error: system:111 (Connection refused) Apr 21 15:30:54 volumio3-lr volumio-remote-updater[411]: [2021-04-21 15:30:54] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 21 15:30:54 volumio3-lr volumio-remote-updater[411]: [2021-04-21 15:30:54] [error] handle_connect error: Underlying Transport Error Apr 21 15:30:55 volumio3-lr kernel: Bluetooth: Core ver 2.22 Apr 21 15:30:55 volumio3-lr kernel: NET: Registered protocol family 31 Apr 21 15:30:55 volumio3-lr kernel: Bluetooth: HCI device and connection manager initialized Apr 21 15:30:55 volumio3-lr kernel: Bluetooth: HCI socket layer initialized Apr 21 15:30:55 volumio3-lr kernel: Bluetooth: L2CAP socket layer initialized Apr 21 15:30:55 volumio3-lr kernel: Bluetooth: SCO socket layer initialized Apr 21 15:30:55 volumio3-lr kernel: Bluetooth: HCI UART driver ver 2.3 Apr 21 15:30:55 volumio3-lr kernel: Bluetooth: HCI UART protocol H4 registered Apr 21 15:30:55 volumio3-lr kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Apr 21 15:30:55 volumio3-lr kernel: Bluetooth: HCI UART protocol Broadcom registered Apr 21 15:30:55 volumio3-lr btuart[400]: bcm43xx_init Apr 21 15:30:55 volumio3-lr btuart[400]: Flash firmware /lib/firmware/brcm/BCM4345C0.hcd Apr 21 15:30:55 volumio3-lr btuart[400]: Set BDADDR UART: b8:27:eb:02:b6:2e Apr 21 15:30:55 volumio3-lr btuart[400]: Set Controller UART speed to 460800 bit/s Apr 21 15:30:55 volumio3-lr btuart[400]: Device setup complete Apr 21 15:30:55 volumio3-lr systemd[1]: Starting Load/Save RF Kill Switch Status... Apr 21 15:30:55 volumio3-lr systemd[1]: Started Configure Bluetooth Modems connected by UART. Apr 21 15:30:55 volumio3-lr systemd-udevd[681]: Process '/usr/bin/hciconfig hci0 up' failed with exit code 1. Apr 21 15:30:55 volumio3-lr systemd[1]: Started Load/Save RF Kill Switch Status. Apr 21 15:30:55 volumio3-lr systemd[1]: Created slice system-bthelper.slice. Apr 21 15:30:55 volumio3-lr systemd[1]: Starting Bluetooth service... Apr 21 15:30:55 volumio3-lr bluetoothd[683]: Bluetooth daemon 5.50 Apr 21 15:30:55 volumio3-lr bluetoothd[683]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Apr 21 15:30:55 volumio3-lr systemd[1]: Started Bluetooth service. Apr 21 15:30:55 volumio3-lr bluetoothd[683]: Starting SDP server Apr 21 15:30:55 volumio3-lr bluetoothd[683]: Excluding (cli) sap Apr 21 15:30:55 volumio3-lr systemd[1]: Started Raspberry Pi bluetooth helper. Apr 21 15:30:55 volumio3-lr systemd[1]: Reached target Bluetooth. Apr 21 15:30:55 volumio3-lr wireless.js[422]: trying... Apr 21 15:30:55 volumio3-lr bluetoothd[683]: Bluetooth management interface 1.14 initialized Apr 21 15:30:55 volumio3-lr kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Apr 21 15:30:55 volumio3-lr kernel: Bluetooth: BNEP filters: protocol multicast Apr 21 15:30:55 volumio3-lr kernel: Bluetooth: BNEP socket layer initialized Apr 21 15:30:55 volumio3-lr bthelper[684]: Raspberry Pi BDADDR already set Apr 21 15:30:55 volumio3-lr dbus-daemon[387]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=683 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Apr 21 15:30:55 volumio3-lr sudo[693]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 21 15:30:55 volumio3-lr sudo[693]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:30:55 volumio3-lr sudo[693]: pam_unix(sudo:session): session closed for user root Apr 21 15:30:55 volumio3-lr systemd[1]: Starting Hostname Service... Apr 21 15:30:55 volumio3-lr bluetoothd[683]: Failed to set privacy: Rejected (0x0b) Apr 21 15:30:55 volumio3-lr bthelper[684]: [CHG] Controller B8:27:EB:02:B6:2E UUIDs: 00001801-0000-1000-8000-00805f9b34fb Apr 21 15:30:55 volumio3-lr bthelper[684]: [CHG] Controller B8:27:EB:02:B6:2E UUIDs: 0000110e-0000-1000-8000-00805f9b34fb Apr 21 15:30:55 volumio3-lr bthelper[684]: [CHG] Controller B8:27:EB:02:B6:2E UUIDs: 00001200-0000-1000-8000-00805f9b34fb Apr 21 15:30:55 volumio3-lr bthelper[684]: [CHG] Controller B8:27:EB:02:B6:2E UUIDs: 0000110c-0000-1000-8000-00805f9b34fb Apr 21 15:30:55 volumio3-lr bthelper[684]: [CHG] Controller B8:27:EB:02:B6:2E UUIDs: 00001800-0000-1000-8000-00805f9b34fb Apr 21 15:30:55 volumio3-lr bthelper[684]: [CHG] Controller B8:27:EB:02:B6:2E Class: 0x0000041c Apr 21 15:30:55 volumio3-lr bthelper[684]: [CHG] Controller B8:27:EB:02:B6:2E Alias: Volumio Apr 21 15:30:55 volumio3-lr bthelper[684]: [CHG] Controller B8:27:EB:02:B6:2E Pairable: yes Apr 21 15:30:55 volumio3-lr bthelper[684]: Changing power off succeeded Apr 21 15:30:55 volumio3-lr dbus-daemon[387]: [system] Successfully activated service 'org.freedesktop.hostname1' Apr 21 15:30:55 volumio3-lr systemd[1]: Started Hostname Service. Apr 21 15:30:55 volumio3-lr bthelper[684]: [CHG] Controller B8:27:EB:02:B6:2E Name: volumio3-lr Apr 21 15:30:55 volumio3-lr bthelper[684]: [CHG] Controller B8:27:EB:02:B6:2E Alias: Volumio Apr 21 15:30:55 volumio3-lr bthelper[684]: [CHG] Controller B8:27:EB:02:B6:2E Class: 0x0000041c Apr 21 15:30:55 volumio3-lr bthelper[684]: Changing power on succeeded Apr 21 15:30:55 volumio3-lr systemd[1]: bthelper@hci0.service: Succeeded. Apr 21 15:30:56 volumio3-lr wireless.js[422]: trying... Apr 21 15:30:56 volumio3-lr sudo[705]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 21 15:30:56 volumio3-lr sudo[705]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:30:56 volumio3-lr sudo[705]: pam_unix(sudo:session): session closed for user root Apr 21 15:30:56 volumio3-lr wpa_supplicant[649]: wlan0: Trying to associate with SSID 'Mozart' Apr 21 15:30:57 volumio3-lr wireless.js[422]: trying... Apr 21 15:30:57 volumio3-lr sudo[708]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 21 15:30:57 volumio3-lr sudo[708]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:30:57 volumio3-lr sudo[708]: pam_unix(sudo:session): session closed for user root Apr 21 15:30:58 volumio3-lr wireless.js[422]: trying... Apr 21 15:30:58 volumio3-lr sudo[711]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 21 15:30:58 volumio3-lr sudo[711]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:30:58 volumio3-lr sudo[711]: pam_unix(sudo:session): session closed for user root Apr 21 15:30:59 volumio3-lr dhcpcd[665]: wlan0: carrier acquired Apr 21 15:30:59 volumio3-lr dhcpcd[665]: wlan0: connected to Access Point `Mozart' Apr 21 15:30:59 volumio3-lr wpa_supplicant[649]: wlan0: Associated with 68:ff:7b:32:23:e2 Apr 21 15:30:59 volumio3-lr wpa_supplicant[649]: wlan0: CTRL-EVENT-CONNECTED - Connection to 68:ff:7b:32:23:e2 completed [id=0 id_str=] Apr 21 15:30:59 volumio3-lr wpa_supplicant[649]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Apr 21 15:30:59 volumio3-lr wpa_supplicant[649]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=CA Apr 21 15:30:59 volumio3-lr dhcpcd[665]: DUID 00:01:00:01:28:0b:2d:a4:b8:27:eb:fd:49:d1 Apr 21 15:30:59 volumio3-lr dhcpcd[665]: wlan0: IAID eb:fd:49:d1 Apr 21 15:30:59 volumio3-lr dhcpcd[665]: wlan0: adding address fe80::b74b:1079:9ddb:92a0 Apr 21 15:30:59 volumio3-lr dhcpcd[665]: ipv6_addaddr1: Permission denied Apr 21 15:30:59 volumio3-lr dhcpcd[665]: wlan0: carrier lost Apr 21 15:30:59 volumio3-lr wireless.js[422]: trying... Apr 21 15:30:59 volumio3-lr dhcpcd[665]: wlan0: carrier acquired Apr 21 15:30:59 volumio3-lr sudo[725]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 21 15:30:59 volumio3-lr sudo[725]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:30:59 volumio3-lr dhcpcd[665]: wlan0: IAID eb:fd:49:d1 Apr 21 15:30:59 volumio3-lr sudo[725]: pam_unix(sudo:session): session closed for user root Apr 21 15:30:59 volumio3-lr dhcpcd[665]: wlan0: soliciting an IPv6 router Apr 21 15:30:59 volumio3-lr dhcpcd[665]: wlan0: soliciting a DHCP lease Apr 21 15:31:00 volumio3-lr dhcpcd[665]: wlan0: offered 192.168.0.125 from 192.168.0.1 Apr 21 15:31:00 volumio3-lr dhcpcd[665]: wlan0: probing address 192.168.0.125/24 Apr 21 15:31:00 volumio3-lr systemd[1]: systemd-rfkill.service: Succeeded. Apr 21 15:31:00 volumio3-lr wireless.js[422]: trying... Apr 21 15:31:00 volumio3-lr sudo[729]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 21 15:31:00 volumio3-lr sudo[729]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:00 volumio3-lr sudo[729]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:01 volumio3-lr wireless.js[422]: trying... Apr 21 15:31:01 volumio3-lr sudo[732]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 21 15:31:01 volumio3-lr sudo[732]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:01 volumio3-lr sudo[732]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:02 volumio3-lr volumio-remote-updater[411]: [2021-04-21 15:31:02] [info] asio async_connect error: system:111 (Connection refused) Apr 21 15:31:02 volumio3-lr volumio-remote-updater[411]: [2021-04-21 15:31:02] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 21 15:31:02 volumio3-lr volumio-remote-updater[411]: [2021-04-21 15:31:02] [error] handle_connect error: Underlying Transport Error Apr 21 15:31:02 volumio3-lr wireless.js[422]: trying... Apr 21 15:31:02 volumio3-lr sudo[735]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 21 15:31:02 volumio3-lr sudo[735]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:02 volumio3-lr sudo[735]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:03 volumio3-lr wireless.js[422]: trying... Apr 21 15:31:03 volumio3-lr sudo[738]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 21 15:31:03 volumio3-lr sudo[738]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:03 volumio3-lr sudo[738]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:03 volumio3-lr wpa_supplicant[649]: RRM: Ignoring radio measurement request: Not RRM network Apr 21 15:31:04 volumio3-lr dhcpcd[665]: wlan0: carrier lost Apr 21 15:31:04 volumio3-lr wpa_supplicant[649]: wlan0: Associated with 68:ff:7b:32:23:e3 Apr 21 15:31:04 volumio3-lr wpa_supplicant[649]: wlan0: CTRL-EVENT-CONNECTED - Connection to 68:ff:7b:32:23:e3 completed [id=0 id_str=] Apr 21 15:31:04 volumio3-lr wpa_supplicant[649]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Apr 21 15:31:04 volumio3-lr dhcpcd[665]: wlan0: carrier acquired Apr 21 15:31:04 volumio3-lr dhcpcd[665]: wlan0: IAID eb:fd:49:d1 Apr 21 15:31:04 volumio3-lr wireless.js[422]: trying... Apr 21 15:31:04 volumio3-lr sudo[761]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 21 15:31:04 volumio3-lr sudo[761]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:04 volumio3-lr sudo[761]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:04 volumio3-lr dhcpcd[665]: wlan0: soliciting a DHCP lease Apr 21 15:31:04 volumio3-lr dhcpcd[665]: wlan0: offered 192.168.0.125 from 192.168.0.1 Apr 21 15:31:04 volumio3-lr dhcpcd[665]: wlan0: probing address 192.168.0.125/24 Apr 21 15:31:05 volumio3-lr dhcpcd[665]: wlan0: soliciting an IPv6 router Apr 21 15:31:05 volumio3-lr wireless.js[422]: trying... Apr 21 15:31:05 volumio3-lr sudo[764]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 21 15:31:05 volumio3-lr sudo[764]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:05 volumio3-lr sudo[764]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:06 volumio3-lr wireless.js[422]: trying... Apr 21 15:31:06 volumio3-lr sudo[767]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 21 15:31:06 volumio3-lr sudo[767]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:06 volumio3-lr sudo[767]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:07 volumio3-lr wireless.js[422]: trying... Apr 21 15:31:07 volumio3-lr sudo[770]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 21 15:31:07 volumio3-lr sudo[770]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:07 volumio3-lr sudo[770]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:08 volumio3-lr wireless.js[422]: trying... Apr 21 15:31:08 volumio3-lr sudo[773]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 21 15:31:08 volumio3-lr sudo[773]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:08 volumio3-lr sudo[773]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:09 volumio3-lr wireless.js[422]: trying... Apr 21 15:31:09 volumio3-lr sudo[776]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 21 15:31:09 volumio3-lr sudo[776]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:09 volumio3-lr sudo[776]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:10 volumio3-lr dhcpcd[665]: wlan0: leased 192.168.0.125 for 7200 seconds Apr 21 15:31:10 volumio3-lr avahi-daemon[423]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.125. Apr 21 15:31:10 volumio3-lr dhcpcd[665]: wlan0: adding route to 192.168.0.0/24 Apr 21 15:31:10 volumio3-lr dhcpcd[665]: wlan0: adding default route via 192.168.0.1 Apr 21 15:31:10 volumio3-lr avahi-daemon[423]: New relevant interface wlan0.IPv4 for mDNS. Apr 21 15:31:10 volumio3-lr avahi-daemon[423]: Registering new address record for 192.168.0.125 on wlan0.IPv4. Apr 21 15:31:10 volumio3-lr wireless.js[422]: trying... Apr 21 15:31:10 volumio3-lr sudo[800]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 21 15:31:10 volumio3-lr sudo[800]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:10 volumio3-lr sudo[800]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:10 volumio3-lr wireless.js[422]: Connected to: ----Mozart Apr 21 15:31:10 volumio3-lr wireless.js[422]: ---- Apr 21 15:31:10 volumio3-lr sudo[803]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 21 15:31:10 volumio3-lr sudo[803]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:10 volumio3-lr sudo[803]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:10 volumio3-lr wireless.js[422]: ... joined AP, wlan0 IPv4 is 192.168.0.125, ipV6 is undefined Apr 21 15:31:10 volumio3-lr wireless.js[422]: It's done! AP Apr 21 15:31:10 volumio3-lr systemd[1]: Started Wireless Services. Apr 21 15:31:10 volumio3-lr systemd[1]: Started Volumio Backend Module. Apr 21 15:31:10 volumio3-lr systemd[1]: Started Volumio Streaming Daemon. Apr 21 15:31:10 volumio3-lr volumio-streaming-daemon[808]: ############################ Apr 21 15:31:10 volumio3-lr volumio-streaming-daemon[808]: # Volumio Streaming Daemon # Apr 21 15:31:10 volumio3-lr volumio-streaming-daemon[808]: # Running on port 7777 # Apr 21 15:31:10 volumio3-lr volumio-streaming-daemon[808]: ############################ Apr 21 15:31:10 volumio3-lr volumio-streaming-daemon[808]: Environment: production Apr 21 15:31:10 volumio3-lr nmbd[544]: [2021/04/21 15:31:10.898540, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 21 15:31:10 volumio3-lr nmbd[544]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Apr 21 15:31:10 volumio3-lr systemd[1]: Started Samba NMB Daemon. Apr 21 15:31:10 volumio3-lr systemd[1]: Starting Samba Winbind Daemon... Apr 21 15:31:11 volumio3-lr nmbd[544]: [2021/04/21 15:31:11.016410, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Apr 21 15:31:11 volumio3-lr nmbd[544]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.0.125 for name WORKGROUP<1d>. Apr 21 15:31:11 volumio3-lr nmbd[544]: This response was from IP 192.168.0.120, reporting an IP address of 192.168.0.120. Apr 21 15:31:11 volumio3-lr winbindd[820]: [2021/04/21 15:31:11.238569, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Apr 21 15:31:11 volumio3-lr winbindd[820]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Apr 21 15:31:11 volumio3-lr systemd[1]: Started Samba Winbind Daemon. Apr 21 15:31:11 volumio3-lr winbindd[820]: [2021/04/21 15:31:11.286091, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 21 15:31:11 volumio3-lr winbindd[820]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Apr 21 15:31:11 volumio3-lr systemd[1]: Starting Samba SMB Daemon... Apr 21 15:31:11 volumio3-lr smbd[825]: [2021/04/21 15:31:11.894716, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 21 15:31:11 volumio3-lr systemd[1]: Started Samba SMB Daemon. Apr 21 15:31:11 volumio3-lr systemd[1]: Reached target Multi-User System. Apr 21 15:31:11 volumio3-lr systemd[1]: Reached target Graphical Interface. Apr 21 15:31:11 volumio3-lr smbd[825]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Apr 21 15:31:11 volumio3-lr systemd[1]: Starting Update UTMP about System Runlevel Changes... Apr 21 15:31:11 volumio3-lr ntpd[553]: Listen normally on 3 wlan0 192.168.0.125:123 Apr 21 15:31:11 volumio3-lr ntpd[553]: new interface(s) found: waking up resolver Apr 21 15:31:11 volumio3-lr systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Apr 21 15:31:11 volumio3-lr systemd[1]: Started Update UTMP about System Runlevel Changes. Apr 21 15:31:11 volumio3-lr systemd[1]: Startup finished in 14.007s (kernel) + 29.939s (userspace) = 43.947s. Apr 21 15:31:12 volumio3-lr volumio-remote-updater[411]: [2021-04-21 15:31:12] [info] asio async_connect error: system:111 (Connection refused) Apr 21 15:31:12 volumio3-lr volumio-remote-updater[411]: [2021-04-21 15:31:12] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 21 15:31:12 volumio3-lr volumio-remote-updater[411]: [2021-04-21 15:31:12] [error] handle_connect error: Underlying Transport Error Apr 21 15:31:13 volumio3-lr volumio[807]: info: ------------------------------------------- Apr 21 15:31:13 volumio3-lr volumio[807]: info: ----- Volumio2 ---- Apr 21 15:31:13 volumio3-lr volumio[807]: info: ------------------------------------------- Apr 21 15:31:13 volumio3-lr volumio[807]: info: ----- System startup ---- Apr 21 15:31:13 volumio3-lr volumio[807]: info: ------------------------------------------- Apr 21 15:31:14 volumio3-lr volumio[807]: info: MYVOLUMIO Environment detected Apr 21 15:31:14 volumio3-lr volumio[807]: info: Plugin folders cleanup Apr 21 15:31:14 volumio3-lr volumio[807]: info: Scanning into folder /volumio/app/plugins/ Apr 21 15:31:14 volumio3-lr volumio[807]: info: Scanning category audio_interface Apr 21 15:31:14 volumio3-lr volumio[807]: info: Scanning category miscellanea Apr 21 15:31:14 volumio3-lr volumio[807]: info: Scanning category music_service Apr 21 15:31:14 volumio3-lr volumio[807]: info: Scanning category plugins.json Apr 21 15:31:14 volumio3-lr volumio[807]: info: Scanning category system_controller Apr 21 15:31:14 volumio3-lr volumio[807]: info: Scanning category user_interface Apr 21 15:31:14 volumio3-lr volumio[807]: info: Scanning into folder /data/plugins/ Apr 21 15:31:14 volumio3-lr volumio[807]: info: Plugin folders cleanup completed Apr 21 15:31:14 volumio3-lr volumio[807]: info: ------------------------------------------- Apr 21 15:31:14 volumio3-lr volumio[807]: info: ----- Core plugins startup ---- Apr 21 15:31:14 volumio3-lr volumio[807]: info: ------------------------------------------- Apr 21 15:31:14 volumio3-lr volumio[807]: info: Loading plugins from folder /volumio/app/plugins/ Apr 21 15:31:14 volumio3-lr volumio[807]: info: Adding plugin upnp to MyMusic Plugins Apr 21 15:31:14 volumio3-lr volumio[807]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 21 15:31:14 volumio3-lr volumio[807]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 21 15:31:14 volumio3-lr volumio[807]: info: Loading plugins from folder /data/plugins/ Apr 21 15:31:14 volumio3-lr volumio[807]: info: Loading plugin "system"... Apr 21 15:31:14 volumio3-lr volumio[807]: Error: ENOENT: no such file or directory, open '/sys/class/net/eth0/address' Apr 21 15:31:14 volumio3-lr volumio[807]: at Object.openSync (fs.js:476:3) Apr 21 15:31:14 volumio3-lr volumio[807]: at Object.readFileSync (fs.js:377:35) Apr 21 15:31:14 volumio3-lr volumio[807]: at ControllerSystem.callHome (/volumio/app/plugins/system_controller/system/index.js:577:22) Apr 21 15:31:14 volumio3-lr volumio[807]: at ControllerSystem.onVolumioStart (/volumio/app/plugins/system_controller/system/index.js:49:45) Apr 21 15:31:14 volumio3-lr volumio[807]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:245:38) Apr 21 15:31:14 volumio3-lr volumio[807]: at /volumio/app/pluginmanager.js:328:34 Apr 21 15:31:14 volumio3-lr volumio[807]: at Array.forEach () Apr 21 15:31:14 volumio3-lr volumio[807]: at HashMap. (/volumio/app/pluginmanager.js:327:20) Apr 21 15:31:14 volumio3-lr volumio[807]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Apr 21 15:31:14 volumio3-lr volumio[807]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) { Apr 21 15:31:14 volumio3-lr volumio[807]: errno: -2, Apr 21 15:31:14 volumio3-lr volumio[807]: syscall: 'open', Apr 21 15:31:14 volumio3-lr volumio[807]: code: 'ENOENT', Apr 21 15:31:14 volumio3-lr volumio[807]: path: '/sys/class/net/eth0/address' Apr 21 15:31:14 volumio3-lr volumio[807]: } Apr 21 15:31:14 volumio3-lr volumio[807]: info: Loading plugin "appearance"... Apr 21 15:31:16 volumio3-lr volumio[807]: info: Loading plugin "network"... Apr 21 15:31:16 volumio3-lr volumio[807]: info: Refreshing Cached IP Addresses Apr 21 15:31:16 volumio3-lr volumio[807]: info: Loading plugin "services"... Apr 21 15:31:16 volumio3-lr volumio[807]: info: Loading plugin "alsa_controller"... Apr 21 15:31:16 volumio3-lr sudo[845]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 21 15:31:16 volumio3-lr sudo[845]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:16 volumio3-lr sudo[847]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 21 15:31:16 volumio3-lr sudo[847]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:16 volumio3-lr sudo[847]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:16 volumio3-lr sudo[845]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:16 volumio3-lr volumio[807]: info: Loading plugin "wizard"... Apr 21 15:31:16 volumio3-lr volumio[807]: info: Loading plugin "volumio_command_line_client"... Apr 21 15:31:16 volumio3-lr volumio[807]: info: Loading plugin "upnp"... Apr 21 15:31:16 volumio3-lr volumio[807]: info: [1619019076479] Starting Upmpd Daemon Apr 21 15:31:16 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 21 15:31:16 volumio3-lr volumio[807]: info: Loading plugin "my_music"... Apr 21 15:31:16 volumio3-lr volumio[807]: info: Loading plugin "mpd"... Apr 21 15:31:16 volumio3-lr volumio[807]: info: Creating MPD Configuration file Apr 21 15:31:16 volumio3-lr volumio[807]: info: Loading plugin "upnp_browser"... Apr 21 15:31:16 volumio3-lr sudo[855]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 21 15:31:16 volumio3-lr sudo[855]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:16 volumio3-lr sudo[855]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:16 volumio3-lr sudo[857]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 21 15:31:16 volumio3-lr sudo[857]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:16 volumio3-lr systemd[1]: Stopping Music Player Daemon... Apr 21 15:31:17 volumio3-lr systemd[1]: mpd.service: Succeeded. Apr 21 15:31:17 volumio3-lr systemd[1]: Stopped Music Player Daemon. Apr 21 15:31:17 volumio3-lr systemd[1]: Starting Music Player Daemon... Apr 21 15:31:17 volumio3-lr systemd[1]: systemd-fsckd.service: Succeeded. Apr 21 15:31:17 volumio3-lr volumio[807]: info: Loading plugin "networkfs"... Apr 21 15:31:17 volumio3-lr volumio[807]: info: Starting Udev Watcher for removable devices Apr 21 15:31:17 volumio3-lr sudo[865]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.100/itunes /mnt/NAS/iTunes Apr 21 15:31:17 volumio3-lr sudo[865]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:18 volumio3-lr kernel: FS-Cache: Netfs 'cifs' registered for caching Apr 21 15:31:18 volumio3-lr kernel: Key type cifs.spnego registered Apr 21 15:31:18 volumio3-lr kernel: Key type cifs.idmap registered Apr 21 15:31:18 volumio3-lr kernel: CIFS: Attempting to mount //192.168.0.100/itunes Apr 21 15:31:18 volumio3-lr kernel: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount. Apr 21 15:31:18 volumio3-lr volumio[807]: info: Ignoring mount for partition: boot Apr 21 15:31:18 volumio3-lr volumio[807]: info: Ignoring mount for partition: volumio Apr 21 15:31:18 volumio3-lr volumio[807]: info: Ignoring mount for partition: volumio_data Apr 21 15:31:18 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 21 15:31:18 volumio3-lr volumio[807]: info: Loading plugin "alarm-clock"... Apr 21 15:31:18 volumio3-lr sudo[865]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:18 volumio3-lr volumio[807]: info: Loading plugin "airplay_emulation"... Apr 21 15:31:18 volumio3-lr volumio[807]: info: Starting Shairport Sync Apr 21 15:31:18 volumio3-lr volumio[807]: info: Loading plugin "last_100"... Apr 21 15:31:18 volumio3-lr volumio[807]: info: Loading plugin "webradio"... Apr 21 15:31:18 volumio3-lr volumio[807]: info: Loading plugin "i2s_dacs"... Apr 21 15:31:18 volumio3-lr volumio[807]: info: Loading plugin "volumiodiscovery"... Apr 21 15:31:18 volumio3-lr volumio[807]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 21 15:31:18 volumio3-lr volumio[807]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 21 15:31:18 volumio3-lr volumio[807]: *** WARNING *** For more information see Apr 21 15:31:18 volumio3-lr node[807]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 21 15:31:18 volumio3-lr volumio[807]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 21 15:31:18 volumio3-lr volumio[807]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 21 15:31:18 volumio3-lr volumio[807]: *** WARNING *** For more information see Apr 21 15:31:18 volumio3-lr node[807]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 21 15:31:18 volumio3-lr node[807]: *** WARNING *** For more information see Apr 21 15:31:18 volumio3-lr node[807]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 21 15:31:18 volumio3-lr node[807]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 21 15:31:18 volumio3-lr node[807]: *** WARNING *** For more information see Apr 21 15:31:18 volumio3-lr volumio[807]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 21 15:31:18 volumio3-lr volumio[807]: info: Discovery: Started advertising with name: volumio3-lr Apr 21 15:31:18 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 21 15:31:18 volumio3-lr volumio[807]: info: Loading plugin "outputs"... Apr 21 15:31:18 volumio3-lr volumio[807]: info: Loading plugin "albumart"... Apr 21 15:31:18 volumio3-lr volumio[807]: info: Plugin example_plugin is not enabled Apr 21 15:31:18 volumio3-lr volumio[807]: info: Loading plugin "inputs"... Apr 21 15:31:18 volumio3-lr mpd[862]: Apr 21 15:31 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 21 15:31:18 volumio3-lr volumio[807]: info: Loading plugin "updater_comm"... Apr 21 15:31:18 volumio3-lr mpd[862]: Apr 21 15:31 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Apr 21 15:31:18 volumio3-lr mpd[862]: Apr 21 15:31 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Apr 21 15:31:18 volumio3-lr systemd[1]: Started Music Player Daemon. Apr 21 15:31:18 volumio3-lr sudo[857]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:19 volumio3-lr volumio[807]: info: Plugin mpdemulation is not enabled Apr 21 15:31:19 volumio3-lr volumio[807]: info: Loading plugin "rest_api"... Apr 21 15:31:19 volumio3-lr volumio[807]: info: Loading plugin "websocket"... Apr 21 15:31:19 volumio3-lr volumio[807]: info: Loading i18n strings for locale en Apr 21 15:31:19 volumio3-lr volumio[807]: Updating browse sources language Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::initPlayerControls Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: Express server listening on port 3000 Apr 21 15:31:19 volumio3-lr volumio[807]: [Metrics] WebUI: 6s 636.44ms Apr 21 15:31:19 volumio3-lr volumio[807]: Forking 3 albumart workers Apr 21 15:31:19 volumio3-lr volumio[807]: Volumio Calling Home Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreStateMachine::resetVolumioState Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreStateMachine::getcurrentVolume Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioRetrievevolume Apr 21 15:31:19 volumio3-lr volumio[807]: info: MPD Permissions set Apr 21 15:31:19 volumio3-lr volumio[807]: info: MPD running with PID862 Apr 21 15:31:19 volumio3-lr volumio[807]: ,establishing connection Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:31:19 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreStateMachine::updateTrackBlock Apr 21 15:31:19 volumio3-lr volumio[807]: info: CorePlayQueue::getTrackBlock Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioRetrievevolume Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 15:31:19 volumio3-lr volumio[807]: info: Reloading queue from file Apr 21 15:31:19 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioGetState Apr 21 15:31:19 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:31:19 volumio3-lr volumio[807]: error: updateQueue error: null Apr 21 15:31:19 volumio3-lr volumio[807]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 21 15:31:20 volumio3-lr volumio[807]: info: CoreStateMachine::setRepeat null single undefined Apr 21 15:31:20 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:31:20 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:31:20 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:31:20 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:31:20 volumio3-lr volumio[807]: info: CoreStateMachine::setRandom null Apr 21 15:31:20 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:31:20 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:31:20 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:31:20 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:31:20 volumio3-lr volumio[807]: info: Setting Device type: Raspberry PI Apr 21 15:31:20 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioGetQueue Apr 21 15:31:20 volumio3-lr volumio[807]: info: CoreStateMachine::getQueue Apr 21 15:31:20 volumio3-lr volumio[807]: info: CorePlayQueue::getQueue Apr 21 15:31:20 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid Apr 21 15:31:20 volumio3-lr volumio[807]: Starting albumart workers Apr 21 15:31:20 volumio3-lr volumio[807]: Starting albumart workers Apr 21 15:31:20 volumio3-lr volumio[807]: Starting albumart workers Apr 21 15:31:20 volumio3-lr volumio[807]: info: Completed loading Core Plugins Apr 21 15:31:20 volumio3-lr volumio[807]: info: Preparing to generate the ALSA configuration file Apr 21 15:31:20 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:31:20 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:31:20 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:31:20 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:31:20 volumio3-lr volumio[807]: info: Volumio called home Apr 21 15:31:20 volumio3-lr volumio[807]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Apr 21 15:31:20 volumio3-lr volumio[807]: info: Reading ALSA contributions from plugins. Apr 21 15:31:20 volumio3-lr volumio[807]: error: updateQueue error: null Apr 21 15:31:20 volumio3-lr volumio[807]: info: Discovery: adding e40fd676-b561-4d87-acc9-95b56ff4f401 Apr 21 15:31:20 volumio3-lr volumio[807]: info: mDNS: Found device volumio3-lr Apr 21 15:31:20 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioGetState Apr 21 15:31:20 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:31:20 volumio3-lr volumio[807]: info: Discovery: adding 3233fb98-3584-4883-ae1e-8fc3657d7f9f Apr 21 15:31:20 volumio3-lr volumio[807]: info: mDNS: Found device kitchen-Volumio Apr 21 15:31:20 volumio3-lr volumio[807]: info: Asound.conf file unchanged, so no further update is needed Apr 21 15:31:20 volumio3-lr volumio[807]: info: Output device has changed, restarting MPD Apr 21 15:31:20 volumio3-lr volumio[807]: info: Output device has changed, restarting Shairport Sync Apr 21 15:31:21 volumio3-lr sudo[971]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 21 15:31:21 volumio3-lr sudo[971]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:21 volumio3-lr sudo[976]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 21 15:31:21 volumio3-lr sudo[976]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:21 volumio3-lr sudo[971]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:21 volumio3-lr systemd[1]: Stopping Music Player Daemon... Apr 21 15:31:21 volumio3-lr volumio[807]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 21 15:31:21 volumio3-lr volumio[807]: info: ___________ START PLUGINS ___________ Apr 21 15:31:21 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 21 15:31:21 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 21 15:31:21 volumio3-lr volumio[807]: info: [1619019081056] CoreMusicLibrary::Adding element Media Servers Apr 21 15:31:21 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 21 15:31:21 volumio3-lr volumio[807]: Cannot find translation for sourceMedia Servers Apr 21 15:31:21 volumio3-lr volumio[807]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 21 15:31:21 volumio3-lr volumio[807]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 21 15:31:21 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 21 15:31:21 volumio3-lr volumio[807]: info: [1619019081186] CoreMusicLibrary::Adding element Last_100 Apr 21 15:31:21 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 21 15:31:21 volumio3-lr volumio[807]: Cannot find translation for sourceMedia Servers Apr 21 15:31:21 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 21 15:31:21 volumio3-lr volumio[807]: info: [1619019081191] CoreMusicLibrary::Adding element Webradio Apr 21 15:31:21 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 21 15:31:21 volumio3-lr volumio[807]: Cannot find translation for sourceMedia Servers Apr 21 15:31:21 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 21 15:31:21 volumio3-lr volumio[807]: info: Completed starting Core Plugins Apr 21 15:31:21 volumio3-lr volumio[807]: info: ------------------------------------------- Apr 21 15:31:21 volumio3-lr volumio[807]: info: ----- MyVolumio plugins startup ---- Apr 21 15:31:21 volumio3-lr volumio[807]: info: ------------------------------------------- Apr 21 15:31:21 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 21 15:31:21 volumio3-lr systemd[1]: mpd.service: Succeeded. Apr 21 15:31:21 volumio3-lr systemd[1]: Stopped Music Player Daemon. Apr 21 15:31:21 volumio3-lr systemd[1]: Starting Music Player Daemon... Apr 21 15:31:21 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioGetState Apr 21 15:31:21 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:31:21 volumio3-lr volumio[807]: info: MPD Permissions set Apr 21 15:31:21 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:21 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 15:31:21 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 15:31:21 volumio3-lr volumio[807]: info: Starting Shairport Sync Apr 21 15:31:21 volumio3-lr volumio[807]: info: Starting Shairport Sync Apr 21 15:31:21 volumio3-lr volumio[807]: info: Starting Shairport Sync Apr 21 15:31:21 volumio3-lr sudo[1004]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 21 15:31:21 volumio3-lr sudo[1004]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:21 volumio3-lr sudo[1006]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 21 15:31:21 volumio3-lr sudo[1006]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:21 volumio3-lr systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 21 15:31:21 volumio3-lr systemd[1]: shairport-sync.service: Succeeded. Apr 21 15:31:21 volumio3-lr systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 21 15:31:21 volumio3-lr systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 21 15:31:21 volumio3-lr sudo[1004]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:21 volumio3-lr systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 21 15:31:21 volumio3-lr systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Apr 21 15:31:21 volumio3-lr systemd[1]: shairport-sync.service: Succeeded. Apr 21 15:31:21 volumio3-lr systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 21 15:31:21 volumio3-lr sudo[1010]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 21 15:31:21 volumio3-lr sudo[1010]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:21 volumio3-lr systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 21 15:31:21 volumio3-lr sudo[1006]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:21 volumio3-lr systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 21 15:31:21 volumio3-lr systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Apr 21 15:31:21 volumio3-lr systemd[1]: shairport-sync.service: Succeeded. Apr 21 15:31:21 volumio3-lr systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 21 15:31:21 volumio3-lr systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 21 15:31:21 volumio3-lr sudo[1010]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:21 volumio3-lr volumio[807]: info: Apr 21 15:31:21 volumio3-lr volumio[807]: ---------------------------- Client requests Volume 20 Apr 21 15:31:21 volumio3-lr volumio[807]: info: VolumeController::SetAlsaVolume20 Apr 21 15:31:21 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:31:21 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:31:21 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:31:21 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:31:21 volumio3-lr volumio[807]: info: Shairport-Sync Started Apr 21 15:31:21 volumio3-lr volumio[807]: Error adding Membership: Error: addMembership EINVAL Apr 21 15:31:21 volumio3-lr volumio[807]: info: Shairport-Sync Started Apr 21 15:31:21 volumio3-lr volumio[807]: info: Setting volume on startup at 20 Apr 21 15:31:21 volumio3-lr volumio[807]: info: Shairport-Sync Started Apr 21 15:31:21 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioGetState Apr 21 15:31:21 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:31:22 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioGetState Apr 21 15:31:22 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:31:22 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 21 15:31:22 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioGetVisibleSources Apr 21 15:31:22 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 21 15:31:22 volumio3-lr volumio[807]: info: Listing playlists Apr 21 15:31:22 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioGetQueue Apr 21 15:31:22 volumio3-lr volumio[807]: info: CoreStateMachine::getQueue Apr 21 15:31:22 volumio3-lr volumio[807]: info: CorePlayQueue::getQueue Apr 21 15:31:22 volumio3-lr volumio-remote-updater[411]: [2021-04-21 15:31:22] [connect] Successful connection Apr 21 15:31:22 volumio3-lr volumio-remote-updater[411]: [2021-04-21 15:31:22] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1619019082 101 Apr 21 15:31:22 volumio3-lr mpd[1002]: Apr 21 15:31 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 21 15:31:22 volumio3-lr mpd[1002]: Apr 21 15:31 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Apr 21 15:31:22 volumio3-lr mpd[1002]: Apr 21 15:31 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Apr 21 15:31:22 volumio3-lr systemd[1]: Started Music Player Daemon. Apr 21 15:31:22 volumio3-lr sudo[976]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:22 volumio3-lr volumio[807]: error: updateQueue error: null Apr 21 15:31:25 volumio3-lr systemd[1]: systemd-hostnamed.service: Succeeded. Apr 21 15:31:26 volumio3-lr sudo[1023]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 21 15:31:26 volumio3-lr sudo[1023]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:26 volumio3-lr sudo[1025]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 21 15:31:26 volumio3-lr sudo[1025]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:26 volumio3-lr sudo[1025]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:26 volumio3-lr sudo[1023]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:26 volumio3-lr sudo[1030]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 21 15:31:26 volumio3-lr sudo[1030]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:26 volumio3-lr systemd[1]: Started UPnP Renderer front-end to MPD. Apr 21 15:31:26 volumio3-lr sudo[1030]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:26 volumio3-lr volumio[807]: info: Upmpdcli Daemon Started Apr 21 15:31:26 volumio3-lr volumio[1033]: Generating RSA private key, 4096 bit long modulus (2 primes) Apr 21 15:31:29 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 21 15:31:29 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 21 15:31:29 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 21 15:31:29 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 21 15:31:29 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 21 15:31:29 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 21 15:31:29 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 21 15:31:29 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 21 15:31:29 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 21 15:31:29 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 21 15:31:29 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 21 15:31:29 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 21 15:31:29 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 21 15:31:29 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 21 15:31:29 volumio3-lr volumio[807]: info: Adding plugin bluetooth to MyMusic Plugins Apr 21 15:31:29 volumio3-lr volumio[807]: info: Adding plugin cd_controller to MyMusic Plugins Apr 21 15:31:29 volumio3-lr volumio[807]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 21 15:31:29 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 21 15:31:31 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 21 15:31:31 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 21 15:31:31 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 15:31:31 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 15:31:31 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 15:31:31 volumio3-lr volumio[807]: info: Starting MyVolumio Remote Streaming Endpoints Apr 21 15:31:31 volumio3-lr volumio[807]: info: MyVolumio not started Apr 21 15:31:31 volumio3-lr volumio[807]: info: Initializing device activation check Apr 21 15:31:31 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 15:31:31 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 21 15:31:31 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 21 15:31:31 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 21 15:31:31 volumio3-lr volumio[807]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 21 15:31:31 volumio3-lr volumio[807]: info: Streaming services startup Apr 21 15:31:31 volumio3-lr volumio[807]: info: Starting Streaming Daemon Apr 21 15:31:31 volumio3-lr sudo[1051]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 21 15:31:31 volumio3-lr sudo[1051]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:31:31 volumio3-lr systemd[1]: Stopping Volumio Streaming Daemon... Apr 21 15:31:31 volumio3-lr systemd[1]: volumio-streaming-daemon.service: Main process exited, code=killed, status=15/TERM Apr 21 15:31:31 volumio3-lr systemd[1]: volumio-streaming-daemon.service: Succeeded. Apr 21 15:31:31 volumio3-lr systemd[1]: Stopped Volumio Streaming Daemon. Apr 21 15:31:31 volumio3-lr systemd[1]: Started Volumio Streaming Daemon. Apr 21 15:31:31 volumio3-lr sudo[1051]: pam_unix(sudo:session): session closed for user root Apr 21 15:31:31 volumio3-lr volumio-streaming-daemon[1057]: ############################ Apr 21 15:31:31 volumio3-lr volumio-streaming-daemon[1057]: # Volumio Streaming Daemon # Apr 21 15:31:31 volumio3-lr volumio-streaming-daemon[1057]: # Running on port 7777 # Apr 21 15:31:31 volumio3-lr volumio-streaming-daemon[1057]: ############################ Apr 21 15:31:31 volumio3-lr volumio-streaming-daemon[1057]: Environment: production Apr 21 15:31:34 volumio3-lr volumio-streaming-daemon[1057]: Environment: production Apr 21 15:31:34 volumio3-lr volumio[807]: info: Fetching Streaming Services browse cache Apr 21 15:31:37 volumio3-lr volumio[1033]: ...................................................................................................................................................................++++ Apr 21 15:31:40 volumio3-lr volumio[1033]: ...............................................++++ Apr 21 15:31:40 volumio3-lr volumio[1033]: e is 65537 (0x010001) Apr 21 15:31:40 volumio3-lr volumio[1033]: writing RSA key Apr 21 15:31:51 volumio3-lr volumio[807]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Apr 21 15:31:51 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 15:31:51 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 21 15:31:51 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 15:31:51 volumio3-lr volumio[807]: error: MyVolumio Plugin failed to authenticate in a timely fashion Apr 21 15:31:51 volumio3-lr volumio[807]: info: Completed starting MyVolumio Plugin Apr 21 15:31:51 volumio3-lr volumio[807]: info: BOOT COMPLETED Apr 21 15:31:51 volumio3-lr volumio[807]: [Metrics] CommandRouter: 38s 50.20ms Apr 21 15:31:51 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 15:31:51 volumio3-lr kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 21 15:31:56 volumio3-lr volumio[807]: Playing WAVE '/volumio/app/startup.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo Apr 21 15:31:56 volumio3-lr volumio[807]: info: CoreCommandRouter::Close All Modals sent Apr 21 15:31:56 volumio3-lr volumio[807]: info: CoreCommandRouter::Close All Modals sent Apr 21 15:31:56 volumio3-lr ntpd[553]: Soliciting pool server 206.108.0.131 Apr 21 15:31:57 volumio3-lr ntpd[553]: Soliciting pool server 216.232.132.95 Apr 21 15:31:57 volumio3-lr ntpd[553]: Soliciting pool server 206.108.0.133 Apr 21 15:31:57 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 21 15:31:57 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 21 15:31:57 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 21 15:31:58 volumio3-lr ntpd[553]: Soliciting pool server 209.115.181.102 Apr 21 15:31:58 volumio3-lr ntpd[553]: Soliciting pool server 216.197.156.83 Apr 21 15:31:58 volumio3-lr ntpd[553]: Soliciting pool server 199.182.221.110 Apr 21 15:31:59 volumio3-lr ntpd[553]: Soliciting pool server 216.197.228.230 Apr 21 15:31:59 volumio3-lr ntpd[553]: Soliciting pool server 206.108.0.132 Apr 21 15:31:59 volumio3-lr ntpd[553]: Soliciting pool server 162.159.200.1 Apr 21 15:32:00 volumio3-lr ntpd[553]: Soliciting pool server 159.203.8.72 Apr 21 15:32:00 volumio3-lr ntpd[553]: Soliciting pool server 208.81.1.244 Apr 21 15:32:00 volumio3-lr ntpd[553]: Soliciting pool server 207.34.48.31 Apr 21 15:32:00 volumio3-lr ntpd[553]: Soliciting pool server 198.27.76.102 Apr 21 15:32:01 volumio3-lr volumio[807]: info: VolumeController::SetAlsaVolume20 Apr 21 15:32:01 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:32:01 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:32:01 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:32:01 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:32:01 volumio3-lr volumio[807]: info: Listing playlists Apr 21 15:32:01 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 21 15:32:01 volumio3-lr volumio[807]: info: CURURI: artists:// Apr 21 15:32:01 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 21 15:32:01 volumio3-lr volumio[807]: info: CURURI: albums:// Apr 21 15:32:01 volumio3-lr volumio[807]: listAlbums - loading Albums from cache Apr 21 15:32:01 volumio3-lr ntpd[553]: Soliciting pool server 206.75.147.25 Apr 21 15:32:01 volumio3-lr ntpd[553]: Soliciting pool server 2001:678:8::123 Apr 21 15:32:01 volumio3-lr ntpd[553]: Soliciting pool server 216.6.2.70 Apr 21 15:32:01 volumio3-lr ntpd[553]: Soliciting pool server 149.56.121.17 Apr 21 15:32:02 volumio3-lr ntpd[553]: Soliciting pool server 216.55.208.22 Apr 21 15:32:02 volumio3-lr ntpd[553]: Soliciting pool server 192.36.143.130 Apr 21 15:32:03 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPlay Apr 21 15:32:03 volumio3-lr volumio[807]: UNSET VOLATILE Apr 21 15:32:03 volumio3-lr volumio[807]: info: CoreStateMachine::play index 0 Apr 21 15:32:03 volumio3-lr volumio[807]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 21 15:32:03 volumio3-lr volumio[807]: info: CoreStateMachine::stop Apr 21 15:32:03 volumio3-lr volumio[807]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 21 15:32:03 volumio3-lr volumio[807]: UNSET VOLATILE Apr 21 15:32:03 volumio3-lr volumio[807]: info: CoreStateMachine::play index undefined Apr 21 15:32:03 volumio3-lr volumio[807]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 21 15:32:03 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:32:03 volumio3-lr volumio[807]: info: CoreStateMachine::startPlaybackTimer Apr 21 15:32:03 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:32:03 volumio3-lr volumio[807]: verbose: ControllerMpd::clearAddPlayTracks NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3 Apr 21 15:32:03 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand stop Apr 21 15:32:03 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand clear Apr 21 15:32:03 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand add "NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3" Apr 21 15:32:03 volumio3-lr volumio[807]: info: Apr 21 15:32:03 volumio3-lr volumio[807]: ---------------------------- MPD announces system playlist update Apr 21 15:32:03 volumio3-lr volumio[807]: info: Ignoring MPD Status Update Apr 21 15:32:03 volumio3-lr volumio[807]: info: Apr 21 15:32:03 volumio3-lr volumio[807]: ---------------------------- MPD announces system playlist update Apr 21 15:32:03 volumio3-lr volumio[807]: info: Ignoring MPD Status Update Apr 21 15:32:03 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand play Apr 21 15:32:03 volumio3-lr volumio[807]: info: ------------------------------ 7ms Apr 21 15:32:03 volumio3-lr volumio[807]: info: ------------------------------ 6ms Apr 21 15:32:03 volumio3-lr volumio[807]: info: Apr 21 15:32:03 volumio3-lr volumio[807]: ---------------------------- MPD announces state update: player Apr 21 15:32:03 volumio3-lr volumio[807]: info: ControllerMpd::getState Apr 21 15:32:03 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand status Apr 21 15:32:03 volumio3-lr kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 21 15:32:04 volumio3-lr volumio[807]: info: Apr 21 15:32:04 volumio3-lr volumio[807]: ---------------------------- MPD announces state update: player Apr 21 15:32:04 volumio3-lr volumio[807]: info: ControllerMpd::getState Apr 21 15:32:04 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand status Apr 21 15:32:04 volumio3-lr volumio[807]: verbose: ControllerMpd::parseState Apr 21 15:32:04 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 21 15:32:04 volumio3-lr volumio[807]: verbose: ControllerMpd::parseState Apr 21 15:32:04 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 21 15:32:04 volumio3-lr volumio[807]: verbose: ControllerMpd::parseTrackInfo Apr 21 15:32:04 volumio3-lr volumio[807]: info: ControllerMpd::pushState Apr 21 15:32:04 volumio3-lr volumio[807]: info: CoreCommandRouter::servicePushState Apr 21 15:32:04 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:32:04 volumio3-lr volumio[807]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":136,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Gatekeeper","artist":"Feist","album":"Let It Die","uri":"NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3","trackType":"mp3"} Apr 21 15:32:04 volumio3-lr volumio[807]: verbose: CURRENT POSITION 0 Apr 21 15:32:04 volumio3-lr volumio[807]: info: CoreStateMachine::syncState stateService play Apr 21 15:32:04 volumio3-lr volumio[807]: info: CoreStateMachine::syncState currentStatus stop Apr 21 15:32:04 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:32:04 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:32:04 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:32:04 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:32:04 volumio3-lr volumio[807]: info: ------------------------------ 121ms Apr 21 15:32:04 volumio3-lr volumio[807]: verbose: ControllerMpd::parseTrackInfo Apr 21 15:32:04 volumio3-lr volumio[807]: info: ControllerMpd::pushState Apr 21 15:32:04 volumio3-lr volumio[807]: info: CoreCommandRouter::servicePushState Apr 21 15:32:04 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:32:04 volumio3-lr volumio[807]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":136,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Gatekeeper","artist":"Feist","album":"Let It Die","uri":"NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3","trackType":"mp3"} Apr 21 15:32:04 volumio3-lr volumio[807]: verbose: CURRENT POSITION 0 Apr 21 15:32:04 volumio3-lr volumio[807]: info: CoreStateMachine::syncState stateService play Apr 21 15:32:04 volumio3-lr volumio[807]: info: CoreStateMachine::syncState currentStatus play Apr 21 15:32:04 volumio3-lr volumio[807]: info: Received an update from plugin. extracting info from payload Apr 21 15:32:04 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:32:04 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:32:04 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:32:04 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:32:04 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:32:04 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:32:04 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:32:04 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:32:04 volumio3-lr volumio[807]: info: ------------------------------ 97ms Apr 21 15:32:30 volumio3-lr ntpd[553]: receive: Unexpected origin timestamp 0xe42ac3f5.eb5225b0 does not match aorg 0000000000.00000000 from server@206.108.0.133 xmt 0xe42ac40e.74dc1bfd Apr 21 15:32:30 volumio3-lr ntpd[553]: receive: Unexpected origin timestamp 0xe42ac3f5.eb4aea78 does not match aorg 0000000000.00000000 from server@198.27.76.102 xmt 0xe42ac40e.761d9dae Apr 21 15:32:30 volumio3-lr ntpd[553]: receive: Unexpected origin timestamp 0xe42ac3f5.eb482785 does not match aorg 0000000000.00000000 from server@216.6.2.70 xmt 0xe42ac40e.75df9d0d Apr 21 15:32:30 volumio3-lr ntpd[553]: receive: Unexpected origin timestamp 0xe42ac3f5.eb46a104 does not match aorg 0000000000.00000000 from server@149.56.121.17 xmt 0xe42ac40e.75f5616e Apr 21 15:32:30 volumio3-lr ntpd[553]: receive: Unexpected origin timestamp 0xe42ac3f5.eb43c4ef does not match aorg 0000000000.00000000 from server@216.55.208.22 xmt 0xe42ac40e.7542388b Apr 21 15:32:30 volumio3-lr ntpd[553]: receive: Unexpected origin timestamp 0xe42ac3f5.eb4c9b2c does not match aorg 0000000000.00000000 from server@208.81.1.244 xmt 0xe42ac40e.77d5122b Apr 21 15:32:30 volumio3-lr ntpd[553]: receive: Unexpected origin timestamp 0xe42ac3f5.eb50c7fe does not match aorg 0000000000.00000000 from server@216.197.156.83 xmt 0xe42ac40e.795c4529 Apr 21 15:32:30 volumio3-lr ntpd[553]: receive: Unexpected origin timestamp 0xe42ac3f5.eb4991fa does not match aorg 0000000000.00000000 from server@207.34.48.31 xmt 0xe42ac40e.7ad57bfa Apr 21 15:32:30 volumio3-lr ntpd[553]: receive: Unexpected origin timestamp 0xe42ac3f5.eb4e0a88 does not match aorg 0000000000.00000000 from server@199.182.221.110 xmt 0xe42ac40e.7af3f041 Apr 21 15:32:30 volumio3-lr ntpd[553]: receive: Unexpected origin timestamp 0xe42ac3f5.eb4f6725 does not match aorg 0000000000.00000000 from server@209.115.181.102 xmt 0xe42ac40e.7aa41998 Apr 21 15:32:30 volumio3-lr ntpd[553]: receive: Unexpected origin timestamp 0xe42ac3f5.eb3c7b65 does not match aorg 0000000000.00000000 from server@192.36.143.130 xmt 0xe42ac40e.815cee8c Apr 21 15:32:48 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPause Apr 21 15:32:48 volumio3-lr volumio[807]: info: CoreStateMachine::pause Apr 21 15:32:48 volumio3-lr volumio[807]: info: CoreStateMachine::stPlaybackTimer Apr 21 15:32:48 volumio3-lr volumio[807]: info: CoreStateMachine::servicePause Apr 21 15:32:48 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:32:48 volumio3-lr volumio[807]: info: CoreCommandRouter::servicePause Apr 21 15:32:48 volumio3-lr volumio[807]: info: ControllerMpd::pause Apr 21 15:32:48 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand pause Apr 21 15:32:48 volumio3-lr volumio[807]: info: Apr 21 15:32:48 volumio3-lr volumio[807]: ---------------------------- MPD announces state update: player Apr 21 15:32:48 volumio3-lr volumio[807]: info: ControllerMpd::getState Apr 21 15:32:48 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand status Apr 21 15:32:48 volumio3-lr volumio[807]: verbose: ControllerMpd::parseState Apr 21 15:32:48 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 21 15:32:48 volumio3-lr volumio[807]: verbose: ControllerMpd::parseTrackInfo Apr 21 15:32:48 volumio3-lr volumio[807]: info: ControllerMpd::pushState Apr 21 15:32:48 volumio3-lr volumio[807]: info: CoreCommandRouter::servicePushState Apr 21 15:32:48 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:32:48 volumio3-lr volumio[807]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":20582,"duration":136,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Gatekeeper","artist":"Feist","album":"Let It Die","uri":"NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3","trackType":"mp3"} Apr 21 15:32:48 volumio3-lr volumio[807]: verbose: CURRENT POSITION 0 Apr 21 15:32:48 volumio3-lr volumio[807]: info: CoreStateMachine::syncState stateService pause Apr 21 15:32:48 volumio3-lr volumio[807]: info: CoreStateMachine::syncState currentStatus pause Apr 21 15:32:48 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:32:48 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:32:48 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:32:48 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:32:48 volumio3-lr volumio[807]: info: CoreStateMachine::stPlaybackTimer Apr 21 15:32:48 volumio3-lr volumio[807]: info: ------------------------------ 28ms Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPlay Apr 21 15:33:08 volumio3-lr volumio[807]: UNSET VOLATILE Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::play index 0 Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::stop Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 21 15:33:08 volumio3-lr volumio[807]: UNSET VOLATILE Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::updateTrackBlock Apr 21 15:33:08 volumio3-lr volumio[807]: info: CorePlayQueue::getTrackBlock Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::stPlaybackTimer Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::serviceStop Apr 21 15:33:08 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::serviceStop Apr 21 15:33:08 volumio3-lr volumio[807]: info: ControllerMpd::stop Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand stop Apr 21 15:33:08 volumio3-lr volumio[807]: info: Apr 21 15:33:08 volumio3-lr volumio[807]: ---------------------------- MPD announces state update: player Apr 21 15:33:08 volumio3-lr volumio[807]: info: ControllerMpd::getState Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand status Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::play index undefined Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 21 15:33:08 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::startPlaybackTimer Apr 21 15:33:08 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: ControllerMpd::clearAddPlayTracks NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3 Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand stop Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: ControllerMpd::parseState Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand clear Apr 21 15:33:08 volumio3-lr volumio[807]: info: Apr 21 15:33:08 volumio3-lr volumio[807]: ---------------------------- MPD announces system playlist update Apr 21 15:33:08 volumio3-lr volumio[807]: info: Ignoring MPD Status Update Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: ControllerMpd::parseTrackInfo Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand add "NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3" Apr 21 15:33:08 volumio3-lr volumio[807]: info: ControllerMpd::pushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::servicePushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:33:08 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:08 volumio3-lr volumio[807]: 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":"Gatekeeper","artist":"Feist","album":"Let It Die","uri":"NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3","trackType":"mp3"} Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: CURRENT POSITION 0 Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::syncState stateService stop Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::syncState currentStatus stop Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:33:08 volumio3-lr volumio[807]: info: No code Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:33:08 volumio3-lr volumio[807]: info: ------------------------------ 66ms Apr 21 15:33:08 volumio3-lr volumio[807]: error: updateQueue error: null Apr 21 15:33:08 volumio3-lr volumio[807]: info: Apr 21 15:33:08 volumio3-lr volumio[807]: ---------------------------- MPD announces system playlist update Apr 21 15:33:08 volumio3-lr volumio[807]: info: Ignoring MPD Status Update Apr 21 15:33:08 volumio3-lr volumio[807]: info: ------------------------------ 49ms Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand play Apr 21 15:33:08 volumio3-lr volumio[807]: info: ------------------------------ 18ms Apr 21 15:33:08 volumio3-lr volumio[807]: info: Apr 21 15:33:08 volumio3-lr volumio[807]: ---------------------------- MPD announces state update: player Apr 21 15:33:08 volumio3-lr volumio[807]: info: ControllerMpd::getState Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand status Apr 21 15:33:08 volumio3-lr kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: ControllerMpd::parseState Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 21 15:33:08 volumio3-lr volumio[807]: info: Apr 21 15:33:08 volumio3-lr volumio[807]: ---------------------------- MPD announces state update: player Apr 21 15:33:08 volumio3-lr volumio[807]: info: ControllerMpd::getState Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand status Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: ControllerMpd::parseTrackInfo Apr 21 15:33:08 volumio3-lr volumio[807]: info: ControllerMpd::pushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::servicePushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":136,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Gatekeeper","artist":"Feist","album":"Let It Die","uri":"NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3","trackType":"mp3"} Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: CURRENT POSITION 0 Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::syncState stateService play Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::syncState currentStatus stop Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:33:08 volumio3-lr volumio[807]: info: ------------------------------ 108ms Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: ControllerMpd::parseState Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: ControllerMpd::parseTrackInfo Apr 21 15:33:08 volumio3-lr volumio[807]: info: ControllerMpd::pushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::servicePushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":136,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Gatekeeper","artist":"Feist","album":"Let It Die","uri":"NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3","trackType":"mp3"} Apr 21 15:33:08 volumio3-lr volumio[807]: verbose: CURRENT POSITION 0 Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::syncState stateService play Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::syncState currentStatus play Apr 21 15:33:08 volumio3-lr volumio[807]: info: Received an update from plugin. extracting info from payload Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:33:08 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:33:08 volumio3-lr volumio[807]: info: ------------------------------ 75ms Apr 21 15:33:34 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPause Apr 21 15:33:34 volumio3-lr volumio[807]: info: CoreStateMachine::pause Apr 21 15:33:34 volumio3-lr volumio[807]: info: CoreStateMachine::stPlaybackTimer Apr 21 15:33:34 volumio3-lr volumio[807]: info: CoreStateMachine::servicePause Apr 21 15:33:34 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:34 volumio3-lr volumio[807]: info: CoreCommandRouter::servicePause Apr 21 15:33:34 volumio3-lr volumio[807]: info: ControllerMpd::pause Apr 21 15:33:34 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand pause Apr 21 15:33:34 volumio3-lr volumio[807]: info: Apr 21 15:33:34 volumio3-lr volumio[807]: ---------------------------- MPD announces state update: player Apr 21 15:33:34 volumio3-lr volumio[807]: info: ControllerMpd::getState Apr 21 15:33:34 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand status Apr 21 15:33:34 volumio3-lr volumio[807]: verbose: ControllerMpd::parseState Apr 21 15:33:34 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 21 15:33:34 volumio3-lr volumio[807]: verbose: ControllerMpd::parseTrackInfo Apr 21 15:33:34 volumio3-lr volumio[807]: info: ControllerMpd::pushState Apr 21 15:33:34 volumio3-lr volumio[807]: info: CoreCommandRouter::servicePushState Apr 21 15:33:34 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:34 volumio3-lr volumio[807]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":26582,"duration":136,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Gatekeeper","artist":"Feist","album":"Let It Die","uri":"NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3","trackType":"mp3"} Apr 21 15:33:34 volumio3-lr volumio[807]: verbose: CURRENT POSITION 0 Apr 21 15:33:34 volumio3-lr volumio[807]: info: CoreStateMachine::syncState stateService pause Apr 21 15:33:34 volumio3-lr volumio[807]: info: CoreStateMachine::syncState currentStatus pause Apr 21 15:33:34 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:33:34 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:34 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:33:34 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:33:34 volumio3-lr volumio[807]: info: CoreStateMachine::stPlaybackTimer Apr 21 15:33:34 volumio3-lr volumio[807]: info: ------------------------------ 24ms Apr 21 15:33:37 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioSeek Apr 21 15:33:37 volumio3-lr volumio[807]: info: CoreStateMachine::seek Apr 21 15:33:37 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:37 volumio3-lr volumio[807]: info: TRACKBLOCK {"uri":"mnt/NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3","service":"mpd","name":"Gatekeeper","artist":"Feist","album":"Let It Die","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=428&web=Feist/Let%20It%20Die/extralarge&path=%2FNAS%2FiTunes%2FFeist%2FLet%20It%20Die&metadata=false","duration":136,"trackType":"mp3","samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2} Apr 21 15:33:37 volumio3-lr volumio[807]: info: CoreStateMachine::startPlaybackTimer Apr 21 15:33:37 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:37 volumio3-lr volumio[807]: info: ControllerMpd::seek Apr 21 15:33:37 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:33:37 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:37 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:33:37 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:33:37 volumio3-lr volumio[807]: error: null Apr 21 15:33:37 volumio3-lr volumio[807]: info: Apr 21 15:33:37 volumio3-lr volumio[807]: ---------------------------- MPD announces state update: player Apr 21 15:33:37 volumio3-lr volumio[807]: info: ControllerMpd::getState Apr 21 15:33:37 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand status Apr 21 15:33:37 volumio3-lr volumio[807]: verbose: ControllerMpd::parseState Apr 21 15:33:37 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 21 15:33:37 volumio3-lr volumio[807]: verbose: ControllerMpd::parseTrackInfo Apr 21 15:33:37 volumio3-lr volumio[807]: info: ControllerMpd::pushState Apr 21 15:33:37 volumio3-lr volumio[807]: info: CoreCommandRouter::servicePushState Apr 21 15:33:37 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:37 volumio3-lr volumio[807]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":27000,"duration":136,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Gatekeeper","artist":"Feist","album":"Let It Die","uri":"NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3","trackType":"mp3"} Apr 21 15:33:37 volumio3-lr volumio[807]: verbose: CURRENT POSITION 0 Apr 21 15:33:37 volumio3-lr volumio[807]: info: CoreStateMachine::syncState stateService pause Apr 21 15:33:37 volumio3-lr volumio[807]: info: CoreStateMachine::syncState currentStatus pause Apr 21 15:33:37 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:33:37 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:37 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:33:37 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:33:37 volumio3-lr volumio[807]: info: CoreStateMachine::stPlaybackTimer Apr 21 15:33:37 volumio3-lr volumio[807]: info: ------------------------------ 41ms Apr 21 15:33:38 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioSeek Apr 21 15:33:38 volumio3-lr volumio[807]: info: CoreStateMachine::seek Apr 21 15:33:38 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:38 volumio3-lr volumio[807]: info: TRACKBLOCK {"uri":"mnt/NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3","service":"mpd","name":"Gatekeeper","artist":"Feist","album":"Let It Die","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=428&web=Feist/Let%20It%20Die/extralarge&path=%2FNAS%2FiTunes%2FFeist%2FLet%20It%20Die&metadata=false","duration":136,"trackType":"mp3","samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2} Apr 21 15:33:38 volumio3-lr volumio[807]: info: CoreStateMachine::startPlaybackTimer Apr 21 15:33:38 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:38 volumio3-lr volumio[807]: info: ControllerMpd::seek Apr 21 15:33:38 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:33:38 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:38 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:33:38 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:33:38 volumio3-lr volumio[807]: error: null Apr 21 15:33:38 volumio3-lr volumio[807]: info: Apr 21 15:33:38 volumio3-lr volumio[807]: ---------------------------- MPD announces state update: player Apr 21 15:33:38 volumio3-lr volumio[807]: info: ControllerMpd::getState Apr 21 15:33:38 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand status Apr 21 15:33:38 volumio3-lr volumio[807]: verbose: ControllerMpd::parseState Apr 21 15:33:38 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 21 15:33:38 volumio3-lr volumio[807]: verbose: ControllerMpd::parseTrackInfo Apr 21 15:33:38 volumio3-lr volumio[807]: info: ControllerMpd::pushState Apr 21 15:33:38 volumio3-lr volumio[807]: info: CoreCommandRouter::servicePushState Apr 21 15:33:38 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:38 volumio3-lr volumio[807]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2000,"duration":136,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Gatekeeper","artist":"Feist","album":"Let It Die","uri":"NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3","trackType":"mp3"} Apr 21 15:33:38 volumio3-lr volumio[807]: verbose: CURRENT POSITION 0 Apr 21 15:33:38 volumio3-lr volumio[807]: info: CoreStateMachine::syncState stateService pause Apr 21 15:33:38 volumio3-lr volumio[807]: info: CoreStateMachine::syncState currentStatus pause Apr 21 15:33:38 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:33:38 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:38 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:33:38 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:33:38 volumio3-lr volumio[807]: info: CoreStateMachine::stPlaybackTimer Apr 21 15:33:38 volumio3-lr volumio[807]: info: ------------------------------ 29ms Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioSeek Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreStateMachine::seek Apr 21 15:33:40 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:40 volumio3-lr volumio[807]: info: TRACKBLOCK {"uri":"mnt/NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3","service":"mpd","name":"Gatekeeper","artist":"Feist","album":"Let It Die","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=428&web=Feist/Let%20It%20Die/extralarge&path=%2FNAS%2FiTunes%2FFeist%2FLet%20It%20Die&metadata=false","duration":136,"trackType":"mp3","samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2} Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreStateMachine::startPlaybackTimer Apr 21 15:33:40 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:40 volumio3-lr volumio[807]: info: ControllerMpd::seek Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:33:40 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:33:40 volumio3-lr volumio[807]: error: null Apr 21 15:33:40 volumio3-lr volumio[807]: info: Apr 21 15:33:40 volumio3-lr volumio[807]: ---------------------------- MPD announces state update: player Apr 21 15:33:40 volumio3-lr volumio[807]: info: ControllerMpd::getState Apr 21 15:33:40 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand status Apr 21 15:33:40 volumio3-lr volumio[807]: verbose: ControllerMpd::parseState Apr 21 15:33:40 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 21 15:33:40 volumio3-lr volumio[807]: verbose: ControllerMpd::parseTrackInfo Apr 21 15:33:40 volumio3-lr volumio[807]: info: ControllerMpd::pushState Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreCommandRouter::servicePushState Apr 21 15:33:40 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:40 volumio3-lr volumio[807]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":3000,"duration":136,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Gatekeeper","artist":"Feist","album":"Let It Die","uri":"NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3","trackType":"mp3"} Apr 21 15:33:40 volumio3-lr volumio[807]: verbose: CURRENT POSITION 0 Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreStateMachine::syncState stateService pause Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreStateMachine::syncState currentStatus pause Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:33:40 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreStateMachine::stPlaybackTimer Apr 21 15:33:40 volumio3-lr volumio[807]: info: ------------------------------ 26ms Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioSeek Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreStateMachine::seek Apr 21 15:33:40 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:40 volumio3-lr volumio[807]: info: TRACKBLOCK {"uri":"mnt/NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3","service":"mpd","name":"Gatekeeper","artist":"Feist","album":"Let It Die","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=428&web=Feist/Let%20It%20Die/extralarge&path=%2FNAS%2FiTunes%2FFeist%2FLet%20It%20Die&metadata=false","duration":136,"trackType":"mp3","samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2} Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreStateMachine::startPlaybackTimer Apr 21 15:33:40 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:40 volumio3-lr volumio[807]: info: ControllerMpd::seek Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:33:40 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:33:40 volumio3-lr volumio[807]: error: null Apr 21 15:33:40 volumio3-lr volumio[807]: info: Apr 21 15:33:40 volumio3-lr volumio[807]: ---------------------------- MPD announces state update: player Apr 21 15:33:40 volumio3-lr volumio[807]: info: ControllerMpd::getState Apr 21 15:33:40 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand status Apr 21 15:33:40 volumio3-lr volumio[807]: verbose: ControllerMpd::parseState Apr 21 15:33:40 volumio3-lr volumio[807]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 21 15:33:40 volumio3-lr volumio[807]: verbose: ControllerMpd::parseTrackInfo Apr 21 15:33:40 volumio3-lr volumio[807]: info: ControllerMpd::pushState Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreCommandRouter::servicePushState Apr 21 15:33:40 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:40 volumio3-lr volumio[807]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":136,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Gatekeeper","artist":"Feist","album":"Let It Die","uri":"NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3","trackType":"mp3"} Apr 21 15:33:40 volumio3-lr volumio[807]: verbose: CURRENT POSITION 0 Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreStateMachine::syncState stateService pause Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreStateMachine::syncState currentStatus pause Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreStateMachine::pushState Apr 21 15:33:40 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioPushState Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 15:33:40 volumio3-lr volumio[807]: info: CoreStateMachine::stPlaybackTimer Apr 21 15:33:40 volumio3-lr volumio[807]: info: ------------------------------ 25ms Apr 21 15:34:22 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioGetVisibleSources Apr 21 15:34:22 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 21 15:34:22 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioGetState Apr 21 15:34:22 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:34:22 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioGetQueue Apr 21 15:34:22 volumio3-lr volumio[807]: info: CoreStateMachine::getQueue Apr 21 15:34:22 volumio3-lr volumio[807]: info: CorePlayQueue::getQueue Apr 21 15:34:22 volumio3-lr volumio[807]: info: Listing playlists Apr 21 15:34:22 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 21 15:34:22 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 21 15:34:22 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 21 15:34:22 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 21 15:34:22 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 21 15:34:23 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioGetState Apr 21 15:34:23 volumio3-lr volumio[807]: info: CorePlayQueue::getTrack 0 Apr 21 15:34:23 volumio3-lr volumio[807]: info: CoreCommandRouter::volumioGetQueue Apr 21 15:34:23 volumio3-lr volumio[807]: info: CoreStateMachine::getQueue Apr 21 15:34:23 volumio3-lr volumio[807]: info: CorePlayQueue::getQueue Apr 21 15:34:23 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid Apr 21 15:34:29 volumio3-lr volumio[807]: info: CALLMETHOD: system_controller system sendBugReport [object Object] Apr 21 15:34:29 volumio3-lr volumio[807]: info: CoreCommandRouter::executeOnPlugin: system , sendBugReport Apr 21 15:34:29 volumio3-lr sudo[1267]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig Apr 21 15:34:29 volumio3-lr sudo[1267]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 15:34:29 volumio3-lr sudo[1267]: pam_unix(sudo:session): session closed for user root Apr 21 15:34:30 volumio3-lr sudo[1278]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl -p 7 Apr 21 15:34:30 volumio3-lr sudo[1278]: pam_unix(sudo:session): session opened for user root by (uid=0) # cat /var/log/mpd.log --------------- Apr 21 15:30 : zeroconf: No global port, disabling zeroconf Apr 21 15:31 : zeroconf: No global port, disabling zeroconf Apr 21 15:31 : client: [0] opened from local Apr 21 15:31 : exception: No such directory Apr 21 15:31 : client: [1] opened from local Apr 21 15:31 : zeroconf: No global port, disabling zeroconf Apr 21 15:31 : client: [0] opened from local Apr 21 15:31 : client: [1] opened from 127.0.0.1:53918 Apr 21 15:31 : client: [2] opened from 127.0.0.1:53922 Apr 21 15:31 : exception: Failed to read mixer for 'alsa': no such mixer control: PCM Apr 21 15:32 : exception: Failed to open mixer for 'alsa': no such mixer control: PCM Apr 21 15:33 : player: played "NAS/iTunes/Feist/Let It Die/01 Gatekeeper.mp3" Apr 21 15:33 : exception: Failed to open mixer for 'alsa': no such mixer control: PCM