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