Tue Mar 2 20:25:14 UTC 2021 Description="'restart, load Tidal playlist, listen two songs, skip to third, everything stops working'" # cat /proc/version --------------- Linux version 4.19.118-v7+ (dom@buildbot) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1311 SMP Mon Apr 27 14:21:24 BST 2020 # cat /etc/os-release --------------- PRETTY_NAME="Raspbian GNU/Linux 8 (jessie)" NAME="Raspbian GNU/Linux" VERSION_ID="8" VERSION="8 (jessie)" 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="e81b2037a65d8f554cb0c857a1007d659ad7f838" VOLUMIO_FE_VERSION="e489037accd8e0b2dcbd6e0b054400d8cd36d4e2" VOLUMIO_BE_VERSION="25875b197c75cd1ac7eb5664d94cdd19afb06985" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Feb 19 17:39:10 CET 2021" VOLUMIO_VERSION="2.873" VOLUMIO_HARDWARE="pi" VOLUMIO_HASH="781d4c9fbf86d562939968306a6a26f4" # ifconfig --------------- eth0 Link encap:Ethernet HWaddr b8:27:eb:8e:ac:1f inet addr:192.168.0.22 Bcast:192.168.0.255 Mask:255.255.255.0 UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:90053 errors:0 dropped:4 overruns:0 frame:0 TX packets:17174 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:130460322 (124.4 MiB) TX bytes:1850339 (1.7 MiB) lo Link encap:Local Loopback inet addr:127.0.0.1 Mask:255.0.0.0 UP LOOPBACK RUNNING MTU:65536 Metric:1 RX packets:15258 errors:0 dropped:0 overruns:0 frame:0 TX packets:15258 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:1897612 (1.8 MiB) TX bytes:1897612 (1.8 MiB) # sudo iwconfig --------------- eth0 no wireless extensions. lo no wireless extensions. wlan0 IEEE 802.11 ESSID:off/any Mode:Managed Access Point: Not-Associated Retry short limit:7 RTS thr:off Fragment thr:off Encryption key:off Power Management:off # aplay -l --------------- xcb_connection_has_error() returned true **** List of PLAYBACK Hardware Devices **** card 0: ALSA [bcm2835 ALSA], device 0: bcm2835 ALSA [bcm2835 ALSA] Subdevices: 4/4 Subdevice #0: subdevice #0 Subdevice #1: subdevice #1 Subdevice #2: subdevice #2 Subdevice #3: subdevice #3 card 0: ALSA [bcm2835 ALSA], device 1: bcm2835 IEC958/HDMI [bcm2835 IEC958/HDMI] Subdevices: 1/1 Subdevice #0: subdevice #0 card 0: ALSA [bcm2835 ALSA], device 2: bcm2835 IEC958/HDMI1 [bcm2835 IEC958/HDMI1] Subdevices: 1/1 Subdevice #0: subdevice #0 card 1: Headphones [bcm2835 Headphones], device 0: bcm2835 Headphones [bcm2835 Headphones] Subdevices: 3/3 Subdevice #0: subdevice #0 Subdevice #1: subdevice #1 Subdevice #2: subdevice #2 card 2: sndrpihifiberry [snd_rpi_hifiberry_dacplus], device 0: HiFiBerry DAC+ HiFi pcm512x-hifi-0 [HiFiBerry DAC+ HiFi pcm512x-hifi-0] Subdevices: 0/1 Subdevice #0: subdevice #0 # ps -ef --------------- UID PID PPID C STIME TTY TIME CMD root 1 0 0 20:10 ? 00:00:05 /sbin/init root 2 0 0 20:10 ? 00:00:00 [kthreadd] root 3 2 0 20:10 ? 00:00:00 [rcu_gp] root 4 2 0 20:10 ? 00:00:00 [rcu_par_gp] root 8 2 0 20:10 ? 00:00:00 [mm_percpu_wq] root 9 2 0 20:10 ? 00:00:00 [ksoftirqd/0] root 10 2 0 20:10 ? 00:00:00 [rcu_sched] root 11 2 0 20:10 ? 00:00:00 [rcu_bh] root 12 2 0 20:10 ? 00:00:00 [migration/0] root 13 2 0 20:10 ? 00:00:00 [cpuhp/0] root 14 2 0 20:10 ? 00:00:00 [cpuhp/1] root 15 2 0 20:10 ? 00:00:00 [migration/1] root 16 2 0 20:10 ? 00:00:00 [ksoftirqd/1] root 19 2 0 20:10 ? 00:00:00 [cpuhp/2] root 20 2 0 20:10 ? 00:00:00 [migration/2] root 21 2 0 20:10 ? 00:00:00 [ksoftirqd/2] root 24 2 0 20:10 ? 00:00:00 [cpuhp/3] root 25 2 0 20:10 ? 00:00:00 [migration/3] root 26 2 0 20:10 ? 00:00:00 [ksoftirqd/3] root 29 2 0 20:10 ? 00:00:00 [kdevtmpfs] root 30 2 0 20:10 ? 00:00:00 [netns] root 32 2 0 20:10 ? 00:00:00 [kworker/1:1-eve] root 34 2 0 20:10 ? 00:00:00 [kworker/3:1-eve] root 35 2 0 20:10 ? 00:00:00 [khungtaskd] root 36 2 0 20:10 ? 00:00:00 [oom_reaper] root 37 2 0 20:10 ? 00:00:00 [writeback] root 38 2 0 20:10 ? 00:00:00 [kcompactd0] root 39 2 0 20:10 ? 00:00:00 [crypto] root 40 2 0 20:10 ? 00:00:00 [kblockd] root 41 2 0 20:10 ? 00:00:00 [watchdogd] root 42 2 0 20:10 ? 00:00:00 [rpciod] root 43 2 0 20:10 ? 00:00:00 [kworker/u9:0-hc] root 44 2 0 20:10 ? 00:00:00 [xprtiod] root 45 2 0 20:10 ? 00:00:00 [kworker/u8:1-ev] root 47 2 0 20:10 ? 00:00:00 [kswapd0] root 48 2 0 20:10 ? 00:00:00 [nfsiod] root 70 2 0 20:10 ? 00:00:00 [kthrotld] root 71 2 0 20:10 ? 00:00:00 [iscsi_eh] root 72 2 0 20:10 ? 00:00:00 [dwc_otg] root 73 2 0 20:10 ? 00:00:00 [DWC Notificatio] root 74 2 0 20:10 ? 00:00:00 [vchiq-slot/0] root 75 2 0 20:10 ? 00:00:00 [vchiq-recy/0] root 76 2 0 20:10 ? 00:00:00 [vchiq-sync/0] root 77 2 0 20:10 ? 00:00:00 [vchiq-keep/0] root 78 2 0 20:10 ? 00:00:00 [SMIO] root 79 2 0 20:10 ? 00:00:00 [kworker/2:2-mm_] root 80 2 0 20:10 ? 00:00:00 [irq/86-mmc1] root 89 2 0 20:10 ? 00:00:00 [mmc_complete] root 90 2 0 20:10 ? 00:00:00 [kworker/2:1H-kb] root 91 2 0 20:10 ? 00:00:00 [kworker/0:1H-kb] root 112 2 0 20:10 ? 00:00:00 [kworker/1:1H-kb] root 113 2 0 20:10 ? 00:00:00 [kworker/1:2H-kb] root 117 2 0 20:10 ? 00:00:00 [kworker/3:1H-kb] root 118 2 0 20:10 ? 00:00:00 [jbd2/mmcblk0p2-] root 119 2 0 20:10 ? 00:00:00 [ext4-rsv-conver] root 121 2 0 20:10 ? 00:00:00 [kworker/0:2-cgr] root 123 2 0 20:10 ? 00:00:00 [irq/166-usb-001] root 129 2 0 20:10 ? 00:00:00 [loop0] root 148 2 0 20:10 ? 00:00:00 [kworker/2:2H-kb] root 149 2 0 20:10 ? 00:00:00 [jbd2/mmcblk0p3-] root 150 2 0 20:10 ? 00:00:00 [ext4-rsv-conver] root 157 2 0 20:10 ? 00:00:00 [ipv6_addrconf] root 169 2 0 20:10 ? 00:00:00 [kworker/3:2H-kb] root 187 1 0 20:10 ? 00:00:02 /lib/systemd/systemd-journald root 200 2 0 20:10 ? 00:00:00 [kworker/0:2H-kb] root 213 1 0 20:10 ? 00:00:00 /lib/systemd/systemd-udevd root 257 2 0 20:10 ? 00:00:00 [SMIO] root 299 2 0 20:10 ? 00:00:00 [mmal-vchiq] root 302 2 0 20:10 ? 00:00:00 [mmal-vchiq] root 305 2 0 20:10 ? 00:00:00 [mmal-vchiq] root 353 2 0 20:10 ? 00:00:00 [cfg80211] root 358 2 0 20:10 ? 00:00:00 [brcmf_wq/mmc1:0] root 359 2 0 20:10 ? 00:00:00 [brcmf_wdog/mmc1] root 506 2 0 20:10 ? 00:00:00 [kworker/1:3-mm_] root 576 1 0 20:10 ? 00:00:00 /sbin/rpcbind -w statd 586 1 0 20:10 ? 00:00:00 /sbin/rpc.statd root 598 1 0 20:10 ? 00:00:00 /usr/sbin/rpc.idmapd root 600 1 0 20:10 ? 00:00:01 /usr/sbin/haveged --Foreground --verbose=1 --write=1024 volumio 603 1 0 20:10 ? 00:00:00 /usr/bin/udisks-glue --foreground volumio 608 1 0 20:10 ? 00:00:00 /usr/local/bin/volumio-remote-updater root 609 1 0 20:10 ? 00:00:00 /bin/bash /bin/volumiologrotate root 629 1 0 20:10 ? 00:00:00 /lib/systemd/systemd-logind avahi 668 1 0 20:10 ? 00:00:00 avahi-daemon: running [volumio.local] mpd 675 1 1 20:10 ? 00:00:09 /usr/bin/mpd --no-daemon message+ 676 1 0 20:10 ? 00:00:00 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation nobody 702 1 0 20:10 ? 00:00:00 /usr/sbin/thd --daemon --triggers /etc/triggerhappy/triggers.d/ --socket /var/run/thd.socket --pidfile /var/run/thd.pid --user nobody /dev/input/event* root 716 1 0 20:10 ? 00:00:00 /usr/sbin/ifplugd -i eth0 -q -f -u0 -d10 -w -I root 743 2 0 20:10 ? 00:00:00 [kworker/u8:3-ev] avahi 772 668 0 20:10 ? 00:00:00 avahi-daemon: chroot helper root 779 1 0 20:10 ? 00:00:00 /usr/bin/hciattach /dev/serial1 bcm43xx 3000000 flow - b8:27:eb:24:06:b5 root 784 2 0 20:10 ? 00:00:00 [kworker/u9:2-hc] root 790 1 0 20:10 ? 00:00:00 /usr/sbin/sshd -D ntp 793 1 0 20:10 ? 00:00:00 /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 100:104 root 809 1 0 20:10 ? 00:00:00 /sbin/dhcpcd root 815 1 0 20:10 ? 00:00:00 /usr/lib/udisks/udisks-daemon --no-debug root 817 1 0 20:10 ? 00:00:00 /usr/lib/bluetooth/bluetoothd --noplugin=sap root 832 1 0 20:10 tty1 00:00:00 /sbin/agetty --noclear tty1 linux root 834 815 0 20:10 ? 00:00:00 udisks-daemon: not polling any devices root 843 1 0 20:10 ? 00:00:00 /usr/lib/policykit-1/polkitd --no-debug root 891 1 0 20:10 ? 00:00:00 /usr/sbin/nmbd -D root 892 891 0 20:10 ? 00:00:00 /usr/sbin/nmbd -D root 906 1 0 20:10 ? 00:00:00 /usr/sbin/winbindd root 910 906 0 20:10 ? 00:00:00 /usr/sbin/winbindd volumio 914 1 2 20:10 ? 00:00:22 /usr/local/bin/node /volumio/index.js root 930 1 0 20:10 ? 00:00:00 /usr/sbin/smbd -D root 937 906 0 20:10 ? 00:00:00 /usr/sbin/winbindd root 938 906 0 20:10 ? 00:00:00 /usr/sbin/winbindd root 939 930 0 20:10 ? 00:00:00 /usr/sbin/smbd -D root 985 2 0 20:10 ? 00:00:00 [cifsiod] root 986 2 0 20:10 ? 00:00:00 [cifsoplockd] root 990 2 0 20:10 ? 00:00:00 [cifsd] volumio 1027 914 0 20:10 ? 00:00:00 /bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 1033 1027 0 20:10 ? 00:00:01 /bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 1034 1027 0 20:10 ? 00:00:01 /bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 1039 1027 0 20:10 ? 00:00:01 /bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart shairpo+ 1109 1 0 20:10 ? 00:00:03 /usr/local/bin/shairport-sync --configfile=/tmp/shairport-sync.conf volumio 1146 1 0 20:10 ? 00:00:01 /usr/bin/upmpdcli -c /tmp/upmpdcli.conf volumio 1174 1 0 20:10 ? 00:00:00 /bin/streaming-daemon volumio 1205 1 0 20:10 ? 00:00:00 /bin/sh /tmp/sshtunnel.sh volumio 1207 1205 0 20:10 ? 00:00:00 /usr/lib/autossh/autossh -M 0 -o ServerAliveInterval 30 -o ServerAliveCountMax 3 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -N -p 2222 -R YKafCM5P6LeTbWAZkT5Wjzkz7683-ff06005737f2cdb74650c18e4be1765d.eu1.myvolumio.org:8091:localhost:3000 eu1.myvolumio.org volumio 1213 1207 0 20:10 ? 00:00:00 /usr/bin/ssh -o ServerAliveInterval 30 -o ServerAliveCountMax 3 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -N -p 2222 -R YKafCM5P6LeTbWAZkT5Wjzkz7683-ff06005737f2cdb74650c18e4be1765d.eu1.myvolumio.org:8091:localhost:3000 eu1.myvolumio.org volumio 1246 1 0 20:10 ? 00:00:00 /bin/sh /bin/bt/btstart.sh start volumio 1271 1 0 20:10 ? 00:00:00 /usr/bin/pulseaudio rtkit 1272 1 0 20:10 ? 00:00:00 /usr/lib/rtkit/rtkit-daemon volumio 1280 1246 0 20:10 ? 00:00:00 /usr/bin/python /bin/bt/simple-agent -c NoInputNoOutput volumio 1429 914 0 20:11 ? 00:00:00 /bin/journalctl --output cat -f root 1927 2 0 20:15 ? 00:00:00 [kworker/3:2-eve] root 2021 2 0 20:16 ? 00:00:00 [kworker/0:0-eve] root 2125 2 0 20:16 ? 00:00:00 [kworker/2:0-eve] root 2657 2 0 20:20 ? 00:00:00 [kworker/3:0-eve] root 2718 2 0 20:21 ? 00:00:00 [kworker/1:0-eve] root 2972 2 0 20:22 ? 00:00:00 [kworker/2:1-eve] root 3038 2 0 20:23 ? 00:00:00 [kworker/0:1-mm_] root 3057 609 0 20:24 ? 00:00:00 sleep 60 volumio 3067 914 0 20:25 ? 00:00:00 /bin/sh -c /usr/local/bin/node /volumio/logsubmit.js 'restart, load Tidal playlist, listen two songs, skip to third, everything stops working' volumio 3068 3067 0 20:25 ? 00:00:00 /usr/local/bin/node /volumio/logsubmit.js restart, load Tidal playlist, listen two songs, skip to third, everything stops working volumio 3093 3068 0 20:25 ? 00:00:00 /bin/sh -c ps -ef >>/tmp/logondemand 2>&1 volumio 3094 3093 0 20:25 ? 00:00:00 ps -ef # df -h --------------- Filesystem Size Used Avail Use% Mounted on /dev/mmcblk0p2 2.2G 1.1G 1001M 53% /imgpart /dev/loop0 340M 340M 0 100% /static overlay 13G 172M 12G 2% / devtmpfs 471M 0 471M 0% /dev tmpfs 485M 68K 485M 1% /dev/shm tmpfs 485M 4.7M 481M 1% /run tmpfs 5.0M 4.0K 5.0M 1% /run/lock tmpfs 485M 0 485M 0% /sys/fs/cgroup tmpfs 485M 60K 485M 1% /tmp tmpfs 485M 0 485M 0% /var/spool/cups tmpfs 20M 16K 20M 1% /var/log tmpfs 485M 0 485M 0% /var/spool/cups/tmp /dev/mmcblk0p1 61M 57M 3.4M 95% /boot //192.168.0.55/music 1.9T 767G 1.1T 42% /mnt/NAS/HomePC # mount --------------- /dev/mmcblk0p2 on /imgpart type ext4 (rw,relatime,stripe=1024) /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=482104k,nr_inodes=120526,mode=755) 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) cgroup on /sys/fs/cgroup/systemd type cgroup (rw,nosuid,nodev,noexec,relatime,xattr,release_agent=/lib/systemd/systemd-cgroups-agent,name=systemd) 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/blkio type cgroup (rw,nosuid,nodev,noexec,relatime,blkio) cgroup on /sys/fs/cgroup/memory type cgroup (rw,nosuid,nodev,noexec,relatime,memory) cgroup on /sys/fs/cgroup/devices type cgroup (rw,nosuid,nodev,noexec,relatime,devices) cgroup on /sys/fs/cgroup/freezer type cgroup (rw,nosuid,nodev,noexec,relatime,freezer) cgroup on /sys/fs/cgroup/net_cls type cgroup (rw,nosuid,nodev,noexec,relatime,net_cls) cgroup on /sys/fs/cgroup/pids type cgroup (rw,nosuid,nodev,noexec,relatime,pids) systemd-1 on /proc/sys/fs/binfmt_misc type autofs (rw,relatime,fd=22,pgrp=1,timeout=300,minproto=5,maxproto=5,direct) mqueue on /dev/mqueue type mqueue (rw,relatime) debugfs on /sys/kernel/debug type debugfs (rw,relatime) fusectl on /sys/fs/fuse/connections type fusectl (rw,relatime) configfs on /sys/kernel/config type configfs (rw,relatime) tmpfs on /tmp type tmpfs (rw,noatime,mode=755) tmpfs on /var/spool/cups type tmpfs (rw,noatime,mode=755) tmpfs on /var/log type tmpfs (rw,nodev,relatime,size=20480k,mode=777,uid=1000,gid=4) tmpfs on /var/spool/cups/tmp type tmpfs (rw,noatime,mode=755) /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) rpc_pipefs on /run/rpc_pipefs type rpc_pipefs (rw,relatime) //192.168.0.55/music on /mnt/NAS/HomePC type cifs (ro,relatime,vers=default,cache=strict,username=aleksandra,uid=0,noforceuid,gid=0,noforcegid,addr=192.168.0.55,file_mode=0666,dir_mode=0777,soft,nounix,serverino,mapposix,rsize=1048576,wsize=1048576,echo_interval=60,actimeo=1) # netstat -natp --------------- (Not all processes could be identified, non-owned process info will not be shown, you would have to be root to see it all.) Active Internet connections (servers and established) Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name tcp 0 0 0.0.0.0:445 0.0.0.0:* LISTEN - tcp 0 0 192.168.0.22:49152 0.0.0.0:* LISTEN 1146/upmpdcli tcp 0 0 0.0.0.0:5000 0.0.0.0:* LISTEN - tcp 0 0 0.0.0.0:4713 0.0.0.0:* LISTEN 1271/pulseaudio tcp 0 0 0.0.0.0:139 0.0.0.0:* LISTEN - tcp 0 0 0.0.0.0:111 0.0.0.0:* LISTEN - tcp 0 0 0.0.0.0:54833 0.0.0.0:* LISTEN - tcp 0 0 0.0.0.0:22 0.0.0.0:* LISTEN - tcp 0 0 127.0.0.1:42030 127.0.0.1:3000 ESTABLISHED 914/node tcp 0 0 192.168.0.22:44366 35.201.97.85:443 ESTABLISHED 914/node tcp 0 0 127.0.0.1:59342 127.0.0.1:6600 ESTABLISHED 914/node tcp 0 0 127.0.0.1:42244 127.0.0.1:3000 ESTABLISHED 608/volumio-remote- tcp 0 0 192.168.0.22:52734 151.101.2.142:80 ESTABLISHED - tcp 0 0 127.0.0.1:42018 127.0.0.1:3000 ESTABLISHED 914/node tcp 0 0 192.168.0.22:48792 192.168.0.55:445 ESTABLISHED - tcp 0 0 127.0.0.1:50680 127.0.0.1:6599 TIME_WAIT - tcp 0 235 192.168.0.22:42946 151.101.66.142:80 ESTABLISHED - tcp 0 0 192.168.0.22:50686 172.67.141.32:443 ESTABLISHED 1174/streaming-daem tcp 0 32 192.168.0.22:54956 188.166.162.121:443 LAST_ACK - tcp 0 0 192.168.0.22:50584 172.67.141.32:443 ESTABLISHED 1174/streaming-daem tcp 0 0 127.0.0.1:50704 127.0.0.1:6599 ESTABLISHED 1146/upmpdcli tcp 0 0 127.0.0.1:50694 127.0.0.1:6599 TIME_WAIT - tcp 0 0 127.0.0.1:42068 127.0.0.1:3000 ESTABLISHED 914/node tcp 0 0 127.0.0.1:42448 127.0.0.1:3000 TIME_WAIT - tcp 0 0 192.168.0.22:33650 84.247.14.230:80 ESTABLISHED 914/node tcp 1 32 192.168.0.22:54940 188.166.162.121:443 LAST_ACK - tcp 0 0 127.0.0.1:59754 127.0.0.1:6600 ESTABLISHED 914/node tcp 0 0 127.0.0.1:59730 127.0.0.1:6600 ESTABLISHED 914/node tcp 0 0 192.168.0.22:50684 172.67.141.32:443 ESTABLISHED 1174/streaming-daem tcp 0 0 192.168.0.22:47318 188.166.162.121:2222 ESTABLISHED 1213/ssh tcp 0 0 192.168.0.22:50600 172.67.141.32:443 ESTABLISHED 1174/streaming-daem tcp 0 0 127.0.0.1:59744 127.0.0.1:6600 ESTABLISHED 914/node tcp6 0 0 :::3000 :::* LISTEN 914/node tcp6 0 0 :::3001 :::* LISTEN 1027/node tcp6 0 0 :::3005 :::* LISTEN 914/node tcp6 0 0 :::445 :::* LISTEN - tcp6 0 0 :::49152 :::* LISTEN 1146/upmpdcli tcp6 0 0 :::7777 :::* LISTEN 1174/streaming-daem tcp6 0 0 :::6599 :::* LISTEN 914/node tcp6 0 0 :::46471 :::* LISTEN - tcp6 0 0 :::5000 :::* LISTEN - tcp6 0 0 :::6600 :::* LISTEN - tcp6 0 0 :::4713 :::* LISTEN 1271/pulseaudio tcp6 0 0 :::139 :::* LISTEN - tcp6 0 0 :::111 :::* LISTEN - tcp6 0 0 :::22 :::* LISTEN - tcp6 0 0 127.0.0.1:3000 127.0.0.1:42244 ESTABLISHED 914/node tcp6 0 0 127.0.0.1:3000 127.0.0.1:42068 ESTABLISHED 914/node tcp6 0 0 127.0.0.1:3000 127.0.0.1:42018 ESTABLISHED 914/node tcp6 0 0 192.168.0.22:3000 192.168.0.211:54758 TIME_WAIT - tcp6 0 0 127.0.0.1:3000 127.0.0.1:42030 ESTABLISHED 914/node tcp6 0 0 127.0.0.1:6599 127.0.0.1:50704 ESTABLISHED 914/node tcp6 0 0 192.168.0.22:3000 192.168.0.211:54535 ESTABLISHED 914/node tcp6 0 0 192.168.0.22:3000 192.168.0.211:54524 ESTABLISHED 914/node tcp6 7 0 127.0.0.1:6600 127.0.0.1:59342 ESTABLISHED - tcp6 0 0 127.0.0.1:6600 127.0.0.1:59730 ESTABLISHED - tcp6 0 0 127.0.0.1:6600 127.0.0.1:59754 ESTABLISHED - tcp6 0 0 127.0.0.1:6600 127.0.0.1:59744 ESTABLISHED - # cat /var/log/mpd.log --------------- Mar 02 20:10 : zeroconf: No global port, disabling zeroconf Mar 02 20:10 : client: [0] opened from local Mar 02 20:10 : exception: No such directory Mar 02 20:10 : client: [1] opened from 127.0.0.1:59342 Mar 02 20:11 : exception: No such playlist Mar 02 20:13 : player: played "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInOWE5ZTE5MzViN2UzOTlhZjI3YWQ3NDYwZDNjMjdlMzFfNjEubXA0/0.flac?token=1614719466~ZWFmZDVjZmM2NGMzZjhjNzRmYmViMzM5M2JhMTQ4MmI2YTJkNmIzMQ==" Mar 02 20:13 : exception: No such playlist Mar 02 20:13 : player: played "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInZDQxZmQ0NGU4NDcyYTczZWM3ZGYzMGE4MjExNzYyMmVfNjEubXA0/0.flac?token=1614719601~ZjMyYWZlOTFlMmZmMDhiYThmZjFlYWFmZWNkZmJiYWEyYzgzZTczNg==" Mar 02 20:13 : exception: No such playlist Mar 02 20:14 : player: played "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInYzFlZjZkNjIxZTM3MWVlMzYzODM3YzljOWFiZmI1YTdfNjEubXA0/0.flac?token=1614719606~ZmJiYmVmYmVmMmEwYjZkNzkwODY0ZjZkMjMyYjFkNmI0YjRlMTNlZA==" Mar 02 20:15 : exception: No such playlist Mar 02 20:15 : player: played "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInMzNmNTY0YjdmNDhhYWNlZDk2NTBjZGQwZmI1NjRlMTlfNjEubXA0/0.flac?token=1614719700~NTRiNjdkZjgyNjE2Nzk0MGQ0OGVhYzI0ODQ3Mjg4ZjJkOGJlODVmMg==" Mar 02 20:15 : exception: No such playlist Mar 02 20:18 : exception: No such playlist Mar 02 20:18 : player: played "http://ab-pr-fa.audio.tidal.com/d74a4ade474c28c47ede2c87d4dc104b_39.flac?token=1614719705~MjMwMjU5OTY1NGU2YzU0ZmFjNTgyN2Q2MDI2MzEwNTA2Y2JhZGZlZg==" Mar 02 20:23 : player: played "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInMTY2NzUwMDI5ODNjNjc3YmYxZWMxYjExMjg2NDFjZWVfNjEubXA0/0.flac?token=1614719907~M2VmOGFhMmIxMjY2MmRlOWZlZjU5ODQzMThiZjBmMDNjMDdiYzQyMQ==" # cat /data/configuration/plugins.json --------------- { "music_service": { "airplay_emulation": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "mpd": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "webradio": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "example_plugin": { "enabled": { "type": "boolean", "value": false }, "status": { "type": "string", "value": "STOPPED" } }, "last_100": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "upnp_browser": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "inputs": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "streaming_services": { "status": { "type": "string", "value": "STARTED" } }, "radio_paradise": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "cd_controller": { "status": { "type": "string", "value": "STARTED" } }, "tidal": { "status": { "type": "string", "value": "STARTED" } }, "qobuz": { "status": { "type": "string", "value": "STARTED" } } }, "audio_interface": { "upnp": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "alsa_controller": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "outputs": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "bluetooth": { "status": { "type": "string", "value": "STARTED" } } }, "miscellanea": { "alarm-clock": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "albumart": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "appearance": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "wizard": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "my_music": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } } }, "user_interface": { "websocket": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "mpdemulation": { "enabled": { "type": "boolean", "value": false }, "status": { "type": "string", "value": "STARTED" } }, "rest_api": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } } }, "system_controller": { "updater_comm": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "network": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "networkfs": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "services": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "system": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "i2s_dacs": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "volumiodiscovery": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "volumio_command_line_client": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "my_volumio": { "status": { "type": "string", "value": "STARTED" } } } } # cat /etc/mpd.conf --------------- # Volumio MPD Configuration File # Files and directories ####################################################### music_directory "/var/lib/mpd/music" playlist_directory "/var/lib/mpd/playlists" db_file "/var/lib/mpd/tag_cache" log_file "/var/log/mpd.log" #pid_file "/var/run/mpd/pid" #state_file "/var/lib/mpd/state" #sticker_file "/var/lib/mpd/sticker.sql" ############################################################################### # General music daemon options ################################################ user "mpd" group "audio" bind_to_address "any" #port "6600" #log_level "default" gapless_mp3_playback "no" #save_absolute_paths_in_playlists "no" #metadata_to_use "artist,album,title,track,name,genre,date,composer,performer,disc" auto_update "yes" #auto_update_depth "3" ############################################################################### # Symbolic link behavior ###################################################### follow_outside_symlinks "yes" follow_inside_symlinks "yes" ############################################################################### # Input ####################################################################### # input { plugin "curl" # proxy "proxy.isp.com:8080" # proxy_user "user" # proxy_password "password" } ############################################################################### # Decoder ################################################################ ############################################################################### # Audio Output ################################################################ resampler { plugin "soxr" quality "high" threads "1" } audio_output { type "alsa" name "alsa" device "hw:2,0" dop "no" } audio_output { type "fifo" enabled "no" name "multiroom" path "/tmp/snapfifo" format "44100:16:2" } #replaygain "album" #replaygain_preamp "0" volume_normalization "no" ############################################################################### # MPD Internal Buffering ###################################################### audio_buffer_size "4096" buffer_before_play "10%" ############################################################################### # Resource Limitations ######################################################## #connection_timeout "60" max_connections "20" max_playlist_length "81920" max_command_list_size "81920" max_output_buffer_size "81920" ############################################################################### # Character Encoding ########################################################## filesystem_charset "UTF-8" id3v1_encoding "UTF-8" ############################################################################### # volumio endpointstest --------------- TESTING REMOTE ENDPOINTS https://google.com: OK https://www.googleapis.com: OK https://securetoken.googleapis.com: OK https://myvolumio.firebaseio.com: OK https://functions.volumio.cloud: OK https://oauth-performer.dfs.volumio.org: OK http://cddb.volumio.org: OK https://functions.volumio.cloud: OK http://pushupdates.volumio.org: OK http://plugins.volumio.org: OK https://database.volumio.cloud: OK https://radio-directory.firebaseapp.com: OK ---------- REMOTE ENDPOINTS TEST OK, all Endpoints are reachable ---------- # sudo journalctl -p 7 --------------- -- Logs begin at Tue 2021-03-02 20:09:56 UTC, end at Tue 2021-03-02 20:25:16 UTC. -- Mar 02 20:09:56 volumio systemd-journal[187]: Runtime journal is using 4.0M (max allowed 30.0M, trying to leave 72.7M free of 480.6M available → current limit 30.0M). Mar 02 20:09:56 volumio kernel: Booting Linux on physical CPU 0x0 Mar 02 20:09:56 volumio kernel: Linux version 4.19.118-v7+ (dom@buildbot) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1311 SMP Mon Apr 27 14:21:24 BST 2020 Mar 02 20:09:56 volumio kernel: CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d Mar 02 20:09:56 volumio kernel: CPU: div instructions available: patching division code Mar 02 20:09:56 volumio kernel: CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache Mar 02 20:09:56 volumio kernel: OF: fdt: Machine model: Raspberry Pi 3 Model B Plus Rev 1.3 Mar 02 20:09:56 volumio kernel: Memory policy: Data cache writealloc Mar 02 20:09:56 volumio kernel: cma: Reserved 8 MiB at 0x3d800000 Mar 02 20:09:56 volumio kernel: On node 0 totalpages: 253952 Mar 02 20:09:56 volumio kernel: Normal zone: 2232 pages used for memmap Mar 02 20:09:56 volumio kernel: Normal zone: 0 pages reserved Mar 02 20:09:56 volumio kernel: Normal zone: 253952 pages, LIFO batch:63 Mar 02 20:09:56 volumio kernel: random: get_random_bytes called from start_kernel+0xac/0x4b4 with crng_init=0 Mar 02 20:09:56 volumio kernel: percpu: Embedded 16 pages/cpu s36864 r8192 d20480 u65536 Mar 02 20:09:56 volumio kernel: pcpu-alloc: s36864 r8192 d20480 u65536 alloc=16*4096 Mar 02 20:09:56 volumio kernel: pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 Mar 02 20:09:56 volumio kernel: Built 1 zonelists, mobility grouping on. Total pages: 251720 Mar 02 20:09:56 volumio kernel: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 bcm2708_fb.fbwidth=640 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash quiet 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 console=ttyS0,115200 kgdboc=ttyS0,115200 console=tty1 imgpart=/dev/mmcblk0p2 imgfile=/volumio_current.sqsh elevator=noop rootwait bootdelay=5 logo.nologo vt.global_cursor_default=0 loglevel=0 snd-bcm2835.enable_compat_alsa=1 snd_bcm2835.enable_headphones=1 Mar 02 20:09:56 volumio kernel: Dentry cache hash table entries: 131072 (order: 7, 524288 bytes) Mar 02 20:09:56 volumio kernel: Inode-cache hash table entries: 65536 (order: 6, 262144 bytes) Mar 02 20:09:56 volumio kernel: Memory: 964208K/1015808K available (8192K kernel code, 656K rwdata, 2232K rodata, 1024K init, 831K bss, 43408K reserved, 8192K cma-reserved) Mar 02 20:09:56 volumio kernel: Virtual kernel memory layout: vector : 0xffff0000 - 0xffff1000 ( 4 kB) fixmap : 0xffc00000 - 0xfff00000 (3072 kB) vmalloc : 0xbe800000 - 0xff800000 (1040 MB) lowmem : 0x80000000 - 0xbe000000 ( 992 MB) modules : 0x7f000000 - 0x80000000 ( 16 MB) .text : 0x(ptrval) - 0x(ptrval) (9184 kB) .init : 0x(ptrval) - 0x(ptrval) (1024 kB) .data : 0x(ptrval) - 0x(ptrval) ( 657 kB) .bss : 0x(ptrval) - 0x(ptrval) ( 832 kB) Mar 02 20:09:56 volumio kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Mar 02 20:09:56 volumio kernel: ftrace: allocating 27093 entries in 80 pages Mar 02 20:09:56 volumio kernel: rcu: Hierarchical RCU implementation. Mar 02 20:09:56 volumio kernel: NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 Mar 02 20:09:56 volumio kernel: arch_timer: cp15 timer(s) running at 19.20MHz (phys). Mar 02 20:09:56 volumio kernel: clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns Mar 02 20:09:56 volumio kernel: sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns Mar 02 20:09:56 volumio kernel: Switching to timer-based delay loop, resolution 52ns Mar 02 20:09:56 volumio kernel: Console: colour dummy device 80x30 Mar 02 20:09:56 volumio kernel: console [tty1] enabled Mar 02 20:09:56 volumio kernel: Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000) Mar 02 20:09:56 volumio kernel: pid_max: default: 32768 minimum: 301 Mar 02 20:09:56 volumio kernel: Mount-cache hash table entries: 2048 (order: 1, 8192 bytes) Mar 02 20:09:56 volumio kernel: Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes) Mar 02 20:09:56 volumio kernel: CPU: Testing write buffer coherency: ok Mar 02 20:09:56 volumio kernel: CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 Mar 02 20:09:56 volumio kernel: Setting up static identity map for 0x100000 - 0x10003c Mar 02 20:09:56 volumio kernel: rcu: Hierarchical SRCU implementation. Mar 02 20:09:56 volumio kernel: smp: Bringing up secondary CPUs ... Mar 02 20:09:56 volumio kernel: CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 Mar 02 20:09:56 volumio kernel: CPU2: thread -1, cpu 2, socket 0, mpidr 80000002 Mar 02 20:09:56 volumio kernel: CPU3: thread -1, cpu 3, socket 0, mpidr 80000003 Mar 02 20:09:56 volumio kernel: smp: Brought up 1 node, 4 CPUs Mar 02 20:09:56 volumio kernel: SMP: Total of 4 processors activated (153.60 BogoMIPS). Mar 02 20:09:56 volumio kernel: CPU: All CPU(s) started in HYP mode. Mar 02 20:09:56 volumio kernel: CPU: Virtualization extensions available. Mar 02 20:09:56 volumio kernel: devtmpfs: initialized Mar 02 20:09:56 volumio kernel: VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4 Mar 02 20:09:56 volumio kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns Mar 02 20:09:56 volumio kernel: futex hash table entries: 1024 (order: 4, 65536 bytes) Mar 02 20:09:56 volumio kernel: pinctrl core: initialized pinctrl subsystem Mar 02 20:09:56 volumio kernel: NET: Registered protocol family 16 Mar 02 20:09:56 volumio kernel: DMA: preallocated 1024 KiB pool for atomic coherent allocations Mar 02 20:09:56 volumio kernel: hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. Mar 02 20:09:56 volumio kernel: hw-breakpoint: maximum watchpoint size is 8 bytes. Mar 02 20:09:56 volumio kernel: Serial: AMBA PL011 UART driver Mar 02 20:09:56 volumio kernel: bcm2835-mbox 3f00b880.mailbox: mailbox enabled Mar 02 20:09:56 volumio kernel: raspberrypi-firmware soc:firmware: Attached to firmware from 2020-04-27 14:35, variant start Mar 02 20:09:56 volumio kernel: raspberrypi-firmware soc:firmware: Firmware hash is 3a8f1793b758d6fb7f375edaa260e069ecd34c88 Mar 02 20:09:56 volumio kernel: bcm2835-dma 3f007000.dma: DMA legacy API manager at (ptrval), dmachans=0x1 Mar 02 20:09:56 volumio kernel: SCSI subsystem initialized Mar 02 20:09:56 volumio kernel: usbcore: registered new interface driver usbfs Mar 02 20:09:56 volumio kernel: usbcore: registered new interface driver hub Mar 02 20:09:56 volumio kernel: usbcore: registered new device driver usb Mar 02 20:09:56 volumio kernel: clocksource: Switched to clocksource arch_sys_counter Mar 02 20:09:56 volumio kernel: VFS: Disk quotas dquot_6.6.0 Mar 02 20:09:56 volumio kernel: VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) Mar 02 20:09:56 volumio kernel: FS-Cache: Loaded Mar 02 20:09:56 volumio kernel: CacheFiles: Loaded Mar 02 20:09:56 volumio kernel: NET: Registered protocol family 2 Mar 02 20:09:56 volumio kernel: tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes) Mar 02 20:09:56 volumio kernel: TCP established hash table entries: 8192 (order: 3, 32768 bytes) Mar 02 20:09:56 volumio kernel: TCP bind hash table entries: 8192 (order: 4, 65536 bytes) Mar 02 20:09:56 volumio kernel: TCP: Hash tables configured (established 8192 bind 8192) Mar 02 20:09:56 volumio kernel: UDP hash table entries: 512 (order: 2, 16384 bytes) Mar 02 20:09:56 volumio kernel: UDP-Lite hash table entries: 512 (order: 2, 16384 bytes) Mar 02 20:09:56 volumio kernel: NET: Registered protocol family 1 Mar 02 20:09:56 volumio kernel: RPC: Registered named UNIX socket transport module. Mar 02 20:09:56 volumio kernel: RPC: Registered udp transport module. Mar 02 20:09:56 volumio kernel: RPC: Registered tcp transport module. Mar 02 20:09:56 volumio kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Mar 02 20:09:56 volumio kernel: Trying to unpack rootfs image as initramfs... Mar 02 20:09:56 volumio kernel: Freeing initrd memory: 19512K Mar 02 20:09:56 volumio kernel: hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available Mar 02 20:09:56 volumio kernel: Initialise system trusted keyrings Mar 02 20:09:56 volumio kernel: workingset: timestamp_bits=14 max_order=18 bucket_order=4 Mar 02 20:09:56 volumio kernel: FS-Cache: Netfs 'nfs' registered for caching Mar 02 20:09:56 volumio kernel: NFS: Registering the id_resolver key type Mar 02 20:09:56 volumio kernel: Key type id_resolver registered Mar 02 20:09:56 volumio kernel: Key type id_legacy registered Mar 02 20:09:56 volumio kernel: nfs4filelayout_init: NFSv4 File Layout Driver Registering... Mar 02 20:09:56 volumio kernel: Key type asymmetric registered Mar 02 20:09:56 volumio kernel: Asymmetric key parser 'x509' registered Mar 02 20:09:56 volumio kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250) Mar 02 20:09:56 volumio kernel: io scheduler noop registered (default) Mar 02 20:09:56 volumio kernel: io scheduler deadline registered Mar 02 20:09:56 volumio kernel: io scheduler cfq registered Mar 02 20:09:56 volumio kernel: io scheduler mq-deadline registered Mar 02 20:09:56 volumio kernel: io scheduler kyber registered Mar 02 20:09:56 volumio kernel: bcm2708_fb soc:fb: FB found 1 display(s) Mar 02 20:09:56 volumio kernel: Console: switching to colour frame buffer device 80x30 Mar 02 20:09:56 volumio kernel: bcm2708_fb soc:fb: Registered framebuffer for display 0, size 640x480 Mar 02 20:09:56 volumio kernel: bcm2835-rng 3f104000.rng: hwrng registered Mar 02 20:09:56 volumio kernel: vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) Mar 02 20:09:56 volumio kernel: vc-sm: Videocore shared memory driver Mar 02 20:09:56 volumio kernel: gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000 Mar 02 20:09:56 volumio kernel: brd: module loaded Mar 02 20:09:56 volumio kernel: loop: module loaded Mar 02 20:09:56 volumio kernel: Loading iSCSI transport class v2.0-870. Mar 02 20:09:56 volumio kernel: libphy: Fixed MDIO Bus: probed Mar 02 20:09:56 volumio kernel: usbcore: registered new interface driver lan78xx Mar 02 20:09:56 volumio kernel: usbcore: registered new interface driver smsc95xx Mar 02 20:09:56 volumio kernel: dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Mar 02 20:09:56 volumio kernel: dwc_otg 3f980000.usb: base=(ptrval) Mar 02 20:09:56 volumio kernel: Core Release: 2.80a Mar 02 20:09:56 volumio kernel: Setting default values for core params Mar 02 20:09:56 volumio kernel: Finished setting default values for core params Mar 02 20:09:56 volumio kernel: Using Buffer DMA mode Mar 02 20:09:56 volumio kernel: Periodic Transfer Interrupt Enhancement - disabled Mar 02 20:09:56 volumio kernel: Multiprocessor Interrupt Enhancement - disabled Mar 02 20:09:56 volumio kernel: OTG VER PARAM: 0, OTG VER FLAG: 0 Mar 02 20:09:56 volumio kernel: Dedicated Tx FIFOs mode Mar 02 20:09:56 volumio kernel: WARN::dwc_otg_hcd_init:1074: FIQ DMA bounce buffers: virt = bd914000 dma = 0xfd914000 len=9024 Mar 02 20:09:56 volumio kernel: FIQ FSM acceleration enabled for : Non-periodic Split Transactions Periodic Split Transactions High-Speed Isochronous Endpoints Interrupt/Control Split Transaction hack enabled Mar 02 20:09:56 volumio kernel: dwc_otg: Microframe scheduler enabled Mar 02 20:09:56 volumio kernel: WARN::hcd_init_fiq:457: FIQ on core 1 Mar 02 20:09:56 volumio kernel: WARN::hcd_init_fiq:458: FIQ ASM at 8068fda0 length 36 Mar 02 20:09:56 volumio kernel: WARN::hcd_init_fiq:497: MPHI regs_base at be810000 Mar 02 20:09:56 volumio kernel: dwc_otg 3f980000.usb: DWC OTG Controller Mar 02 20:09:56 volumio kernel: dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1 Mar 02 20:09:56 volumio kernel: dwc_otg 3f980000.usb: irq 56, io mem 0x00000000 Mar 02 20:09:56 volumio kernel: Init: Port Power? op_state=1 Mar 02 20:09:56 volumio kernel: Init: Power Port (0) Mar 02 20:09:56 volumio kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19 Mar 02 20:09:56 volumio kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Mar 02 20:09:56 volumio kernel: usb usb1: Product: DWC OTG Controller Mar 02 20:09:56 volumio kernel: usb usb1: Manufacturer: Linux 4.19.118-v7+ dwc_otg_hcd Mar 02 20:09:56 volumio kernel: usb usb1: SerialNumber: 3f980000.usb Mar 02 20:09:56 volumio kernel: hub 1-0:1.0: USB hub found Mar 02 20:09:56 volumio kernel: hub 1-0:1.0: 1 port detected Mar 02 20:09:56 volumio kernel: dwc_otg: FIQ enabled Mar 02 20:09:56 volumio kernel: dwc_otg: NAK holdoff enabled Mar 02 20:09:56 volumio kernel: dwc_otg: FIQ split-transaction FSM enabled Mar 02 20:09:56 volumio kernel: Module dwc_common_port init Mar 02 20:09:56 volumio kernel: usbcore: registered new interface driver usb-storage Mar 02 20:09:56 volumio kernel: mousedev: PS/2 mouse device common for all mice Mar 02 20:09:56 volumio kernel: bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Mar 02 20:09:56 volumio kernel: bcm2835-cpufreq: min=600000 max=1400000 Mar 02 20:09:56 volumio kernel: sdhci: Secure Digital Host Controller Interface driver Mar 02 20:09:56 volumio kernel: sdhci: Copyright(c) Pierre Ossman Mar 02 20:09:56 volumio kernel: mmc-bcm2835 3f300000.mmcnr: could not get clk, deferring probe Mar 02 20:09:56 volumio kernel: sdhost-bcm2835 3f202000.mmc: could not get clk, deferring probe Mar 02 20:09:56 volumio kernel: sdhci-pltfm: SDHCI platform and OF driver helper Mar 02 20:09:56 volumio kernel: ledtrig-cpu: registered to indicate activity on CPUs Mar 02 20:09:56 volumio kernel: hidraw: raw HID events driver (C) Jiri Kosina Mar 02 20:09:56 volumio kernel: usbcore: registered new interface driver usbhid Mar 02 20:09:56 volumio kernel: usbhid: USB HID core driver Mar 02 20:09:56 volumio kernel: vchiq: vchiq_init_state: slot_zero = (ptrval), is_master = 0 Mar 02 20:09:56 volumio kernel: [vc_sm_connected_init]: start Mar 02 20:09:56 volumio kernel: [vc_sm_connected_init]: end - returning 0 Mar 02 20:09:56 volumio kernel: Initializing XFRM netlink socket Mar 02 20:09:56 volumio kernel: NET: Registered protocol family 17 Mar 02 20:09:56 volumio kernel: Key type dns_resolver registered Mar 02 20:09:56 volumio kernel: Registering SWP/SWPB emulation handler Mar 02 20:09:56 volumio kernel: registered taskstats version 1 Mar 02 20:09:56 volumio kernel: Loading compiled-in X.509 certificates Mar 02 20:09:56 volumio kernel: uart-pl011 3f201000.serial: cts_event_workaround enabled Mar 02 20:09:56 volumio kernel: 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 81, base_baud = 0) is a PL011 rev2 Mar 02 20:09:56 volumio kernel: mmc-bcm2835 3f300000.mmcnr: mmc_debug:0 mmc_debug2:0 Mar 02 20:09:56 volumio kernel: mmc-bcm2835 3f300000.mmcnr: DMA channel allocated Mar 02 20:09:56 volumio kernel: sdhost: log_buf @ (ptrval) (fd913000) Mar 02 20:09:56 volumio kernel: mmc1: queuing unknown CIS tuple 0x80 (2 bytes) Mar 02 20:09:56 volumio kernel: mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Mar 02 20:09:56 volumio kernel: mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Mar 02 20:09:56 volumio kernel: mmc1: queuing unknown CIS tuple 0x80 (7 bytes) Mar 02 20:09:56 volumio kernel: mmc0: sdhost-bcm2835 loaded - DMA enabled (>1) Mar 02 20:09:56 volumio kernel: of_cfs_init Mar 02 20:09:56 volumio kernel: of_cfs_init: OK Mar 02 20:09:56 volumio kernel: Freeing unused kernel memory: 1024K Mar 02 20:09:56 volumio kernel: Run /init as init process Mar 02 20:09:56 volumio kernel: mmc0: host does not support reading read-only switch, assuming write-enable Mar 02 20:09:56 volumio kernel: mmc0: new high speed SDHC card at address 59b4 Mar 02 20:09:56 volumio kernel: mmcblk0: mmc0:59b4 SD 14.7 GiB Mar 02 20:09:56 volumio kernel: mmcblk0: p1 p2 p3 Mar 02 20:09:56 volumio kernel: random: fast init done Mar 02 20:09:56 volumio kernel: mmc1: new high speed SDIO card at address 0001 Mar 02 20:09:56 volumio kernel: Indeed it is in host mode hprt0 = 00021501 Mar 02 20:09:56 volumio initramfs: Booting Volumio for BCM2835 Mar 02 20:09:56 volumio initramfs: This script mounts rootfs RO with an overlay RW layer. Mar 02 20:09:56 volumio kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Mar 02 20:09:56 volumio kernel: fuse init (API version 7.27) Mar 02 20:09:56 volumio initramfs: IMGPART=/dev/mmcblk0p2 Mar 02 20:09:56 volumio initramfs: IMGFILE=/volumio_current.sqsh Mar 02 20:09:56 volumio initramfs: Boot delay (except first time) will be 5 seconds Mar 02 20:09:56 volumio initramfs: /dev/mmcblk0p2: Mar 02 20:09:56 volumio kernel: EXT4-fs (mmcblk0p2): recovery complete Mar 02 20:09:56 volumio kernel: EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null) Mar 02 20:09:56 volumio initramfs: Doing a 5 second delay here to give kernel load a headstart Mar 02 20:09:56 volumio kernel: usb 1-1: new high-speed USB device number 2 using dwc_otg Mar 02 20:09:56 volumio kernel: Indeed it is in host mode hprt0 = 00001101 Mar 02 20:09:56 volumio kernel: usb 1-1: New USB device found, idVendor=0424, idProduct=2514, bcdDevice= b.b3 Mar 02 20:09:56 volumio kernel: usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Mar 02 20:09:56 volumio kernel: hub 1-1:1.0: USB hub found Mar 02 20:09:56 volumio kernel: hub 1-1:1.0: 4 ports detected Mar 02 20:09:56 volumio kernel: usb 1-1.1: new high-speed USB device number 3 using dwc_otg Mar 02 20:09:56 volumio kernel: usb 1-1.1: New USB device found, idVendor=0424, idProduct=2514, bcdDevice= b.b3 Mar 02 20:09:56 volumio kernel: usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Mar 02 20:09:56 volumio kernel: hub 1-1.1:1.0: USB hub found Mar 02 20:09:56 volumio kernel: hub 1-1.1:1.0: 3 ports detected Mar 02 20:09:56 volumio kernel: usb 1-1.1.1: new high-speed USB device number 4 using dwc_otg Mar 02 20:09:56 volumio kernel: usb 1-1.1.1: New USB device found, idVendor=0424, idProduct=7800, bcdDevice= 3.00 Mar 02 20:09:56 volumio kernel: usb 1-1.1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Mar 02 20:09:56 volumio kernel: lan78xx 1-1.1.1:1.0 (unnamed net_device) (uninitialized): No External EEPROM. Setting MAC Speed Mar 02 20:09:56 volumio kernel: libphy: lan78xx-mdiobus: probed Mar 02 20:09:56 volumio kernel: lan78xx 1-1.1.1:1.0 (unnamed net_device) (uninitialized): int urb period 64 Mar 02 20:09:56 volumio initramfs: Checking for USB updates Mar 02 20:09:56 volumio initramfs: No USB device detected (when incorrect, try adding 'bootdelay=5' to your boot cmdline) Mar 02 20:09:56 volumio kernel: EXT4-fs (mmcblk0p3): recovery complete Mar 02 20:09:56 volumio kernel: EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Opts: (null) Mar 02 20:09:56 volumio initramfs: With Option: Mar 02 20:09:56 volumio initramfs: VOLUMIO_VERSION="2.873" Mar 02 20:09:56 volumio initramfs: Finish initramfs, continue booting Volumio Mar 02 20:09:56 volumio kernel: random: systemd: uninitialized urandom read (16 bytes read) Mar 02 20:09:56 volumio systemd[1]: systemd 215 running in system mode. (+PAM +AUDIT +SELINUX +IMA +SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ -SECCOMP -APPARMOR) Mar 02 20:09:56 volumio systemd[1]: Detected architecture 'arm'. Mar 02 20:09:56 volumio kernel: NET: Registered protocol family 10 Mar 02 20:09:56 volumio kernel: Segment Routing with IPv6 Mar 02 20:09:56 volumio systemd[1]: Inserted module 'ipv6' Mar 02 20:09:56 volumio systemd[1]: Set hostname to . Mar 02 20:09:56 volumio kernel: random: systemd-sysv-ge: uninitialized urandom read (16 bytes read) Mar 02 20:09:56 volumio kernel: random: systemd: uninitialized urandom read (16 bytes read) Mar 02 20:09:56 volumio systemd[1]: [/lib/systemd/system/mpd.service:18] Unknown lvalue 'ProtectKernelTunables' in section 'Service' Mar 02 20:09:56 volumio systemd[1]: [/lib/systemd/system/mpd.service:19] Unknown lvalue 'ProtectControlGroups' in section 'Service' Mar 02 20:09:56 volumio systemd[1]: [/lib/systemd/system/mpd.service:20] Unknown lvalue 'ProtectKernelModules' in section 'Service' Mar 02 20:09:56 volumio systemd[1]: [/lib/systemd/system/mpd.service:23] Unknown lvalue 'RestrictNamespaces' in section 'Service' Mar 02 20:09:56 volumio systemd[1]: Cannot add dependency job for unit display-manager.service, ignoring: Unit display-manager.service failed to load: No such file or directory. Mar 02 20:09:56 volumio systemd[1]: Starting Forward Password Requests to Wall Directory Watch. Mar 02 20:09:56 volumio kernel: i2c /dev entries driver Mar 02 20:09:56 volumio systemd-journal[187]: Journal started Mar 02 20:09:56 volumio systemd[1]: Starting Slices. Mar 02 20:09:56 volumio systemd[1]: Reached target Slices. Mar 02 20:09:56 volumio systemd[1]: Starting Remount Root and Kernel File Systems... Mar 02 20:09:56 volumio systemd[1]: Mounted Debug File System. Mar 02 20:09:56 volumio systemd[1]: Mounted POSIX Message Queue File System. Mar 02 20:09:56 volumio systemd[1]: Started Create list of required static device nodes for the current kernel. Mar 02 20:09:56 volumio systemd[1]: Starting Create Static Device Nodes in /dev... Mar 02 20:09:56 volumio systemd[1]: Time has been changed Mar 02 20:09:56 volumio systemd[1]: Started Restore / save the current clock. Mar 02 20:09:56 volumio systemd[1]: Started Remount Root and Kernel File Systems. Mar 02 20:09:56 volumio systemd[1]: Started Various fixups to make systemd work better on Debian. Mar 02 20:09:56 volumio systemd-modules-load[185]: Inserted module 'i2c_dev' Mar 02 20:09:56 volumio systemd[1]: Started Load Kernel Modules. Mar 02 20:09:56 volumio fake-hwclock[173]: Tue Mar 2 20:09:56 UTC 2021 Mar 02 20:09:56 volumio systemd[1]: Mounting FUSE Control File System... Mar 02 20:09:56 volumio systemd[1]: Mounting Configuration File System... Mar 02 20:09:56 volumio systemd[1]: Starting Apply Kernel Variables... Mar 02 20:09:56 volumio systemd[1]: Starting udev Kernel Device Manager... Mar 02 20:09:56 volumio systemd[1]: Starting Local File Systems (Pre). Mar 02 20:09:56 volumio systemd[1]: Reached target Local File Systems (Pre). Mar 02 20:09:56 volumio systemd[1]: Mounting /tmp... Mar 02 20:09:56 volumio systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Mar 02 20:09:56 volumio systemd[1]: Mounting /var/spool/cups... Mar 02 20:09:56 volumio systemd[1]: Mounting /var/log... Mar 02 20:09:56 volumio systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Mar 02 20:09:56 volumio systemd[1]: Mounted Configuration File System. Mar 02 20:09:56 volumio systemd[1]: Mounted FUSE Control File System. Mar 02 20:09:56 volumio systemd[1]: Mounted /var/spool/cups. Mar 02 20:09:56 volumio systemd[1]: Mounted /tmp. Mar 02 20:09:56 volumio systemd[1]: Started udev Kernel Device Manager. Mar 02 20:09:56 volumio systemd[1]: Started Apply Kernel Variables. Mar 02 20:09:56 volumio systemd[1]: Mounted /var/log. Mar 02 20:09:56 volumio systemd-udevd[213]: starting version 215 Mar 02 20:09:56 volumio systemd[1]: Starting Show Plymouth Boot Screen... Mar 02 20:09:56 volumio systemd[1]: Starting Copy rules generated while the root was ro... Mar 02 20:09:56 volumio systemd[1]: Mounting /var/spool/cups/tmp... Mar 02 20:09:56 volumio systemd[1]: Started Copy rules generated while the root was ro. Mar 02 20:09:56 volumio systemd[1]: Mounted /var/spool/cups/tmp. Mar 02 20:09:56 volumio systemd[1]: Started Show Plymouth Boot Screen. Mar 02 20:09:56 volumio systemd[1]: Starting Forward Password Requests to Plymouth Directory Watch. Mar 02 20:09:56 volumio systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Mar 02 20:09:56 volumio systemd[1]: Started Dispatch Password Requests to Console Directory Watch. Mar 02 20:09:56 volumio systemd[1]: Starting Paths. Mar 02 20:09:56 volumio systemd[1]: Reached target Paths. Mar 02 20:09:56 volumio kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Mar 02 20:09:56 volumio kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Mar 02 20:09:56 volumio kernel: [vc_sm_connected_init]: start Mar 02 20:09:56 volumio kernel: [vc_sm_connected_init]: installed successfully Mar 02 20:09:56 volumio kernel: media: Linux media interface: v0.10 Mar 02 20:09:56 volumio kernel: videodev: Linux video capture interface: v2.00 Mar 02 20:09:57 volumio kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Mar 02 20:09:57 volumio kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Mar 02 20:09:57 volumio kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Mar 02 20:09:57 volumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Mar 02 20:09:57 volumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Mar 02 20:09:57 volumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Mar 02 20:09:57 volumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Mar 02 20:09:57 volumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Mar 02 20:09:57 volumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Mar 02 20:09:57 volumio kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Mar 02 20:09:57 volumio kernel: snd_bcm2835: unknown parameter 'index' ignored Mar 02 20:09:57 volumio kernel: bcm2835_audio soc:audio: card created with 5 channels Mar 02 20:09:57 volumio kernel: bcm2835_audio soc:audio: card created with 3 channels Mar 02 20:09:57 volumio systemd[1]: Found device /dev/mmcblk0p1. Mar 02 20:09:57 volumio systemd[1]: Starting File System Check on /dev/mmcblk0p1... Mar 02 20:09:57 volumio kernel: snd-rpi-hifiberry-dacplus soc:sound: ASoC: CODEC DAI pcm512x-hifi not registered - will retry Mar 02 20:09:57 volumio systemd[1]: Starting Sound Card. Mar 02 20:09:57 volumio systemd[1]: Reached target Sound Card. Mar 02 20:09:57 volumio kernel: pcm512x 1-004d: Linked as a consumer to regulator.1 Mar 02 20:09:57 volumio kernel: snd-rpi-hifiberry-dacplus soc:sound: pcm512x-hifi <-> 3f203000.i2s mapping ok Mar 02 20:09:57 volumio kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Mar 02 20:09:57 volumio kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Mar 02 20:09:57 volumio kernel: platform regulatory.0: Direct firmware load for regulatory.db failed with error -2 Mar 02 20:09:57 volumio kernel: cfg80211: failed to load regulatory.db Mar 02 20:09:57 volumio systemd[1]: Starting system-ifup.slice. Mar 02 20:09:57 volumio systemd[1]: Created slice system-ifup.slice. Mar 02 20:09:57 volumio systemd-fsck[326]: fsck.fat 3.0.27 (2014-11-12) Mar 02 20:09:57 volumio systemd-fsck[326]: /dev/mmcblk0p1: 245 files, 116276/123044 clusters Mar 02 20:09:57 volumio systemd[1]: Started File System Check on /dev/mmcblk0p1. Mar 02 20:09:57 volumio systemd[1]: Mounting /boot... Mar 02 20:09:57 volumio kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Mar 02 20:09:57 volumio kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Mar 02 20:09:57 volumio kernel: usbcore: registered new interface driver brcmfmac Mar 02 20:09:57 volumio systemd[1]: Mounted /boot. Mar 02 20:09:57 volumio systemd[1]: Starting Local File Systems. Mar 02 20:09:57 volumio systemd[1]: Reached target Local File Systems. Mar 02 20:09:57 volumio systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Mar 02 20:09:57 volumio systemd[1]: Starting Remote File Systems. Mar 02 20:09:57 volumio systemd[1]: Reached target Remote File Systems. Mar 02 20:09:57 volumio systemd[1]: Starting Trigger Flushing of Journal to Persistent Storage... Mar 02 20:09:57 volumio systemd[1]: Starting Create Volatile Files and Directories... Mar 02 20:09:57 volumio systemd[1]: Starting LSB: Raise network interfaces.... Mar 02 20:09:57 volumio systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Mar 02 20:09:58 volumio systemd[1]: Started Create Volatile Files and Directories. Mar 02 20:09:58 volumio systemd[1]: Started Trigger Flushing of Journal to Persistent Storage. Mar 02 20:09:58 volumio systemd[1]: Starting Update UTMP about System Boot/Shutdown... Mar 02 20:09:58 volumio systemd[1]: Started Update UTMP about System Boot/Shutdown. Mar 02 20:09:58 volumio kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Mar 02 20:09:58 volumio kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Mar 2 2020 23:30:41 version 7.45.202 (r724630 CY) FWID 01-72f6ece2 Mar 02 20:09:58 volumio systemd[1]: Starting system-systemd\x2drfkill.slice. Mar 02 20:09:58 volumio systemd[1]: Created slice system-systemd\x2drfkill.slice. Mar 02 20:09:58 volumio systemd[1]: Starting Load/Save RF Kill Switch Status of rfkill0... Mar 02 20:09:58 volumio systemd[1]: Started Load/Save RF Kill Switch Status of rfkill0. Mar 02 20:09:59 volumio kernel: random: crng init done Mar 02 20:09:59 volumio kernel: random: 7 urandom warning(s) missed due to ratelimiting Mar 02 20:09:59 volumio systemd[1]: Received SIGRTMIN+20 from PID 242 (plymouthd). Mar 02 20:09:59 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Mar 02 20:09:59 volumio networking[366]: Configuring network interfaces...done. Mar 02 20:09:59 volumio systemd[1]: Started LSB: Raise network interfaces.. Mar 02 20:09:59 volumio systemd[1]: Starting ifup for wlan0... Mar 02 20:09:59 volumio systemd[1]: Started ifup for wlan0. Mar 02 20:09:59 volumio systemd[1]: Starting ifup for eth0... Mar 02 20:09:59 volumio ifup[509]: /sbin/ifup: interface wlan0 already configured Mar 02 20:09:59 volumio systemd[1]: Started ifup for eth0. Mar 02 20:09:59 volumio systemd[1]: Starting Network. Mar 02 20:09:59 volumio systemd[1]: Reached target Network. Mar 02 20:09:59 volumio systemd[1]: Starting Network is Online. Mar 02 20:09:59 volumio systemd[1]: Reached target Network is Online. Mar 02 20:09:59 volumio systemd[1]: Starting LSB: RPC portmapper replacement... Mar 02 20:10:00 volumio rpcbind[514]: Starting rpcbind daemon.... Mar 02 20:10:00 volumio systemd[1]: Started LSB: RPC portmapper replacement. Mar 02 20:10:00 volumio systemd[1]: Starting RPC Port Mapper. Mar 02 20:10:00 volumio systemd[1]: Reached target RPC Port Mapper. Mar 02 20:10:00 volumio systemd[1]: Starting LSB: NFS support files common to client and server... Mar 02 20:10:00 volumio rpc.statd[586]: Version 1.2.8 starting Mar 02 20:10:00 volumio sm-notify[587]: Version 1.2.8 starting Mar 02 20:10:00 volumio kernel: Installing knfsd (copyright (C) 1996 okir@monad.swb.de). Mar 02 20:10:00 volumio nfs-common[580]: Starting NFS common utilities: statd idmapd. Mar 02 20:10:00 volumio systemd[1]: Started LSB: NFS support files common to client and server. Mar 02 20:10:00 volumio systemd[1]: Starting System Initialization. Mar 02 20:10:00 volumio systemd[1]: Reached target System Initialization. Mar 02 20:10:00 volumio systemd[1]: Starting Avahi mDNS/DNS-SD Stack Activation Socket. Mar 02 20:10:00 volumio systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Mar 02 20:10:00 volumio systemd[1]: Starting mpd.socket. Mar 02 20:10:00 volumio systemd[1]: Listening on mpd.socket. Mar 02 20:10:00 volumio systemd[1]: Starting D-Bus System Message Bus Socket. Mar 02 20:10:00 volumio systemd[1]: Listening on D-Bus System Message Bus Socket. Mar 02 20:10:00 volumio systemd[1]: Starting Sockets. Mar 02 20:10:00 volumio systemd[1]: Reached target Sockets. Mar 02 20:10:00 volumio systemd[1]: Starting Daily Cleanup of Temporary Directories. Mar 02 20:10:00 volumio systemd[1]: Started Daily Cleanup of Temporary Directories. Mar 02 20:10:00 volumio systemd[1]: Starting Timers. Mar 02 20:10:00 volumio systemd[1]: Reached target Timers. Mar 02 20:10:00 volumio systemd[1]: Started Manage Sound Card State (restore and store). Mar 02 20:10:00 volumio systemd[1]: Starting Restore Sound Card State... Mar 02 20:10:00 volumio systemd[1]: Starting Basic System. Mar 02 20:10:00 volumio systemd[1]: Reached target Basic System. Mar 02 20:10:00 volumio systemd[1]: Starting Entropy daemon using the HAVEGE algorithm... Mar 02 20:10:00 volumio systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Mar 02 20:10:00 volumio systemd[1]: Starting Configure Bluetooth Modems connected by UART... Mar 02 20:10:00 volumio systemd[1]: Starting Volumio Iptables Module... Mar 02 20:10:00 volumio systemd[1]: Started Volumio Iptables Module. Mar 02 20:10:00 volumio systemd[1]: Starting mount disks automatically with standby... Mar 02 20:10:00 volumio systemd[1]: Started mount disks automatically with standby. Mar 02 20:10:00 volumio systemd[1]: Starting UPnP Renderer front-end to MPD... Mar 02 20:10:00 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Mar 02 20:10:00 volumio systemd[1]: Starting volumio-remote-updater.service... Mar 02 20:10:00 volumio systemd[1]: Started volumio-remote-updater.service. Mar 02 20:10:00 volumio systemd[1]: Starting Volumio Log Rotation Service... Mar 02 20:10:00 volumio systemd[1]: Started Volumio Log Rotation Service. Mar 02 20:10:00 volumio systemd[1]: Starting Volumio SSH enabler... Mar 02 20:10:00 volumio systemd[1]: Started Volumio SSH enabler. Mar 02 20:10:00 volumio systemd[1]: Starting Wireless Services... Mar 02 20:10:00 volumio systemd[1]: Starting OpenBSD Secure Shell server... Mar 02 20:10:00 volumio systemd[1]: Starting /etc/rc.local Compatibility... Mar 02 20:10:00 volumio systemd[1]: Started getty on tty2-tty6 if dbus and logind are not available. Mar 02 20:10:00 volumio systemd[1]: Starting Login Service... Mar 02 20:10:01 volumio systemd[1]: Starting LSB: start Winbind daemon... Mar 02 20:10:01 volumio systemd[1]: Starting LSB: triggerhappy hotkey daemon... Mar 02 20:10:01 volumio systemd[1]: Starting LSB: start Samba daemons for the AD DC... Mar 02 20:10:01 volumio systemd[1]: Starting LSB: Start NTP daemon... Mar 02 20:10:01 volumio systemd[1]: Starting LSB: start Samba NetBIOS nameserver (nmbd)... Mar 02 20:10:01 volumio kernel: uart-pl011 3f201000.serial: no DMA platform data Mar 02 20:10:01 volumio systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Mar 02 20:10:01 volumio systemd[1]: Starting LSB: Brings up/down network automatically... Mar 02 20:10:01 volumio systemd[1]: Starting LSB: Advanced IEEE 802.11 management daemon... Mar 02 20:10:01 volumio systemd[1]: Starting LSB: IPv4 DHCP client with IPv4LL support... Mar 02 20:10:01 volumio systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Mar 02 20:10:01 volumio systemd[1]: Starting Music Player Daemon... Mar 02 20:10:01 volumio systemd[1]: Starting D-Bus System Message Bus... Mar 02 20:10:01 volumio systemd[1]: Started D-Bus System Message Bus. Mar 02 20:10:01 volumio btuart[601]: Patch not found for BCM4345C0, continue anyway Mar 02 20:10:01 volumio triggerhappy[637]: Unable to parse trigger line: Mar 02 20:10:01 volumio triggerhappy[637]: Unable to parse trigger line: Mar 02 20:10:01 volumio triggerhappy[637]: Unable to parse trigger line: Mar 02 20:10:01 volumio triggerhappy[637]: Unable to parse trigger line: Mar 02 20:10:01 volumio triggerhappy[637]: Unable to parse trigger line: Mar 02 20:10:01 volumio triggerhappy[637]: Unable to parse trigger line: Mar 02 20:10:01 volumio triggerhappy[637]: Unable to parse trigger line: Mar 02 20:10:01 volumio triggerhappy[637]: Error opening '/dev/input/event*': No such file or directory Mar 02 20:10:01 volumio ifplugd(eth0)[716]: ifplugd 0.28 initializing. Mar 02 20:10:01 volumio ifplugd(eth0)[716]: Using interface eth0/B8:27:EB:8E:AC:1F with driver (version: ) Mar 02 20:10:01 volumio dhcpcd[712]: version 6.0.5 starting Mar 02 20:10:01 volumio dhcpcd[660]: dhcpcd[712]: version 6.0.5 starting Mar 02 20:10:01 volumio ifplugd(eth0)[716]: Using detection mode: SIOCETHTOOL Mar 02 20:10:01 volumio ifplugd(eth0)[716]: Initialization complete, link beat detected. Mar 02 20:10:01 volumio ifplugd(eth0)[716]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Mar 02 20:10:01 volumio loadcpufreq[647]: Loading cpufreq kernel modules...done (none). Mar 02 20:10:01 volumio ifplugd(eth0)[716]: client: /sbin/ifup: interface eth0 already configured Mar 02 20:10:01 volumio ifplugd(eth0)[716]: Program executed successfully. Mar 02 20:10:01 volumio ifplugd[649]: Network Interface Plugging Daemon...start eth0...done. Mar 02 20:10:01 volumio dhcpcd[712]: `undefined' is not a valid IP address Mar 02 20:10:01 volumio dhcpcd[660]: dhcpcd[712]: `undefined' is not a valid IP address Mar 02 20:10:01 volumio kernel: Bluetooth: Core ver 2.22 Mar 02 20:10:01 volumio kernel: NET: Registered protocol family 31 Mar 02 20:10:01 volumio kernel: Bluetooth: HCI device and connection manager initialized Mar 02 20:10:01 volumio kernel: Bluetooth: HCI socket layer initialized Mar 02 20:10:01 volumio kernel: Bluetooth: L2CAP socket layer initialized Mar 02 20:10:01 volumio kernel: Bluetooth: SCO socket layer initialized Mar 02 20:10:01 volumio avahi-daemon[668]: Found user 'avahi' (UID 104) and group 'avahi' (GID 106). Mar 02 20:10:01 volumio avahi-daemon[668]: Successfully dropped root privileges. Mar 02 20:10:01 volumio avahi-daemon[668]: avahi-daemon 0.6.31 starting up. Mar 02 20:10:01 volumio dhcpcd[712]: eth0: soliciting an IPv6 router Mar 02 20:10:01 volumio dhcpcd[660]: dhcpcd[712]: eth0: soliciting an IPv6 router Mar 02 20:10:01 volumio dhcpcd[712]: eth0: using static address 192.168.0.22 Mar 02 20:10:01 volumio dhcpcd[712]: eth0: adding host route to 192.168.0.22 via 127.0.0.1 Mar 02 20:10:01 volumio dhcpcd[712]: eth0: adding route to 192.168.0.0/24 Mar 02 20:10:01 volumio dhcpcd[712]: eth0: adding default route via 192.168.0.1 Mar 02 20:10:01 volumio dhcpcd[660]: dhcpcd[712]: eth0: using static address 192.168.0.22 Mar 02 20:10:01 volumio dhcpcd[660]: dhcpcd[712]: eth0: adding host route to 192.168.0.22 via 127.0.0.1 Mar 02 20:10:01 volumio dhcpcd[660]: dhcpcd[712]: eth0: adding route to 192.168.0.0/24 Mar 02 20:10:01 volumio dhcpcd[660]: dhcpcd[712]: eth0: adding default route via 192.168.0.1 Mar 02 20:10:01 volumio kernel: Bluetooth: HCI UART driver ver 2.3 Mar 02 20:10:01 volumio kernel: Bluetooth: HCI UART protocol H4 registered Mar 02 20:10:01 volumio kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Mar 02 20:10:01 volumio kernel: Bluetooth: HCI UART protocol Broadcom registered Mar 02 20:10:01 volumio btuart[601]: bcm43xx_init Mar 02 20:10:01 volumio btuart[601]: Set BDADDR UART: b8:27:eb:24:06:b5 Mar 02 20:10:01 volumio btuart[601]: Set Controller UART speed to 3000000 bit/s Mar 02 20:10:01 volumio btuart[601]: Device setup complete Mar 02 20:10:01 volumio systemd-udevd[780]: failed to execute '/usr/bin/hciconfig' '/usr/bin/hciconfig hci0 up': No such file or directory Mar 02 20:10:02 volumio avahi-daemon[668]: Successfully called chroot(). Mar 02 20:10:02 volumio avahi-daemon[668]: Successfully dropped remaining capabilities. Mar 02 20:10:02 volumio systemd[1]: Started Avahi mDNS/DNS-SD Stack. Mar 02 20:10:02 volumio systemd[1]: Starting Permit User Sessions... Mar 02 20:10:02 volumio avahi-daemon[668]: No service file found in /etc/avahi/services. Mar 02 20:10:02 volumio sudo[635]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 set power_save off Mar 02 20:10:02 volumio systemd[1]: Started Restore Sound Card State. Mar 02 20:10:02 volumio avahi-daemon[668]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.0.22. Mar 02 20:10:02 volumio avahi-daemon[668]: New relevant interface eth0.IPv4 for mDNS. Mar 02 20:10:02 volumio avahi-daemon[668]: Network interface enumeration completed. Mar 02 20:10:02 volumio avahi-daemon[668]: Registering new address record for 192.168.0.22 on eth0.IPv4. Mar 02 20:10:02 volumio systemd[1]: Started Configure Bluetooth Modems connected by UART. Mar 02 20:10:02 volumio systemd[1]: Started OpenBSD Secure Shell server. Mar 02 20:10:02 volumio systemd[1]: Started /etc/rc.local Compatibility. Mar 02 20:10:02 volumio systemd[1]: Started LSB: triggerhappy hotkey daemon. Mar 02 20:10:02 volumio systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Mar 02 20:10:02 volumio systemd[1]: Started LSB: Brings up/down network automatically. Mar 02 20:10:02 volumio systemd[1]: Started LSB: Advanced IEEE 802.11 management daemon. Mar 02 20:10:02 volumio systemd[1]: Started Permit User Sessions. Mar 02 20:10:02 volumio systemd[1]: Started LSB: Start NTP daemon. Mar 02 20:10:02 volumio avahi-daemon[668]: Registering HINFO record with values 'ARMV7L'/'LINUX'. Mar 02 20:10:02 volumio ntpd[726]: ntpd 4.2.6p5@1.2349-o Mon Jul 25 22:35:28 UTC 2016 (1) Mar 02 20:10:02 volumio ntpd[793]: proto: precision = 1.094 usec Mar 02 20:10:02 volumio ntpd[793]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123 Mar 02 20:10:02 volumio dbus[676]: [system] Activating via systemd: service name='org.freedesktop.UDisks' unit='udisks.service' Mar 02 20:10:02 volumio ntpd[793]: Listen and drop on 1 v6wildcard :: UDP 123 Mar 02 20:10:02 volumio ntpd[793]: Listen normally on 2 lo 127.0.0.1 UDP 123 Mar 02 20:10:02 volumio ntpd[793]: Listen normally on 3 eth0 192.168.0.22 UDP 123 Mar 02 20:10:02 volumio ntpd[793]: peers refreshed Mar 02 20:10:02 volumio ntpd[793]: Listening on routing socket on fd #20 for interface updates Mar 02 20:10:02 volumio sshd[790]: Server listening on 0.0.0.0 port 22. Mar 02 20:10:02 volumio sshd[790]: Server listening on :: port 22. Mar 02 20:10:02 volumio ntp[645]: Starting NTP server: ntpd. Mar 02 20:10:02 volumio sudo[635]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 20:10:02 volumio sudo[635]: pam_unix(sudo:session): session closed for user root Mar 02 20:10:02 volumio dhcpcd[712]: forked to background, child pid 809 Mar 02 20:10:02 volumio dhcpcd[809]: wlan0: waiting for carrier Mar 02 20:10:02 volumio dhcpcd[660]: dhcpcd[712]: forked to background, child pid 809 Mar 02 20:10:02 volumio systemd[1]: Started LSB: IPv4 DHCP client with IPv4LL support. Mar 02 20:10:02 volumio systemd-logind[629]: New seat seat0. Mar 02 20:10:02 volumio systemd[1]: Started Login Service. Mar 02 20:10:02 volumio systemd[1]: Starting Disk Manager (legacy version)... Mar 02 20:10:02 volumio systemd[1]: Starting Load/Save RF Kill Switch Status of rfkill1... Mar 02 20:10:02 volumio systemd[1]: Starting Bluetooth service... Mar 02 20:10:02 volumio systemd[1]: Starting LSB: set CPUFreq kernel parameters... Mar 02 20:10:02 volumio systemd[1]: Starting Hold until boot process finishes up... Mar 02 20:10:02 volumio systemd[1]: Starting Terminate Plymouth Boot Screen... Mar 02 20:10:02 volumio systemd[1]: Started Load/Save RF Kill Switch Status of rfkill1. Mar 02 20:10:02 volumio systemd[1]: Received SIGRTMIN+21 from PID 242 (plymouthd). Mar 02 20:10:02 volumio systemd[1]: Started Hold until boot process finishes up. Mar 02 20:10:02 volumio systemd[1]: Started Terminate Plymouth Boot Screen. Mar 02 20:10:02 volumio systemd[1]: Starting Getty on tty1... Mar 02 20:10:02 volumio systemd[1]: Started Getty on tty1. Mar 02 20:10:02 volumio systemd[1]: Starting Login Prompts. Mar 02 20:10:02 volumio systemd[1]: Reached target Login Prompts. Mar 02 20:10:02 volumio bluetoothd[817]: Bluetooth daemon 5.23 Mar 02 20:10:02 volumio dbus[676]: [system] Successfully activated service 'org.freedesktop.UDisks' Mar 02 20:10:02 volumio cpufrequtils[818]: CPUFreq Utilities: Setting performance CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Mar 02 20:10:02 volumio systemd[1]: Started LSB: set CPUFreq kernel parameters. Mar 02 20:10:02 volumio systemd[1]: Started Disk Manager (legacy version). Mar 02 20:10:02 volumio systemd[1]: Started Bluetooth service. Mar 02 20:10:02 volumio systemd[1]: Starting Bluetooth. Mar 02 20:10:02 volumio systemd[1]: Reached target Bluetooth. Mar 02 20:10:02 volumio bluetoothd[817]: Starting SDP server Mar 02 20:10:02 volumio bluetoothd[817]: Excluding (cli) sap Mar 02 20:10:02 volumio dbus[676]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' Mar 02 20:10:02 volumio bluetoothd[817]: Bluetooth management interface 1.14 initialized Mar 02 20:10:02 volumio kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Mar 02 20:10:02 volumio kernel: Bluetooth: BNEP filters: protocol multicast Mar 02 20:10:02 volumio kernel: Bluetooth: BNEP socket layer initialized Mar 02 20:10:02 volumio systemd[1]: Starting Hostname Service... Mar 02 20:10:03 volumio volumio-remote-updater[608]: Error: No active session Mar 02 20:10:03 volumio volumio-remote-updater[608]: [2021-03-02 20:10:03] [info] asio async_connect error: system:111 (Connection refused) Mar 02 20:10:03 volumio volumio-remote-updater[608]: [2021-03-02 20:10:03] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Mar 02 20:10:03 volumio volumio-remote-updater[608]: [2021-03-02 20:10:03] [error] handle_connect error: Underlying Transport Error Mar 02 20:10:03 volumio dbus[676]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkitd.service' Mar 02 20:10:03 volumio avahi-daemon[668]: Server startup complete. Host name is volumio.local. Local service cookie is 1127004608. Mar 02 20:10:03 volumio systemd[1]: Starting Authenticate and Authorize Users to Run Privileged Tasks... Mar 02 20:10:03 volumio systemd-hostnamed[839]: Warning: nss-myhostname is not installed. Changing the local hostname might make it unresolveable. Please install nss-myhostname! Mar 02 20:10:03 volumio dbus[676]: [system] Successfully activated service 'org.freedesktop.hostname1' Mar 02 20:10:03 volumio systemd[1]: Started Hostname Service. Mar 02 20:10:03 volumio polkitd[843]: started daemon version 0.105 using authority implementation `local' version `0.105' Mar 02 20:10:03 volumio dbus[676]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Mar 02 20:10:03 volumio systemd[1]: Started Authenticate and Authorize Users to Run Privileged Tasks. Mar 02 20:10:03 volumio udisks-glue[603]: Device file /dev/mmcblk0 inserted Mar 02 20:10:03 volumio udisks-glue[603]: Device file /dev/mmcblk0p3 inserted Mar 02 20:10:03 volumio volumio[604]: Could not open config: /tmp/upmpdcli.conf Mar 02 20:10:03 volumio systemd[1]: upmpdcli.service: main process exited, code=exited, status=1/FAILURE Mar 02 20:10:03 volumio systemd[1]: Unit upmpdcli.service entered failed state. Mar 02 20:10:03 volumio haveged[600]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 4.8.2 CTV); collect: 128K Mar 02 20:10:03 volumio haveged[600]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 8/40; sz: 15248/74244 Mar 02 20:10:03 volumio haveged[600]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 8.00012 Mar 02 20:10:03 volumio haveged[600]: haveged: fills: 0, generated: 0 Mar 02 20:10:05 volumio wireless.js[813]: Cleaning previous... Mar 02 20:10:05 volumio systemd[1]: Stopped hotspot.service. Mar 02 20:10:05 volumio sudo[866]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Mar 02 20:10:05 volumio sudo[866]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 20:10:05 volumio sudo[866]: pam_unix(sudo:session): session closed for user root Mar 02 20:10:05 volumio sudo[874]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Mar 02 20:10:05 volumio sudo[874]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 20:10:05 volumio systemd[1]: Started LSB: start Samba daemons for the AD DC. Mar 02 20:10:05 volumio winbind[633]: Starting the Winbind daemon: winbindmkdir failed on directory /var/log/samba/cores: No such file or directory Mar 02 20:10:05 volumio winbind[633]: Failed to create /var/log/samba/cores for user 0 with mode 0700 Mar 02 20:10:05 volumio winbind[633]: Unable to setup corepath for winbindd: No such file or directory Mar 02 20:10:05 volumio winbind[633]: mkdir failed on directory /var/log/samba/cores: No such file or directory Mar 02 20:10:05 volumio winbind[633]: Failed to create /var/log/samba/cores for user 0 with mode 0700 Mar 02 20:10:05 volumio winbind[633]: Unable to setup corepath for winbindd: No such file or directory Mar 02 20:10:05 volumio winbind[633]: [2021/03/02 20:10:05, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:05 volumio winbind[633]: Unable to open new log file '/var/log/samba/log.winbindd': No such file or directory Mar 02 20:10:05 volumio winbind[633]: [2021/03/02 20:10:05, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:05 volumio winbind[633]: Unable to open new log file '/var/log/samba/log.winbindd': No such file or directory Mar 02 20:10:05 volumio winbind[633]: [2021/03/02 20:10:05, 0] ../source3/winbindd/winbindd.c:1549(main) Mar 02 20:10:05 volumio winbind[633]: winbindd version 4.2.14-Debian started. Mar 02 20:10:05 volumio winbind[633]: Copyright Andrew Tridgell and the Samba Team 1992-2014 Mar 02 20:10:05 volumio winbind[633]: [2021/03/02 20:10:05, 0] ../lib/util/util.c:220(directory_create_or_exist) Mar 02 20:10:05 volumio winbind[633]: mkdir failed on directory /var/log/samba/cores: No such file or directory Mar 02 20:10:05 volumio winbind[633]: [2021/03/02 20:10:05, 0] ../source3/lib/dumpcore.c:59(get_default_corepath) Mar 02 20:10:05 volumio winbind[633]: Failed to create /var/log/samba/cores for user 0 with mode 0700 Mar 02 20:10:05 volumio winbind[633]: [2021/03/02 20:10:05, 0] ../source3/lib/dumpcore.c:250(dump_core_setup) Mar 02 20:10:05 volumio winbind[633]: Unable to setup corepath for winbindd: No such file or directory Mar 02 20:10:05 volumio winbindd[887]: [2021/03/02 20:10:05.945714, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:05 volumio winbindd[887]: Unable to open new log file '/var/log/samba/log.winbindd': No such file or directory Mar 02 20:10:05 volumio winbindd[887]: [2021/03/02 20:10:05.946556, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:05 volumio winbindd[887]: Unable to open new log file '/var/log/samba/log.winbindd': No such file or directory Mar 02 20:10:05 volumio winbind[633]: [2021/03/02 20:10:05.945714, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:05 volumio winbind[633]: Unable to open new log file '/var/log/samba/log.winbindd': No such file or directory Mar 02 20:10:05 volumio winbind[633]: [2021/03/02 20:10:05.946556, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:05 volumio winbind[633]: Unable to open new log file '/var/log/samba/log.winbindd': No such file or directory Mar 02 20:10:05 volumio nmbd[646]: Starting NetBIOS name server: nmbdmkdir failed on directory /var/log/samba/cores: No such file or directory Mar 02 20:10:05 volumio nmbd[646]: Failed to create /var/log/samba/cores for user 0 with mode 0700 Mar 02 20:10:05 volumio nmbd[646]: Unable to setup corepath for nmbd: No such file or directory Mar 02 20:10:05 volumio nmbd[890]: [2021/03/02 20:10:05.956148, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:05 volumio nmbd[890]: Unable to open new log file '/var/log/samba/log.nmbd': No such file or directory Mar 02 20:10:05 volumio nmbd[890]: [2021/03/02 20:10:05.957462, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:05 volumio nmbd[890]: Unable to open new log file '/var/log/samba/log.nmbd': No such file or directory Mar 02 20:10:05 volumio nmbd[646]: [2021/03/02 20:10:05, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:05 volumio nmbd[646]: Unable to open new log file '/var/log/samba/log.nmbd': No such file or directory Mar 02 20:10:05 volumio nmbd[646]: [2021/03/02 20:10:05, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:05 volumio nmbd[646]: Unable to open new log file '/var/log/samba/log.nmbd': No such file or directory Mar 02 20:10:05 volumio nmbd[646]: [2021/03/02 20:10:05, 0] ../source3/nmbd/nmbd.c:908(main) Mar 02 20:10:05 volumio nmbd[646]: nmbd version 4.2.14-Debian started. Mar 02 20:10:05 volumio nmbd[646]: Copyright Andrew Tridgell and the Samba Team 1992-2014 Mar 02 20:10:05 volumio nmbd[646]: [2021/03/02 20:10:05.956148, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:05 volumio nmbd[646]: Unable to open new log file '/var/log/samba/log.nmbd': No such file or directory Mar 02 20:10:05 volumio nmbd[646]: [2021/03/02 20:10:05.957462, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:05 volumio nmbd[646]: Unable to open new log file '/var/log/samba/log.nmbd': No such file or directory Mar 02 20:10:05 volumio nmbd[891]: [2021/03/02 20:10:05.960460, 0] ../source3/nmbd/asyncdns.c:157(start_async_dns) Mar 02 20:10:05 volumio nmbd[891]: started asyncdns process 892 Mar 02 20:10:05 volumio systemd[1]: Started LSB: start Samba NetBIOS nameserver (nmbd). Mar 02 20:10:05 volumio systemd[1]: Starting LSB: start Samba SMB/CIFS daemon (smbd)... Mar 02 20:10:05 volumio nmbd[646]: . Mar 02 20:10:06 volumio sudo[874]: pam_unix(sudo:session): session closed for user root Mar 02 20:10:06 volumio nmbd[891]: [2021/03/02 20:10:06.062572, 0] ../lib/util/become_daemon.c:124(daemon_ready) Mar 02 20:10:06 volumio nmbd[891]: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Mar 02 20:10:06 volumio winbind[633]: . Mar 02 20:10:06 volumio systemd[1]: Started LSB: start Winbind daemon. Mar 02 20:10:06 volumio winbindd[906]: [2021/03/02 20:10:06.084708, 0] ../source3/winbindd/winbindd_cache.c:3235(initialize_winbindd_cache) Mar 02 20:10:06 volumio winbindd[906]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Mar 02 20:10:06 volumio systemd[1]: Started Music Player Daemon. Mar 02 20:10:06 volumio winbindd[906]: [2021/03/02 20:10:06.120996, 0] ../lib/util/become_daemon.c:124(daemon_ready) Mar 02 20:10:06 volumio winbindd[906]: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Mar 02 20:10:06 volumio winbindd[910]: [2021/03/02 20:10:06.125224, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:06 volumio winbindd[910]: Unable to open new log file '/var/log/samba/log.wb-VOLUMIO': No such file or directory Mar 02 20:10:06 volumio wireless.js[813]: Stopped aP Mar 02 20:10:06 volumio wireless.js[813]: Wireless Networking DISABLED, not starting wireless flow Mar 02 20:10:06 volumio systemd[1]: Started Wireless Services. Mar 02 20:10:06 volumio systemd[1]: Starting Volumio Backend Module... Mar 02 20:10:06 volumio systemd[1]: Started Volumio Backend Module. Mar 02 20:10:06 volumio systemd[1]: Starting Volumio Streaming Daemon... Mar 02 20:10:06 volumio systemd[1]: Started Volumio Streaming Daemon. Mar 02 20:10:06 volumio volumio-streaming-daemon[915]: ############################ Mar 02 20:10:06 volumio volumio-streaming-daemon[915]: # Volumio Streaming Daemon # Mar 02 20:10:06 volumio volumio-streaming-daemon[915]: # Running on port 7777 # Mar 02 20:10:06 volumio volumio-streaming-daemon[915]: ############################ Mar 02 20:10:06 volumio volumio-streaming-daemon[915]: Environment: production Mar 02 20:10:06 volumio smbd[893]: Starting SMB/CIFS daemon: smbd[2021/03/02 20:10:06, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:06 volumio smbd[893]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Mar 02 20:10:06 volumio smbd[893]: [2021/03/02 20:10:06, 0] ../lib/util/util.c:220(directory_create_or_exist) Mar 02 20:10:06 volumio smbd[893]: mkdir failed on directory /var/log/samba/cores: No such file or directory Mar 02 20:10:06 volumio smbd[893]: [2021/03/02 20:10:06, 0] ../source3/lib/dumpcore.c:59(get_default_corepath) Mar 02 20:10:06 volumio smbd[893]: Failed to create /var/log/samba/cores for user 0 with mode 0700 Mar 02 20:10:06 volumio smbd[893]: [2021/03/02 20:10:06, 0] ../source3/lib/dumpcore.c:250(dump_core_setup) Mar 02 20:10:06 volumio smbd[893]: Unable to setup corepath for smbd: No such file or directory Mar 02 20:10:06 volumio smbd[893]: [2021/03/02 20:10:06, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:06 volumio smbd[893]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Mar 02 20:10:06 volumio smbd[893]: [2021/03/02 20:10:06, 0] ../source3/smbd/server.c:1241(main) Mar 02 20:10:06 volumio smbd[893]: smbd version 4.2.14-Debian started. Mar 02 20:10:06 volumio smbd[893]: Copyright Andrew Tridgell and the Samba Team 1992-2014 Mar 02 20:10:06 volumio smbd[929]: [2021/03/02 20:10:06.829103, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:06 volumio smbd[929]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Mar 02 20:10:06 volumio smbd[929]: [2021/03/02 20:10:06.830493, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:06 volumio smbd[929]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Mar 02 20:10:06 volumio smbd[929]: [2021/03/02 20:10:06.830742, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:06 volumio smbd[929]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Mar 02 20:10:06 volumio smbd[893]: [2021/03/02 20:10:06.829103, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:06 volumio smbd[893]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Mar 02 20:10:06 volumio smbd[893]: [2021/03/02 20:10:06.830493, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:06 volumio smbd[893]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Mar 02 20:10:06 volumio smbd[893]: [2021/03/02 20:10:06.830742, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:06 volumio smbd[893]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Mar 02 20:10:06 volumio smbd[893]: . Mar 02 20:10:06 volumio systemd[1]: Started LSB: start Samba SMB/CIFS daemon (smbd). Mar 02 20:10:06 volumio systemd[1]: Starting Multi-User System. Mar 02 20:10:06 volumio systemd[1]: Reached target Multi-User System. Mar 02 20:10:06 volumio systemd[1]: Starting Graphical Interface. Mar 02 20:10:06 volumio systemd[1]: Reached target Graphical Interface. Mar 02 20:10:06 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Mar 02 20:10:06 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Mar 02 20:10:06 volumio systemd[1]: Startup finished in 9.487s (kernel) + 11.603s (userspace) = 21.090s. Mar 02 20:10:06 volumio winbindd[937]: [2021/03/02 20:10:06.887443, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:06 volumio winbindd[937]: Unable to open new log file '/var/log/samba/log.winbindd-idmap': No such file or directory Mar 02 20:10:07 volumio winbindd[938]: [2021/03/02 20:10:07.036305, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:07 volumio winbindd[938]: Unable to open new log file '/var/log/samba/log.wb-BUILTIN': No such file or directory Mar 02 20:10:07 volumio smbd[930]: [2021/03/02 20:10:07.085778, 0] ../lib/util/become_daemon.c:124(daemon_ready) Mar 02 20:10:07 volumio smbd[930]: STATUS=daemon 'smbd' finished starting up and ready to serve connections Mar 02 20:10:07 volumio smbd[939]: [2021/03/02 20:10:07.089709, 0] ../lib/util/debug.c:603(reopen_logs_internal) Mar 02 20:10:07 volumio smbd[939]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Mar 02 20:10:08 volumio volumio-remote-updater[608]: [2021-03-02 20:10:08] [info] asio async_connect error: system:111 (Connection refused) Mar 02 20:10:08 volumio volumio-remote-updater[608]: [2021-03-02 20:10:08] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Mar 02 20:10:08 volumio volumio-remote-updater[608]: [2021-03-02 20:10:08] [error] handle_connect error: Underlying Transport Error Mar 02 20:10:08 volumio volumio[914]: info: ------------------------------------------- Mar 02 20:10:08 volumio volumio[914]: info: ----- Volumio2 ---- Mar 02 20:10:08 volumio volumio[914]: info: ------------------------------------------- Mar 02 20:10:08 volumio volumio[914]: info: ----- System startup ---- Mar 02 20:10:08 volumio volumio[914]: info: ------------------------------------------- Mar 02 20:10:09 volumio volumio[914]: info: MYVOLUMIO Environment detected Mar 02 20:10:09 volumio volumio[914]: info: Plugin folders cleanup Mar 02 20:10:09 volumio volumio[914]: info: Scanning into folder /volumio/app/plugins/ Mar 02 20:10:09 volumio volumio[914]: info: Scanning category audio_interface Mar 02 20:10:09 volumio volumio[914]: info: Scanning category miscellanea Mar 02 20:10:09 volumio volumio[914]: info: Scanning category music_service Mar 02 20:10:09 volumio volumio[914]: info: Scanning category plugins.json Mar 02 20:10:09 volumio volumio[914]: info: Scanning category system_controller Mar 02 20:10:09 volumio volumio[914]: info: Scanning category user_interface Mar 02 20:10:09 volumio volumio[914]: info: Scanning into folder /data/plugins/ Mar 02 20:10:09 volumio volumio[914]: info: Scanning category music_service Mar 02 20:10:09 volumio volumio[914]: info: Plugin folders cleanup completed Mar 02 20:10:09 volumio volumio[914]: info: ------------------------------------------- Mar 02 20:10:09 volumio volumio[914]: info: ----- Core plugins startup ---- Mar 02 20:10:09 volumio volumio[914]: info: ------------------------------------------- Mar 02 20:10:09 volumio volumio[914]: info: Loading plugins from folder /volumio/app/plugins/ Mar 02 20:10:09 volumio volumio[914]: info: Adding plugin upnp to MyMusic Plugins Mar 02 20:10:09 volumio volumio[914]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 02 20:10:09 volumio volumio[914]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 02 20:10:09 volumio volumio[914]: info: Loading plugins from folder /data/plugins/ Mar 02 20:10:09 volumio volumio[914]: info: Loading plugin "system"... Mar 02 20:10:10 volumio volumio[914]: info: Loading plugin "appearance"... Mar 02 20:10:30 volumio systemd[1]: Time has been changed Mar 02 20:10:32 volumio volumio[914]: info: Loading plugin "network"... Mar 02 20:10:32 volumio volumio[914]: info: Refreshing Cached IP Addresses Mar 02 20:10:32 volumio sudo[952]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 02 20:10:32 volumio volumio[914]: info: Loading plugin "services"... Mar 02 20:10:32 volumio volumio[914]: info: Loading plugin "alsa_controller"... Mar 02 20:10:32 volumio sudo[952]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 20:10:32 volumio sudo[952]: pam_unix(sudo:session): session closed for user root Mar 02 20:10:32 volumio sudo[955]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 02 20:10:32 volumio sudo[955]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 20:10:32 volumio sudo[955]: pam_unix(sudo:session): session closed for user root Mar 02 20:10:32 volumio volumio[914]: info: Loading plugin "wizard"... Mar 02 20:10:32 volumio volumio[914]: info: Loading plugin "volumio_command_line_client"... Mar 02 20:10:32 volumio volumio[914]: info: Loading plugin "upnp"... Mar 02 20:10:32 volumio volumio[914]: info: [1614715832969] Starting Upmpd Daemon Mar 02 20:10:32 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 02 20:10:32 volumio volumio[914]: info: Loading plugin "my_music"... Mar 02 20:10:32 volumio volumio[914]: info: Loading plugin "mpd"... Mar 02 20:10:33 volumio volumio[914]: info: Loading plugin "upnp_browser"... Mar 02 20:10:33 volumio volumio[914]: info: Loading plugin "networkfs"... Mar 02 20:10:34 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 02 20:10:34 volumio volumio[914]: info: Loading plugin "alarm-clock"... Mar 02 20:10:34 volumio sudo[976]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=,password=,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.55/music /mnt/NAS/HomePC Mar 02 20:10:34 volumio sudo[976]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 20:10:34 volumio kernel: FS-Cache: Netfs 'cifs' registered for caching Mar 02 20:10:34 volumio kernel: Key type cifs.spnego registered Mar 02 20:10:34 volumio kernel: Key type cifs.idmap registered Mar 02 20:10:34 volumio 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. Mar 02 20:10:34 volumio sudo[976]: pam_unix(sudo:session): session closed for user root Mar 02 20:10:34 volumio volumio[914]: info: Loading plugin "airplay_emulation"... Mar 02 20:10:34 volumio volumio[914]: info: Starting Shairport Sync Mar 02 20:10:34 volumio volumio[914]: info: Loading plugin "last_100"... Mar 02 20:10:34 volumio volumio[914]: info: Loading plugin "webradio"... Mar 02 20:10:34 volumio volumio[914]: info: Loading plugin "i2s_dacs"... Mar 02 20:10:34 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 02 20:10:34 volumio volumio[914]: info: Loading plugin "volumiodiscovery"... Mar 02 20:10:34 volumio volumio[914]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 02 20:10:34 volumio node[914]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 02 20:10:34 volumio node[914]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 02 20:10:34 volumio node[914]: *** WARNING *** For more information see Mar 02 20:10:34 volumio node[914]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 02 20:10:34 volumio node[914]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 02 20:10:34 volumio node[914]: *** WARNING *** For more information see Mar 02 20:10:34 volumio volumio[914]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 02 20:10:34 volumio volumio[914]: *** WARNING *** For more information see Mar 02 20:10:34 volumio volumio[914]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 02 20:10:34 volumio volumio[914]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 02 20:10:34 volumio volumio[914]: *** WARNING *** For more information see Mar 02 20:10:34 volumio volumio[914]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 02 20:10:34 volumio volumio[914]: Discovery: StartAdv! undefined Mar 02 20:10:34 volumio volumio[914]: Discovery: Started advertising... Volumio - undefined Mar 02 20:10:34 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 02 20:10:34 volumio volumio[914]: info: Loading plugin "outputs"... Mar 02 20:10:34 volumio volumio[914]: info: Loading plugin "albumart"... Mar 02 20:10:34 volumio volumio[914]: info: Plugin example_plugin is not enabled Mar 02 20:10:34 volumio volumio[914]: info: Loading plugin "inputs"... Mar 02 20:10:34 volumio volumio[914]: info: Loading plugin "updater_comm"... Mar 02 20:10:34 volumio volumio[914]: info: Plugin mpdemulation is not enabled Mar 02 20:10:34 volumio volumio[914]: info: Loading plugin "rest_api"... Mar 02 20:10:34 volumio volumio[914]: info: Loading plugin "websocket"... Mar 02 20:10:34 volumio volumio[914]: info: Loading plugin "radio_paradise"... Mar 02 20:10:35 volumio volumio[914]: Forking 3 albumart workers Mar 02 20:10:35 volumio volumio[914]: info: Applying required configuration parameters for plugin radio_paradise Mar 02 20:10:35 volumio volumio[914]: info: [1614715835614] [RadioParadise] API delay: 5 Mar 02 20:10:35 volumio volumio[914]: info: ___________ START PLUGINS ___________ Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 02 20:10:35 volumio volumio[914]: info: [1614715835629] CoreMusicLibrary::Adding element Media Servers Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 02 20:10:35 volumio volumio[914]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 02 20:10:35 volumio volumio[914]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 02 20:10:35 volumio volumio[914]: info: [1614715835795] CoreMusicLibrary::Adding element Last_100 Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 02 20:10:35 volumio volumio[914]: info: [1614715835799] CoreMusicLibrary::Adding element Webradio Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 02 20:10:35 volumio volumio[914]: info: [1614715835824] CoreMusicLibrary::Adding element Radio Paradise Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 02 20:10:35 volumio volumio[914]: info: ------------------------------------------- Mar 02 20:10:35 volumio volumio[914]: info: ----- MyVolumio plugins startup ---- Mar 02 20:10:35 volumio volumio[914]: info: ------------------------------------------- Mar 02 20:10:35 volumio volumio[914]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 02 20:10:35 volumio volumio-remote-updater[608]: [2021-03-02 20:10:35] [connect] Successful connection Mar 02 20:10:35 volumio volumio[914]: info: Loading i18n strings for locale en Mar 02 20:10:35 volumio volumio[914]: Updating browse sources language Mar 02 20:10:35 volumio volumio[914]: Cannot find translation for sourceMedia Servers Mar 02 20:10:35 volumio volumio[914]: Cannot find translation for sourceRadio Paradise Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::initPlayerControls Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 02 20:10:35 volumio volumio[914]: Starting albumart workers Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Mar 02 20:10:35 volumio volumio[914]: Starting albumart workers Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 02 20:10:35 volumio volumio[914]: Starting albumart workers Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 02 20:10:35 volumio volumio[914]: info: BOOT COMPLETED Mar 02 20:10:35 volumio volumio[914]: [Metrics] CommandRouter: 6s 951.06ms Mar 02 20:10:35 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 02 20:10:36 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Mar 02 20:10:41 volumio volumio[914]: Playing WAVE '/volumio/app/startup.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo Mar 02 20:10:41 volumio volumio[914]: info: CoreCommandRouter::Close All Modals sent Mar 02 20:10:41 volumio volumio[914]: info: CoreCommandRouter::Close All Modals sent Mar 02 20:10:41 volumio volumio[914]: Express server listening on port 3000 Mar 02 20:10:41 volumio volumio[914]: [Metrics] WebUI: 12s 992.12ms Mar 02 20:10:41 volumio volumio[914]: Volumio Calling Home Mar 02 20:10:41 volumio volumio[914]: info: CoreStateMachine::resetVolumioState Mar 02 20:10:41 volumio volumio[914]: info: CoreStateMachine::getcurrentVolume Mar 02 20:10:41 volumio volumio[914]: info: CoreCommandRouter::volumioRetrievevolume Mar 02 20:10:41 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:10:41 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:10:41 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:10:41 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:10:41 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 02 20:10:41 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 02 20:10:41 volumio volumio[914]: info: Setting Device type: Raspberry PI Mar 02 20:10:41 volumio volumio[914]: info: MPD running with PID675 Mar 02 20:10:41 volumio volumio[914]: ,establishing connection Mar 02 20:10:41 volumio volumio[914]: info: Volumio called home Mar 02 20:10:41 volumio volumio[914]: info: Reloading queue from file Mar 02 20:10:42 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Mar 02 20:10:42 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:10:42 volumio volumio[914]: error: updateQueue error: null Mar 02 20:10:42 volumio volumio[914]: error: Failed LSINFO: Error: [50@0] {} No such directory Mar 02 20:10:42 volumio volumio[914]: info: CoreStateMachine::setRepeat false single undefined Mar 02 20:10:42 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:10:42 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:10:42 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:10:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:10:42 volumio volumio[914]: info: CoreStateMachine::setRandom null Mar 02 20:10:42 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:10:42 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:10:42 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:10:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:10:42 volumio volumio[914]: info: CoreCommandRouter::volumioGetQueue Mar 02 20:10:42 volumio volumio[914]: info: CoreStateMachine::getQueue Mar 02 20:10:42 volumio volumio[914]: info: CorePlayQueue::getQueue Mar 02 20:10:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid Mar 02 20:10:42 volumio volumio[914]: info: Starting Shairport Sync Mar 02 20:10:42 volumio volumio[914]: info: Starting Shairport Sync Mar 02 20:10:42 volumio sudo[1093]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 02 20:10:42 volumio sudo[1093]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 20:10:42 volumio sudo[1095]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 02 20:10:42 volumio systemd[1]: Starting Shairport Sync - AirPlay Audio Receiver... Mar 02 20:10:42 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 02 20:10:42 volumio sudo[1095]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 20:10:42 volumio sudo[1093]: pam_unix(sudo:session): session closed for user root Mar 02 20:10:42 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 02 20:10:42 volumio systemd[1]: Starting Shairport Sync - AirPlay Audio Receiver... Mar 02 20:10:42 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 02 20:10:42 volumio sudo[1095]: pam_unix(sudo:session): session closed for user root Mar 02 20:10:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 02 20:10:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 02 20:10:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 02 20:10:43 volumio sudo[1123]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 02 20:10:43 volumio volumio[914]: Discovery: adding c36e055d-03ed-42c7-81db-3a230585b9c8 Mar 02 20:10:43 volumio volumio[914]: info: mDNS: Found device Volumio Mar 02 20:10:43 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Mar 02 20:10:43 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:10:43 volumio sudo[1125]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 02 20:10:43 volumio sudo[1123]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 20:10:43 volumio sudo[1125]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 20:10:43 volumio sudo[1123]: pam_unix(sudo:session): session closed for user root Mar 02 20:10:43 volumio sudo[1125]: pam_unix(sudo:session): session closed for user root Mar 02 20:10:43 volumio volumio[914]: info: Shairport-Sync Started Mar 02 20:10:43 volumio volumio[914]: Error adding Membership: Error: addMembership EINVAL Mar 02 20:10:43 volumio volumio[914]: info: Shairport-Sync Started Mar 02 20:10:43 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Mar 02 20:10:43 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:10:43 volumio sudo[1141]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 02 20:10:43 volumio sudo[1141]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 20:10:43 volumio systemd[1]: Starting UPnP Renderer front-end to MPD... Mar 02 20:10:43 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Mar 02 20:10:43 volumio sudo[1141]: pam_unix(sudo:session): session closed for user root Mar 02 20:10:43 volumio volumio[914]: info: Upmpdcli Daemon Started Mar 02 20:10:44 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 02 20:10:44 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 02 20:10:44 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 02 20:10:44 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 02 20:10:44 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 02 20:10:44 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 02 20:10:44 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 02 20:10:44 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 02 20:10:44 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 02 20:10:44 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 02 20:10:44 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 02 20:10:44 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 02 20:10:44 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 02 20:10:44 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 02 20:10:44 volumio volumio[914]: info: Adding plugin bluetooth to MyMusic Plugins Mar 02 20:10:44 volumio volumio[914]: info: Adding plugin cd_controller to MyMusic Plugins Mar 02 20:10:44 volumio volumio[914]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 02 20:10:44 volumio volumio[914]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 02 20:10:45 volumio volumio[914]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 02 20:10:45 volumio volumio[914]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 02 20:10:45 volumio volumio[914]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 02 20:10:45 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 02 20:10:45 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 02 20:10:45 volumio volumio[914]: info: Starting MyVolumio Remote Streaming Endpoints Mar 02 20:10:45 volumio volumio[914]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 02 20:10:45 volumio volumio[914]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 02 20:10:45 volumio volumio[914]: info: Streaming services startup Mar 02 20:10:45 volumio volumio[914]: info: Starting Streaming Daemon Mar 02 20:10:45 volumio sudo[1164]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 02 20:10:45 volumio sudo[1164]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 20:10:45 volumio volumio[914]: info: MyVolumio login type: Token Mar 02 20:10:45 volumio systemd[1]: Stopping Volumio Streaming Daemon... Mar 02 20:10:45 volumio volumio[914]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 02 20:10:45 volumio systemd[1]: Starting Volumio Streaming Daemon... Mar 02 20:10:45 volumio systemd[1]: Started Volumio Streaming Daemon. Mar 02 20:10:45 volumio sudo[1164]: pam_unix(sudo:session): session closed for user root Mar 02 20:10:45 volumio volumio-streaming-daemon[1174]: ############################ Mar 02 20:10:45 volumio volumio-streaming-daemon[1174]: # Volumio Streaming Daemon # Mar 02 20:10:45 volumio volumio-streaming-daemon[1174]: # Running on port 7777 # Mar 02 20:10:45 volumio volumio-streaming-daemon[1174]: ############################ Mar 02 20:10:45 volumio volumio-streaming-daemon[1174]: Environment: production Mar 02 20:10:46 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Mar 02 20:10:46 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:10:46 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 02 20:10:46 volumio volumio[914]: info: CoreCommandRouter::volumioGetVisibleSources Mar 02 20:10:46 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 02 20:10:46 volumio volumio[914]: info: Listing playlists Mar 02 20:10:46 volumio volumio[914]: info: CoreCommandRouter::volumioGetQueue Mar 02 20:10:46 volumio volumio[914]: info: CoreStateMachine::getQueue Mar 02 20:10:46 volumio volumio[914]: info: CorePlayQueue::getQueue Mar 02 20:10:46 volumio volumio[914]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 02 20:10:46 volumio volumio[914]: info: MYVOLUMIO: Adding device Mar 02 20:10:46 volumio volumio[914]: info: MYVOLUMIO: Evaluating Server Mar 02 20:10:47 volumio volumio[914]: info: [MyVolumio PluginManager] Subscribed plan changed to virtuoso Mar 02 20:10:47 volumio volumio[914]: info: Removing browser output: myVolumio user plan is not superstar Mar 02 20:10:47 volumio volumio[914]: info: Removing audio output: Mar 02 20:10:47 volumio volumio[914]: info: MYVOLUMIO: Adding device Mar 02 20:10:47 volumio volumio[914]: info: MYVOLUMIO: Evaluating Server Mar 02 20:10:47 volumio volumio[914]: info: Remote config written successfully Mar 02 20:10:47 volumio volumio[914]: info: Starting Tunnel 1 Mar 02 20:10:47 volumio volumio[914]: info: Starting Tunnel Connection Checker Mar 02 20:10:47 volumio sudo[1200]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Mar 02 20:10:47 volumio sudo[1200]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 20:10:47 volumio systemd[1]: Starting MyVolumio SSH Tunnel... Mar 02 20:10:47 volumio systemd[1]: Started MyVolumio SSH Tunnel. Mar 02 20:10:47 volumio sudo[1200]: pam_unix(sudo:session): session closed for user root Mar 02 20:10:47 volumio autossh[1207]: port set to 0, monitoring disabled Mar 02 20:10:47 volumio autossh[1207]: starting ssh (count 1) Mar 02 20:10:47 volumio autossh[1207]: ssh child pid is 1213 Mar 02 20:10:47 volumio volumio[914]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Mar 02 20:10:47 volumio volumio[914]: info: MyVolumio status changed Mar 02 20:10:47 volumio volumio[914]: info: Streaming services startup Mar 02 20:10:47 volumio volumio[914]: info: Re-Starting Streaming Daemon Mar 02 20:10:47 volumio volumio[914]: info: Setting Geolocation for MyVolumio to eu2 Mar 02 20:10:47 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 02 20:10:47 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 02 20:10:47 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 02 20:10:47 volumio volumio[914]: info: Remote SSH Started Mar 02 20:10:48 volumio volumio-streaming-daemon[1174]: Restarting daemon Mar 02 20:10:48 volumio volumio-streaming-daemon[1174]: Environment: production Mar 02 20:10:48 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Mar 02 20:10:48 volumio volumio[914]: info: [MyVolumio PluginManager] Plugin music_service/tidalconnect is enabled for this plan, but could not be found on the local filesystem! Mar 02 20:10:48 volumio volumio[914]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Mar 02 20:10:48 volumio volumiossh-tunnel[1205]: Warning: Permanently added '[eu1.myvolumio.org]:2222,[188.166.162.121]:2222' (RSA) to the list of known hosts. Mar 02 20:10:48 volumio volumio[914]: info: [1614715848347] Starting BluetoothController Mar 02 20:10:48 volumio volumio[914]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Mar 02 20:10:48 volumio volumio[914]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Mar 02 20:10:48 volumio volumio[914]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Mar 02 20:10:48 volumio volumio[914]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Mar 02 20:10:48 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 02 20:10:48 volumio volumio[914]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Mar 02 20:10:48 volumio volumio[914]: info: Preparing CD Folders Mar 02 20:10:48 volumio volumio[914]: info: Adding CD REST API Endpoints Mar 02 20:10:48 volumio volumio[914]: info: Adding detectCD REST Endpoint for plugin: music_service/cd_controller Mar 02 20:10:48 volumio volumio[914]: info: Adding cdRemove REST Endpoint for plugin: music_service/cd_controller Mar 02 20:10:48 volumio volumio[914]: info: Adding cdPostScan REST Endpoint for plugin: music_service/cd_controller Mar 02 20:10:48 volumio volumio[914]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Mar 02 20:10:48 volumio volumio[914]: info: Detecting CD presence Mar 02 20:10:48 volumio volumio[914]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Mar 02 20:10:48 volumio volumio[914]: info: Refreshing TIDAL token Mar 02 20:10:48 volumio volumio[914]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Mar 02 20:10:48 volumio sudo[1223]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Volumio Mar 02 20:10:48 volumio volumio[914]: info: Stopping AccessToken refresher cron for QOBUZ Mar 02 20:10:48 volumio sudo[1223]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 20:10:48 volumio sudo[1223]: pam_unix(sudo:session): session closed for user root Mar 02 20:10:48 volumio volumio-streaming-daemon[1174]: Enabled services: Mar 02 20:10:48 volumio volumio-streaming-daemon[1174]: 1) tidal Mar 02 20:10:48 volumio volumio-streaming-daemon[1174]: 2) qobuz Mar 02 20:10:48 volumio volumio[914]: info: AccessToken refresher cron started for QOBUZ Mar 02 20:10:48 volumio volumio[914]: info: Setting Geolocation for MyVolumio to eu1 Mar 02 20:10:48 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 02 20:10:48 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 02 20:10:48 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 02 20:10:48 volumio volumio[914]: info: Bluetooth name changed to Volumio Mar 02 20:10:48 volumio volumio-streaming-daemon[1174]: Environment: production Mar 02 20:10:48 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Mar 02 20:10:48 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:10:48 volumio volumio[914]: info: Updating MyVolumio device info Mar 02 20:10:48 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 02 20:10:48 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 02 20:10:48 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 02 20:10:49 volumio volumio[914]: info: Access Token successfully retrieved Mar 02 20:10:49 volumio volumio[914]: info: Fetching Streaming Services browse cache Mar 02 20:10:49 volumio volumio[914]: info: Updating MyVolumio device info Mar 02 20:10:49 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 02 20:10:49 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 02 20:10:49 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 02 20:10:49 volumio volumio-streaming-daemon[1174]: Environment: production Mar 02 20:10:49 volumio volumio-streaming-daemon[1174]: Environment: production Mar 02 20:10:50 volumio volumio[914]: info: Successfully retrieved User Session From TIDAL Mar 02 20:10:50 volumio volumio[914]: info: Successfully retrieved User Subscription From TIDAL Mar 02 20:10:50 volumio volumio[914]: info: Adding TIDAL to Browse Sources Mar 02 20:10:50 volumio volumio[914]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 02 20:10:50 volumio volumio[914]: info: [1614715850294] CoreMusicLibrary::Adding element TIDAL Mar 02 20:10:50 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 02 20:10:50 volumio volumio[914]: info: Stopping AccessToken refresher cron Mar 02 20:10:50 volumio volumio[914]: info: AccessToken refresher cron started Mar 02 20:10:50 volumio volumio[914]: info: Fetching Streaming Services browse cache Mar 02 20:10:50 volumio volumio-remote-updater[608]: [2021-03-02 20:10:50] [connect] Successful connection Mar 02 20:10:50 volumio volumio-remote-updater[608]: [2021-03-02 20:10:50] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.5.1" /socket.io/?EIO=4&transport=websocket&t=1614715850 101 Mar 02 20:10:51 volumio sudo[1241]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Mar 02 20:10:51 volumio sudo[1241]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 20:10:51 volumio systemd[1]: Starting Volumio Bluetooth Module... Mar 02 20:10:51 volumio systemd[1]: Started Volumio Bluetooth Module. Mar 02 20:10:51 volumio sudo[1241]: pam_unix(sudo:session): session closed for user root Mar 02 20:10:51 volumio sudo[1247]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Mar 02 20:10:51 volumio sudo[1247]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 20:10:51 volumio volumio[914]: info: Volumio BT Module successfully started Mar 02 20:10:51 volumio volumiobt[1246]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Mar 02 20:10:51 volumio sudo[1247]: pam_unix(sudo:session): session closed for user root Mar 02 20:10:52 volumio sudo[1261]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Mar 02 20:10:52 volumio sudo[1261]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 20:10:52 volumio volumiobt[1246]: pulseaudio: no process found Mar 02 20:10:52 volumio sudo[1261]: pam_unix(sudo:session): session closed for user root Mar 02 20:10:52 volumio dbus[676]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' Mar 02 20:10:52 volumio systemd[1]: Starting RealtimeKit Scheduling Policy Service... Mar 02 20:10:52 volumio volumio[914]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 02 20:10:52 volumio volumio[914]: BT PLUGIN MESSAGE: Playing: false Mar 02 20:10:52 volumio volumio[914]: BT PLUGIN MESSAGE: VOLATILE: Mar 02 20:10:52 volumio volumio[914]: BT PLUGIN MESSAGE: STATE:undefined Mar 02 20:10:52 volumio dbus[676]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Mar 02 20:10:52 volumio rtkit-daemon[1272]: Successfully called chroot. Mar 02 20:10:52 volumio rtkit-daemon[1272]: Successfully dropped privileges. Mar 02 20:10:52 volumio rtkit-daemon[1272]: Successfully limited resources. Mar 02 20:10:52 volumio rtkit-daemon[1272]: Running. Mar 02 20:10:52 volumio rtkit-daemon[1272]: Canary thread running. Mar 02 20:10:52 volumio rtkit-daemon[1272]: Watchdog thread running. Mar 02 20:10:52 volumio systemd[1]: Started RealtimeKit Scheduling Policy Service. Mar 02 20:10:53 volumio pulseaudio[1271]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Mar 02 20:10:53 volumio pulseaudio[1271]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Mar 02 20:10:53 volumio pulseaudio[1271]: org.bluez.Manager.GetProperties() failed: org.freedesktop.DBus.Error.UnknownMethod: Method "GetProperties" with signature "" on interface "org.bluez.Manager" doesn't exist Mar 02 20:10:53 volumio bluetoothd[817]: Endpoint registered: sender=:1.18 path=/MediaEndpoint/A2DPSource Mar 02 20:10:53 volumio bluetoothd[817]: Endpoint registered: sender=:1.18 path=/MediaEndpoint/A2DPSink Mar 02 20:10:53 volumio volumiobt[1246]: Applying permissions Mar 02 20:10:53 volumio volumiobt[1246]: Setting BT discoverable and pairable Mar 02 20:10:53 volumio volumiobt[1246]: [105B blob data] Mar 02 20:10:53 volumio volumiobt[1246]: [bluetooth]# -e power on Mar 02 20:10:53 volumio volumiobt[1246]: Invalid command Mar 02 20:10:53 volumio volumiobt[1246]: [bluetooth]# agent on Mar 02 20:10:53 volumio volumiobt[1246]: [bluetooth]# discoverable on Mar 02 20:10:53 volumio volumiobt[1246]: [bluetooth]# pairable on Mar 02 20:10:53 volumio volumiobt[1246]: [bluetooth]# agent NoInputNoOutput Mar 02 20:10:53 volumio volumiobt[1246]: Failed to register agent object Mar 02 20:10:53 volumio volumiobt[1246]: [bluetooth]# default-agent Mar 02 20:10:53 volumio volumiobt[1246]: No agent is registered Mar 02 20:10:53 volumio volumiobt[1246]: [bluetooth]# quit Mar 02 20:10:53 volumio volumiobt[1246]: [61B blob data] Mar 02 20:10:53 volumio volumiobt[1246]: [91B blob data] Mar 02 20:10:53 volumio volumiobt[1246]: [62B blob data] Mar 02 20:11:04 volumio volumio[914]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 02 20:11:04 volumio volumio[914]: info: CoreStateMachine::ClearQueue Mar 02 20:11:04 volumio volumio[914]: info: CoreStateMachine::stop Mar 02 20:11:04 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:11:04 volumio volumio[914]: UNSET VOLATILE Mar 02 20:11:04 volumio volumio[914]: info: CorePlayQueue::clearPlayQueue Mar 02 20:11:04 volumio volumio[914]: info: CorePlayQueue::saveQueue Mar 02 20:11:04 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:11:04 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:11:05 volumio volumio[914]: info: CoreCommandRouter::volumioPushQueue Mar 02 20:11:05 volumio volumio[914]: info: CoreStateMachine::addQueueItems Mar 02 20:11:05 volumio volumio[914]: info: CorePlayQueue::addQueueItems Mar 02 20:11:05 volumio volumio[914]: info: Adding Item to queue: tidal://mymusic/albums/az/116620371 Mar 02 20:11:05 volumio volumio[914]: info: Exploding uri tidal://mymusic/albums/az/116620371 in service tidal Mar 02 20:11:05 volumio volumio[914]: info: explodeTIDALUri took 501 milliseconds Mar 02 20:11:05 volumio volumio[914]: info: CorePlayQueue::saveQueue Mar 02 20:11:05 volumio volumio[914]: info: CoreCommandRouter::volumioPushQueue Mar 02 20:11:05 volumio volumio[914]: info: CoreStateMachine::updateTrackBlock Mar 02 20:11:05 volumio volumio[914]: info: CorePlayQueue::getTrackBlock Mar 02 20:11:05 volumio volumio[914]: info: CoreCommandRouter::volumioPlay Mar 02 20:11:05 volumio volumio[914]: UNSET VOLATILE Mar 02 20:11:05 volumio volumio[914]: info: CoreStateMachine::play index 0 Mar 02 20:11:05 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:11:05 volumio volumio[914]: info: CoreStateMachine::stop Mar 02 20:11:05 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:11:05 volumio volumio[914]: UNSET VOLATILE Mar 02 20:11:05 volumio volumio[914]: info: CoreStateMachine::play index undefined Mar 02 20:11:05 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:11:05 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:11:05 volumio volumio[914]: info: CoreStateMachine::startPlaybackTimer Mar 02 20:11:05 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:11:05 volumio volumio[914]: info: [1614715865526] ControllerTidal::clearAddPlayTrack Mar 02 20:11:05 volumio volumio[914]: info: Getting stream with soundQuality LOSSLESS Mar 02 20:11:05 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 02 20:11:05 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 02 20:11:06 volumio volumio[914]: info: getStreamUrl took 586 milliseconds Mar 02 20:11:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand stop Mar 02 20:11:06 volumio volumio[914]: info: sendMpdCommand stop took 3 milliseconds Mar 02 20:11:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand clear Mar 02 20:11:06 volumio volumio[914]: info: Mar 02 20:11:06 volumio volumio[914]: ---------------------------- MPD announces system playlist update Mar 02 20:11:06 volumio volumio[914]: info: Ignoring MPD Status Update Mar 02 20:11:06 volumio volumio[914]: info: sendMpdCommand clear took 3 milliseconds Mar 02 20:11:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand load "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInOWE5ZTE5MzViN2UzOTlhZjI3YWQ3NDYwZDNjMjdlMzFfNjEubXA0/0.flac?token=1614719466~ZWFmZDVjZmM2NGMzZjhjNzRmYmViMzM5M2JhMTQ4MmI2YTJkNmIzMQ==" Mar 02 20:11:06 volumio volumio[914]: error: updateQueue error: null Mar 02 20:11:06 volumio volumio[914]: info: ------------------------------ 6ms Mar 02 20:11:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand add "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInOWE5ZTE5MzViN2UzOTlhZjI3YWQ3NDYwZDNjMjdlMzFfNjEubXA0/0.flac?token=1614719466~ZWFmZDVjZmM2NGMzZjhjNzRmYmViMzM5M2JhMTQ4MmI2YTJkNmIzMQ==" Mar 02 20:11:06 volumio volumio[914]: info: Mar 02 20:11:06 volumio volumio[914]: ---------------------------- MPD announces system playlist update Mar 02 20:11:06 volumio volumio[914]: info: Ignoring MPD Status Update Mar 02 20:11:06 volumio volumio[914]: info: sendMpdCommand add "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInOWE5ZTE5MzViN2UzOTlhZjI3YWQ3NDYwZDNjMjdlMzFfNjEubXA0/0.flac?token=1614719466~ZWFmZDVjZmM2NGMzZjhjNzRmYmViMzM5M2JhMTQ4MmI2YTJkNmIzMQ==" took 2 milliseconds Mar 02 20:11:06 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 02 20:11:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand play Mar 02 20:11:06 volumio volumio[914]: info: ------------------------------ 5ms Mar 02 20:11:06 volumio volumio[914]: info: sendMpdCommand play took 3 milliseconds Mar 02 20:11:06 volumio volumio[914]: info: Mar 02 20:11:06 volumio volumio[914]: ---------------------------- MPD announces state update: player Mar 02 20:11:06 volumio volumio[914]: info: ControllerMpd::getState Mar 02 20:11:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Mar 02 20:11:06 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Mar 02 20:11:06 volumio volumio[914]: info: Mar 02 20:11:06 volumio volumio[914]: ---------------------------- MPD announces state update: player Mar 02 20:11:06 volumio volumio[914]: info: sendMpdCommand status took 13 milliseconds Mar 02 20:11:06 volumio volumio[914]: info: ControllerMpd::getState Mar 02 20:11:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Mar 02 20:11:06 volumio volumio[914]: verbose: ControllerMpd::parseState Mar 02 20:11:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 20:11:06 volumio volumio[914]: info: sendMpdCommand status took 5 milliseconds Mar 02 20:11:06 volumio volumio[914]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 02 20:11:06 volumio volumio[914]: verbose: ControllerMpd::parseState Mar 02 20:11:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 20:11:06 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Mar 02 20:11:06 volumio volumio[914]: info: ControllerMpd::pushState Mar 02 20:11:06 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 02 20:11:06 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:11:06 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":264,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"573 Kbps","isStreaming":false,"title":"0.flac?token=1614719466~ZWFmZDVjZmM2NGMzZjhjNzRmYmViMzM5M2JhMTQ4MmI2YTJkNmIzMQ==","artist":null,"album":null,"uri":"http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInOWE5ZTE5MzViN2UzOTlhZjI3YWQ3NDYwZDNjMjdlMzFfNjEubXA0/0.flac?token=1614719466~ZWFmZDVjZmM2NGMzZjhjNzRmYmViMzM5M2JhMTQ4MmI2YTJkNmIzMQ==","trackType":"tidal"} Mar 02 20:11:06 volumio volumio[914]: verbose: CURRENT POSITION 0 Mar 02 20:11:06 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Mar 02 20:11:06 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus stop Mar 02 20:11:06 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:11:06 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:11:06 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:11:06 volumio volumio[914]: info: ------------------------------ 52ms Mar 02 20:11:06 volumio volumio[914]: info: sendMpdCommand playlistinfo took 27 milliseconds Mar 02 20:11:06 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Mar 02 20:11:06 volumio volumio[914]: info: ControllerMpd::pushState Mar 02 20:11:06 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 02 20:11:06 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:11:06 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":464,"duration":264,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"583 Kbps","isStreaming":false,"title":"0.flac?token=1614719466~ZWFmZDVjZmM2NGMzZjhjNzRmYmViMzM5M2JhMTQ4MmI2YTJkNmIzMQ==","artist":null,"album":null,"uri":"http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInOWE5ZTE5MzViN2UzOTlhZjI3YWQ3NDYwZDNjMjdlMzFfNjEubXA0/0.flac?token=1614719466~ZWFmZDVjZmM2NGMzZjhjNzRmYmViMzM5M2JhMTQ4MmI2YTJkNmIzMQ==","trackType":"tidal"} Mar 02 20:11:06 volumio volumio[914]: verbose: CURRENT POSITION 0 Mar 02 20:11:06 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Mar 02 20:11:06 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus play Mar 02 20:11:06 volumio volumio[914]: info: Received an update from plugin. extracting info from payload Mar 02 20:11:06 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:11:06 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:11:06 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:11:06 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:11:06 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:11:06 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:11:06 volumio volumio[914]: info: ------------------------------ 67ms Mar 02 20:11:12 volumio volumio[914]: info: CoreCommandRouter::volumioGetState Mar 02 20:11:12 volumio volumio[914]: info: CoreCommandRouter::volumioGetQueue Mar 02 20:11:12 volumio volumio[914]: info: CoreStateMachine::getQueue Mar 02 20:11:12 volumio volumio[914]: info: CorePlayQueue::getQueue Mar 02 20:11:12 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid Mar 02 20:11:14 volumio volumio[914]: info: CALLMETHOD: system_controller system enableLiveLog true Mar 02 20:11:14 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , enableLiveLog Mar 02 20:11:14 volumio volumio[914]: info: Launching a new LiveLog session Mar 02 20:11:19 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 02 20:11:19 volumio volumio[914]: info: browseTIDALUri took 326 milliseconds Mar 02 20:11:22 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 02 20:11:23 volumio volumio[914]: info: browseTIDALUri took 439 milliseconds Mar 02 20:11:26 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 02 20:11:26 volumio volumio[914]: info: browseTIDALUri took 218 milliseconds Mar 02 20:11:53 volumio volumio[914]: info: CALLMETHOD: system_controller system enableLiveLog false Mar 02 20:11:53 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , enableLiveLog Mar 02 20:11:53 volumio volumio[914]: info: Launching a new LiveLog session Mar 02 20:11:53 volumio volumio[914]: info: Live Log process terminated: null Mar 02 20:11:55 volumio volumio[914]: info: CALLMETHOD: system_controller system enableLiveLog true Mar 02 20:11:55 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , enableLiveLog Mar 02 20:11:55 volumio volumio[914]: info: Launching a new LiveLog session Mar 02 20:12:05 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 02 20:12:06 volumio volumio[914]: info: browseTIDALUri took 421 milliseconds Mar 02 20:12:10 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 02 20:12:10 volumio volumio[914]: info: browseTIDALUri took 560 milliseconds Mar 02 20:12:22 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 02 20:12:22 volumio volumio[914]: info: browseTIDALUri took 332 milliseconds Mar 02 20:13:21 volumio volumio[914]: info: CoreCommandRouter::volumioNext Mar 02 20:13:21 volumio volumio[914]: info: CoreStateMachine::next Mar 02 20:13:21 volumio volumio[914]: info: [1614716001219] ControllerTidal::next Mar 02 20:13:21 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:13:21 volumio volumio[914]: info: CoreStateMachine::next Mar 02 20:13:21 volumio volumio[914]: info: CoreStateMachine::stop Mar 02 20:13:21 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:13:21 volumio volumio[914]: UNSET VOLATILE Mar 02 20:13:21 volumio volumio[914]: info: CoreStateMachine::stPlaybackTimer Mar 02 20:13:21 volumio volumio[914]: info: CoreStateMachine::updateTrackBlock Mar 02 20:13:21 volumio volumio[914]: info: CorePlayQueue::getTrackBlock Mar 02 20:13:21 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:13:21 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:13:21 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:13:21 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:13:21 volumio volumio[914]: info: CoreStateMachine::serviceStop Mar 02 20:13:21 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:13:21 volumio volumio[914]: info: CoreCommandRouter::serviceStop Mar 02 20:13:21 volumio volumio[914]: info: [1614716001242] ControllerTidal::stop Mar 02 20:13:21 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 02 20:13:21 volumio volumio[914]: info: ControllerMpd::stop Mar 02 20:13:21 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand stop Mar 02 20:13:21 volumio volumio[914]: info: sendMpdCommand stop took 75 milliseconds Mar 02 20:13:21 volumio volumio[914]: info: CoreStateMachine::play index undefined Mar 02 20:13:21 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:13:21 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 02 20:13:21 volumio volumio[914]: info: CoreStateMachine::startPlaybackTimer Mar 02 20:13:21 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 02 20:13:21 volumio volumio[914]: info: [1614716001326] ControllerTidal::clearAddPlayTrack Mar 02 20:13:21 volumio volumio[914]: info: Getting stream with soundQuality LOSSLESS Mar 02 20:13:21 volumio volumio[914]: info: CoreStateMachine::updateTrackBlock Mar 02 20:13:21 volumio volumio[914]: info: CorePlayQueue::getTrackBlock Mar 02 20:13:21 volumio volumio[914]: info: Mar 02 20:13:21 volumio volumio[914]: ---------------------------- MPD announces state update: player Mar 02 20:13:21 volumio volumio[914]: info: ControllerMpd::getState Mar 02 20:13:21 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Mar 02 20:13:21 volumio volumio[914]: info: sendMpdCommand status took 8 milliseconds Mar 02 20:13:21 volumio volumio[914]: verbose: ControllerMpd::parseState Mar 02 20:13:21 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 20:13:21 volumio volumio[914]: info: sendMpdCommand playlistinfo took 10 milliseconds Mar 02 20:13:21 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Mar 02 20:13:21 volumio volumio[914]: info: ControllerMpd::pushState Mar 02 20:13:21 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 02 20:13:21 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:13:21 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 02 20:13:21 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:13:21 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:13:21 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 02 20:13:21 volumio volumio[914]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Mar 02 20:13:21 volumio volumio[914]: info: ------------------------------ 33ms Mar 02 20:13:21 volumio volumio[914]: info: getStreamUrl took 378 milliseconds Mar 02 20:13:21 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand stop Mar 02 20:13:21 volumio volumio[914]: info: sendMpdCommand stop took 2 milliseconds Mar 02 20:13:21 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand clear Mar 02 20:13:21 volumio volumio[914]: info: Mar 02 20:13:21 volumio volumio[914]: ---------------------------- MPD announces system playlist update Mar 02 20:13:21 volumio volumio[914]: info: Ignoring MPD Status Update Mar 02 20:13:21 volumio volumio[914]: info: sendMpdCommand clear took 5 milliseconds Mar 02 20:13:21 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand load "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInZDQxZmQ0NGU4NDcyYTczZWM3ZGYzMGE4MjExNzYyMmVfNjEubXA0/0.flac?token=1614719601~ZjMyYWZlOTFlMmZmMDhiYThmZjFlYWFmZWNkZmJiYWEyYzgzZTczNg==" Mar 02 20:13:21 volumio volumio[914]: error: updateQueue error: null Mar 02 20:13:21 volumio volumio[914]: info: ------------------------------ 10ms Mar 02 20:13:21 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand add "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInZDQxZmQ0NGU4NDcyYTczZWM3ZGYzMGE4MjExNzYyMmVfNjEubXA0/0.flac?token=1614719601~ZjMyYWZlOTFlMmZmMDhiYThmZjFlYWFmZWNkZmJiYWEyYzgzZTczNg==" Mar 02 20:13:21 volumio volumio[914]: info: Mar 02 20:13:21 volumio volumio[914]: ---------------------------- MPD announces system playlist update Mar 02 20:13:21 volumio volumio[914]: info: Ignoring MPD Status Update Mar 02 20:13:21 volumio volumio[914]: info: sendMpdCommand add "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInZDQxZmQ0NGU4NDcyYTczZWM3ZGYzMGE4MjExNzYyMmVfNjEubXA0/0.flac?token=1614719601~ZjMyYWZlOTFlMmZmMDhiYThmZjFlYWFmZWNkZmJiYWEyYzgzZTczNg==" took 2 milliseconds Mar 02 20:13:21 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 02 20:13:21 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand play Mar 02 20:13:21 volumio volumio[914]: info: ------------------------------ 9ms Mar 02 20:13:21 volumio volumio[914]: info: sendMpdCommand play took 6 milliseconds Mar 02 20:13:22 volumio volumio[914]: info: Mar 02 20:13:22 volumio volumio[914]: ---------------------------- MPD announces state update: player Mar 02 20:13:22 volumio volumio[914]: info: ControllerMpd::getState Mar 02 20:13:22 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Mar 02 20:13:22 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Mar 02 20:13:22 volumio volumio[914]: info: Mar 02 20:13:22 volumio volumio[914]: ---------------------------- MPD announces state update: player Mar 02 20:13:22 volumio volumio[914]: info: sendMpdCommand status took 16 milliseconds Mar 02 20:13:22 volumio volumio[914]: info: ControllerMpd::getState Mar 02 20:13:22 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Mar 02 20:13:22 volumio volumio[914]: verbose: ControllerMpd::parseState Mar 02 20:13:22 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 20:13:22 volumio volumio[914]: info: sendMpdCommand status took 7 milliseconds Mar 02 20:13:22 volumio volumio[914]: info: sendMpdCommand playlistinfo took 5 milliseconds Mar 02 20:13:22 volumio volumio[914]: verbose: ControllerMpd::parseState Mar 02 20:13:22 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 20:13:22 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Mar 02 20:13:22 volumio volumio[914]: info: ControllerMpd::pushState Mar 02 20:13:22 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 02 20:13:22 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 02 20:13:22 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":359,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1614719601~ZjMyYWZlOTFlMmZmMDhiYThmZjFlYWFmZWNkZmJiYWEyYzgzZTczNg==","artist":null,"album":null,"uri":"http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInZDQxZmQ0NGU4NDcyYTczZWM3ZGYzMGE4MjExNzYyMmVfNjEubXA0/0.flac?token=1614719601~ZjMyYWZlOTFlMmZmMDhiYThmZjFlYWFmZWNkZmJiYWEyYzgzZTczNg==","trackType":"tidal"} Mar 02 20:13:22 volumio volumio[914]: verbose: CURRENT POSITION 1 Mar 02 20:13:22 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Mar 02 20:13:22 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus stop Mar 02 20:13:22 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:13:22 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:13:22 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:13:22 volumio volumio[914]: info: ------------------------------ 60ms Mar 02 20:13:22 volumio volumio[914]: info: sendMpdCommand playlistinfo took 46 milliseconds Mar 02 20:13:22 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Mar 02 20:13:22 volumio volumio[914]: info: ControllerMpd::pushState Mar 02 20:13:22 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 02 20:13:22 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 02 20:13:22 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":464,"duration":359,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"657 Kbps","isStreaming":false,"title":"0.flac?token=1614719601~ZjMyYWZlOTFlMmZmMDhiYThmZjFlYWFmZWNkZmJiYWEyYzgzZTczNg==","artist":null,"album":null,"uri":"http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInZDQxZmQ0NGU4NDcyYTczZWM3ZGYzMGE4MjExNzYyMmVfNjEubXA0/0.flac?token=1614719601~ZjMyYWZlOTFlMmZmMDhiYThmZjFlYWFmZWNkZmJiYWEyYzgzZTczNg==","trackType":"tidal"} Mar 02 20:13:22 volumio volumio[914]: verbose: CURRENT POSITION 1 Mar 02 20:13:22 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Mar 02 20:13:22 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus play Mar 02 20:13:22 volumio volumio[914]: info: Received an update from plugin. extracting info from payload Mar 02 20:13:22 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:13:22 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:13:22 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:13:22 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:13:22 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:13:22 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:13:22 volumio volumio[914]: info: ------------------------------ 92ms Mar 02 20:13:25 volumio volumio[914]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::ClearQueue Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::stop Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:13:25 volumio volumio[914]: UNSET VOLATILE Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::stPlaybackTimer Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::updateTrackBlock Mar 02 20:13:25 volumio volumio[914]: info: CorePlayQueue::getTrackBlock Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:13:25 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 02 20:13:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:13:25 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::serviceStop Mar 02 20:13:25 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 02 20:13:25 volumio volumio[914]: info: CoreCommandRouter::serviceStop Mar 02 20:13:25 volumio volumio[914]: info: [1614716005073] ControllerTidal::stop Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 02 20:13:25 volumio volumio[914]: info: ControllerMpd::stop Mar 02 20:13:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand stop Mar 02 20:13:25 volumio volumio[914]: info: CorePlayQueue::clearPlayQueue Mar 02 20:13:25 volumio volumio[914]: info: CorePlayQueue::saveQueue Mar 02 20:13:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:13:25 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:13:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushQueue Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::addQueueItems Mar 02 20:13:25 volumio volumio[914]: info: CorePlayQueue::addQueueItems Mar 02 20:13:25 volumio volumio[914]: info: Adding Item to queue: tidal://song/65103767 Mar 02 20:13:25 volumio volumio[914]: info: Exploding uri tidal://song/65103767 in service tidal Mar 02 20:13:25 volumio volumio[914]: info: Adding Item to queue: tidal://song/65103768 Mar 02 20:13:25 volumio volumio[914]: info: Exploding uri tidal://song/65103768 in service tidal Mar 02 20:13:25 volumio volumio[914]: info: Adding Item to queue: tidal://song/65103769 Mar 02 20:13:25 volumio volumio[914]: info: Exploding uri tidal://song/65103769 in service tidal Mar 02 20:13:25 volumio volumio[914]: info: Adding Item to queue: tidal://song/65103770 Mar 02 20:13:25 volumio volumio[914]: info: Exploding uri tidal://song/65103770 in service tidal Mar 02 20:13:25 volumio volumio[914]: info: Adding Item to queue: tidal://song/65103771 Mar 02 20:13:25 volumio volumio[914]: info: Exploding uri tidal://song/65103771 in service tidal Mar 02 20:13:25 volumio volumio[914]: info: Mar 02 20:13:25 volumio volumio[914]: ---------------------------- MPD announces state update: player Mar 02 20:13:25 volumio volumio[914]: info: sendMpdCommand stop took 61 milliseconds Mar 02 20:13:25 volumio volumio[914]: info: ControllerMpd::getState Mar 02 20:13:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Mar 02 20:13:25 volumio volumio[914]: info: sendMpdCommand status took 5 milliseconds Mar 02 20:13:25 volumio volumio[914]: verbose: ControllerMpd::parseState Mar 02 20:13:25 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 20:13:25 volumio volumio[914]: info: sendMpdCommand playlistinfo took 12 milliseconds Mar 02 20:13:25 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Mar 02 20:13:25 volumio volumio[914]: info: ControllerMpd::pushState Mar 02 20:13:25 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:13:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:13:25 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:13:25 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 02 20:13:25 volumio volumio[914]: 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":"0.flac?token=1614719601~ZjMyYWZlOTFlMmZmMDhiYThmZjFlYWFmZWNkZmJiYWEyYzgzZTczNg==","artist":null,"album":null,"uri":"http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInZDQxZmQ0NGU4NDcyYTczZWM3ZGYzMGE4MjExNzYyMmVfNjEubXA0/0.flac?token=1614719601~ZjMyYWZlOTFlMmZmMDhiYThmZjFlYWFmZWNkZmJiYWEyYzgzZTczNg==","trackType":"tidal"} Mar 02 20:13:25 volumio volumio[914]: verbose: CURRENT POSITION 1 Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::syncState stateService stop Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus stop Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:13:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:13:25 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:13:25 volumio volumio[914]: info: No code Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:13:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:13:25 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:13:25 volumio volumio[914]: info: ------------------------------ 47ms Mar 02 20:13:25 volumio volumio[914]: info: explodeTIDALUri took 393 milliseconds Mar 02 20:13:25 volumio volumio[914]: info: explodeTIDALUri took 417 milliseconds Mar 02 20:13:25 volumio volumio[914]: info: explodeTIDALUri took 429 milliseconds Mar 02 20:13:25 volumio volumio[914]: info: explodeTIDALUri took 482 milliseconds Mar 02 20:13:25 volumio volumio[914]: info: explodeTIDALUri took 548 milliseconds Mar 02 20:13:25 volumio volumio[914]: info: CorePlayQueue::saveQueue Mar 02 20:13:25 volumio volumio[914]: info: CoreCommandRouter::volumioPushQueue Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::updateTrackBlock Mar 02 20:13:25 volumio volumio[914]: info: CorePlayQueue::getTrackBlock Mar 02 20:13:25 volumio volumio[914]: info: CoreCommandRouter::volumioPlay Mar 02 20:13:25 volumio volumio[914]: UNSET VOLATILE Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::play index 4 Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::stop Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:13:25 volumio volumio[914]: UNSET VOLATILE Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::play index undefined Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:13:25 volumio volumio[914]: info: CorePlayQueue::getTrack 4 Mar 02 20:13:25 volumio volumio[914]: info: CoreStateMachine::startPlaybackTimer Mar 02 20:13:25 volumio volumio[914]: info: CorePlayQueue::getTrack 4 Mar 02 20:13:25 volumio volumio[914]: info: [1614716005646] ControllerTidal::clearAddPlayTrack Mar 02 20:13:25 volumio volumio[914]: info: Getting stream with soundQuality LOSSLESS Mar 02 20:13:26 volumio volumio[914]: info: getStreamUrl took 637 milliseconds Mar 02 20:13:26 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand stop Mar 02 20:13:26 volumio volumio[914]: info: sendMpdCommand stop took 2 milliseconds Mar 02 20:13:26 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand clear Mar 02 20:13:26 volumio volumio[914]: info: Mar 02 20:13:26 volumio volumio[914]: ---------------------------- MPD announces system playlist update Mar 02 20:13:26 volumio volumio[914]: info: Ignoring MPD Status Update Mar 02 20:13:26 volumio volumio[914]: info: sendMpdCommand clear took 5 milliseconds Mar 02 20:13:26 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand load "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInYzFlZjZkNjIxZTM3MWVlMzYzODM3YzljOWFiZmI1YTdfNjEubXA0/0.flac?token=1614719606~ZmJiYmVmYmVmMmEwYjZkNzkwODY0ZjZkMjMyYjFkNmI0YjRlMTNlZA==" Mar 02 20:13:26 volumio volumio[914]: error: updateQueue error: null Mar 02 20:13:26 volumio volumio[914]: info: ------------------------------ 10ms Mar 02 20:13:26 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand add "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInYzFlZjZkNjIxZTM3MWVlMzYzODM3YzljOWFiZmI1YTdfNjEubXA0/0.flac?token=1614719606~ZmJiYmVmYmVmMmEwYjZkNzkwODY0ZjZkMjMyYjFkNmI0YjRlMTNlZA==" Mar 02 20:13:26 volumio volumio[914]: info: Mar 02 20:13:26 volumio volumio[914]: ---------------------------- MPD announces system playlist update Mar 02 20:13:26 volumio volumio[914]: info: Ignoring MPD Status Update Mar 02 20:13:26 volumio volumio[914]: info: sendMpdCommand add "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInYzFlZjZkNjIxZTM3MWVlMzYzODM3YzljOWFiZmI1YTdfNjEubXA0/0.flac?token=1614719606~ZmJiYmVmYmVmMmEwYjZkNzkwODY0ZjZkMjMyYjFkNmI0YjRlMTNlZA==" took 2 milliseconds Mar 02 20:13:26 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 02 20:13:26 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand play Mar 02 20:13:26 volumio volumio[914]: info: ------------------------------ 5ms Mar 02 20:13:26 volumio volumio[914]: info: sendMpdCommand play took 3 milliseconds Mar 02 20:13:26 volumio volumio[914]: info: Mar 02 20:13:26 volumio volumio[914]: ---------------------------- MPD announces state update: player Mar 02 20:13:26 volumio volumio[914]: info: ControllerMpd::getState Mar 02 20:13:26 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Mar 02 20:13:26 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Mar 02 20:13:26 volumio volumio[914]: info: Mar 02 20:13:26 volumio volumio[914]: ---------------------------- MPD announces state update: player Mar 02 20:13:26 volumio volumio[914]: info: sendMpdCommand status took 19 milliseconds Mar 02 20:13:26 volumio volumio[914]: info: ControllerMpd::getState Mar 02 20:13:26 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Mar 02 20:13:26 volumio volumio[914]: verbose: ControllerMpd::parseState Mar 02 20:13:26 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 20:13:26 volumio volumio[914]: info: sendMpdCommand status took 3 milliseconds Mar 02 20:13:26 volumio volumio[914]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 02 20:13:26 volumio volumio[914]: verbose: ControllerMpd::parseState Mar 02 20:13:26 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 20:13:26 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Mar 02 20:13:26 volumio volumio[914]: info: ControllerMpd::pushState Mar 02 20:13:26 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 02 20:13:26 volumio volumio[914]: info: CorePlayQueue::getTrack 4 Mar 02 20:13:26 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":603,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1614719606~ZmJiYmVmYmVmMmEwYjZkNzkwODY0ZjZkMjMyYjFkNmI0YjRlMTNlZA==","artist":null,"album":null,"uri":"http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInYzFlZjZkNjIxZTM3MWVlMzYzODM3YzljOWFiZmI1YTdfNjEubXA0/0.flac?token=1614719606~ZmJiYmVmYmVmMmEwYjZkNzkwODY0ZjZkMjMyYjFkNmI0YjRlMTNlZA==","trackType":"tidal"} Mar 02 20:13:26 volumio volumio[914]: verbose: CURRENT POSITION 4 Mar 02 20:13:26 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Mar 02 20:13:26 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus stop Mar 02 20:13:26 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:13:26 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:13:26 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:13:26 volumio volumio[914]: info: ------------------------------ 41ms Mar 02 20:13:26 volumio volumio[914]: info: sendMpdCommand playlistinfo took 20 milliseconds Mar 02 20:13:26 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Mar 02 20:13:26 volumio volumio[914]: info: ControllerMpd::pushState Mar 02 20:13:26 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 02 20:13:26 volumio volumio[914]: info: CorePlayQueue::getTrack 4 Mar 02 20:13:26 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":464,"duration":603,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"374 Kbps","isStreaming":false,"title":"0.flac?token=1614719606~ZmJiYmVmYmVmMmEwYjZkNzkwODY0ZjZkMjMyYjFkNmI0YjRlMTNlZA==","artist":null,"album":null,"uri":"http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInYzFlZjZkNjIxZTM3MWVlMzYzODM3YzljOWFiZmI1YTdfNjEubXA0/0.flac?token=1614719606~ZmJiYmVmYmVmMmEwYjZkNzkwODY0ZjZkMjMyYjFkNmI0YjRlMTNlZA==","trackType":"tidal"} Mar 02 20:13:26 volumio volumio[914]: verbose: CURRENT POSITION 4 Mar 02 20:13:26 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Mar 02 20:13:26 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus play Mar 02 20:13:26 volumio volumio[914]: info: Received an update from plugin. extracting info from payload Mar 02 20:13:26 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:13:26 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:13:26 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:13:26 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:13:26 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:13:26 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:13:26 volumio volumio[914]: info: ------------------------------ 53ms Mar 02 20:13:46 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 02 20:13:47 volumio volumio[914]: info: browseTIDALUri took 198 milliseconds Mar 02 20:13:49 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 02 20:13:49 volumio volumio[914]: info: browseTIDALUri took 451 milliseconds Mar 02 20:13:55 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 02 20:13:55 volumio volumio[914]: info: browseTIDALUri took 381 milliseconds Mar 02 20:13:59 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 02 20:14:00 volumio volumio[914]: info: browseTIDALUri took 455 milliseconds Mar 02 20:14:05 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 02 20:14:06 volumio volumio[914]: info: browseTIDALUri took 465 milliseconds Mar 02 20:14:21 volumio volumio[914]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 02 20:14:21 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 02 20:14:21 volumio volumio[914]: info: Received Get System Version Mar 02 20:14:21 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 02 20:14:24 volumio volumio[914]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 02 20:14:26 volumio volumio[914]: info: CoreCommandRouter::Close All Modals sent Mar 02 20:14:53 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 02 20:14:53 volumio volumio[914]: info: browseTIDALUri took 362 milliseconds Mar 02 20:14:59 volumio volumio[914]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 02 20:14:59 volumio volumio[914]: info: CoreStateMachine::ClearQueue Mar 02 20:14:59 volumio volumio[914]: info: CoreStateMachine::stop Mar 02 20:14:59 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:14:59 volumio volumio[914]: UNSET VOLATILE Mar 02 20:14:59 volumio volumio[914]: info: CoreStateMachine::stPlaybackTimer Mar 02 20:14:59 volumio volumio[914]: info: CoreStateMachine::updateTrackBlock Mar 02 20:14:59 volumio volumio[914]: info: CorePlayQueue::getTrackBlock Mar 02 20:14:59 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:14:59 volumio volumio[914]: info: CorePlayQueue::getTrack 4 Mar 02 20:14:59 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:14:59 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:14:59 volumio volumio[914]: info: CoreStateMachine::serviceStop Mar 02 20:14:59 volumio volumio[914]: info: CorePlayQueue::getTrack 4 Mar 02 20:14:59 volumio volumio[914]: info: CoreCommandRouter::serviceStop Mar 02 20:14:59 volumio volumio[914]: info: [1614716099732] ControllerTidal::stop Mar 02 20:14:59 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 02 20:14:59 volumio volumio[914]: info: ControllerMpd::stop Mar 02 20:14:59 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand stop Mar 02 20:14:59 volumio volumio[914]: info: CorePlayQueue::clearPlayQueue Mar 02 20:14:59 volumio volumio[914]: info: CorePlayQueue::saveQueue Mar 02 20:14:59 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:14:59 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:14:59 volumio volumio[914]: info: CoreCommandRouter::volumioPushQueue Mar 02 20:14:59 volumio volumio[914]: info: CoreStateMachine::addQueueItems Mar 02 20:14:59 volumio volumio[914]: info: CorePlayQueue::addQueueItems Mar 02 20:14:59 volumio volumio[914]: info: Adding Item to queue: tidal://mymusic/mixes/0027f45af2489747b167b63021f9bf Mar 02 20:14:59 volumio volumio[914]: info: Exploding uri tidal://mymusic/mixes/0027f45af2489747b167b63021f9bf in service tidal Mar 02 20:14:59 volumio volumio[914]: info: Mar 02 20:14:59 volumio volumio[914]: ---------------------------- MPD announces state update: player Mar 02 20:14:59 volumio volumio[914]: info: sendMpdCommand stop took 113 milliseconds Mar 02 20:14:59 volumio volumio[914]: info: ControllerMpd::getState Mar 02 20:14:59 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Mar 02 20:14:59 volumio volumio[914]: info: sendMpdCommand status took 6 milliseconds Mar 02 20:14:59 volumio volumio[914]: verbose: ControllerMpd::parseState Mar 02 20:14:59 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 20:14:59 volumio volumio[914]: info: sendMpdCommand playlistinfo took 7 milliseconds Mar 02 20:14:59 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Mar 02 20:14:59 volumio volumio[914]: info: ControllerMpd::pushState Mar 02 20:14:59 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 02 20:14:59 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:14:59 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:14:59 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:14:59 volumio volumio[914]: info: CorePlayQueue::getTrack 4 Mar 02 20:14:59 volumio volumio[914]: 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":"0.flac?token=1614719606~ZmJiYmVmYmVmMmEwYjZkNzkwODY0ZjZkMjMyYjFkNmI0YjRlMTNlZA==","artist":null,"album":null,"uri":"http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInYzFlZjZkNjIxZTM3MWVlMzYzODM3YzljOWFiZmI1YTdfNjEubXA0/0.flac?token=1614719606~ZmJiYmVmYmVmMmEwYjZkNzkwODY0ZjZkMjMyYjFkNmI0YjRlMTNlZA==","trackType":"tidal"} Mar 02 20:14:59 volumio volumio[914]: verbose: CURRENT POSITION 4 Mar 02 20:14:59 volumio volumio[914]: info: CoreStateMachine::syncState stateService stop Mar 02 20:14:59 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus stop Mar 02 20:14:59 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:14:59 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:14:59 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:14:59 volumio volumio[914]: info: No code Mar 02 20:14:59 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:14:59 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:14:59 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:14:59 volumio volumio[914]: info: ------------------------------ 42ms Mar 02 20:15:00 volumio volumio[914]: info: explodeTIDALUri took 465 milliseconds Mar 02 20:15:00 volumio volumio[914]: info: CorePlayQueue::saveQueue Mar 02 20:15:00 volumio volumio[914]: info: CoreCommandRouter::volumioPushQueue Mar 02 20:15:00 volumio volumio[914]: info: CoreStateMachine::updateTrackBlock Mar 02 20:15:00 volumio volumio[914]: info: CorePlayQueue::getTrackBlock Mar 02 20:15:00 volumio volumio[914]: info: CoreCommandRouter::volumioPlay Mar 02 20:15:00 volumio volumio[914]: UNSET VOLATILE Mar 02 20:15:00 volumio volumio[914]: info: CoreStateMachine::play index 0 Mar 02 20:15:00 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:15:00 volumio volumio[914]: info: CoreStateMachine::stop Mar 02 20:15:00 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:15:00 volumio volumio[914]: UNSET VOLATILE Mar 02 20:15:00 volumio volumio[914]: info: CoreStateMachine::play index undefined Mar 02 20:15:00 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:15:00 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:15:00 volumio volumio[914]: info: CoreStateMachine::startPlaybackTimer Mar 02 20:15:00 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:15:00 volumio volumio[914]: info: [1614716100225] ControllerTidal::clearAddPlayTrack Mar 02 20:15:00 volumio volumio[914]: info: Getting stream with soundQuality LOSSLESS Mar 02 20:15:00 volumio volumio[914]: info: getStreamUrl took 346 milliseconds Mar 02 20:15:00 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand stop Mar 02 20:15:00 volumio volumio[914]: info: sendMpdCommand stop took 1 milliseconds Mar 02 20:15:00 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand clear Mar 02 20:15:00 volumio volumio[914]: info: Mar 02 20:15:00 volumio volumio[914]: ---------------------------- MPD announces system playlist update Mar 02 20:15:00 volumio volumio[914]: info: Ignoring MPD Status Update Mar 02 20:15:00 volumio volumio[914]: info: sendMpdCommand clear took 4 milliseconds Mar 02 20:15:00 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand load "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInMzNmNTY0YjdmNDhhYWNlZDk2NTBjZGQwZmI1NjRlMTlfNjEubXA0/0.flac?token=1614719700~NTRiNjdkZjgyNjE2Nzk0MGQ0OGVhYzI0ODQ3Mjg4ZjJkOGJlODVmMg==" Mar 02 20:15:00 volumio volumio[914]: error: updateQueue error: null Mar 02 20:15:00 volumio volumio[914]: info: ------------------------------ 9ms Mar 02 20:15:00 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand add "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInMzNmNTY0YjdmNDhhYWNlZDk2NTBjZGQwZmI1NjRlMTlfNjEubXA0/0.flac?token=1614719700~NTRiNjdkZjgyNjE2Nzk0MGQ0OGVhYzI0ODQ3Mjg4ZjJkOGJlODVmMg==" Mar 02 20:15:00 volumio volumio[914]: info: Mar 02 20:15:00 volumio volumio[914]: ---------------------------- MPD announces system playlist update Mar 02 20:15:00 volumio volumio[914]: info: Ignoring MPD Status Update Mar 02 20:15:00 volumio volumio[914]: info: sendMpdCommand add "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInMzNmNTY0YjdmNDhhYWNlZDk2NTBjZGQwZmI1NjRlMTlfNjEubXA0/0.flac?token=1614719700~NTRiNjdkZjgyNjE2Nzk0MGQ0OGVhYzI0ODQ3Mjg4ZjJkOGJlODVmMg==" took 2 milliseconds Mar 02 20:15:00 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 02 20:15:00 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand play Mar 02 20:15:00 volumio volumio[914]: info: ------------------------------ 3ms Mar 02 20:15:00 volumio volumio[914]: info: sendMpdCommand play took 6 milliseconds Mar 02 20:15:00 volumio volumio[914]: info: Mar 02 20:15:00 volumio volumio[914]: ---------------------------- MPD announces state update: player Mar 02 20:15:00 volumio volumio[914]: info: ControllerMpd::getState Mar 02 20:15:00 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Mar 02 20:15:00 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Mar 02 20:15:00 volumio volumio[914]: info: Mar 02 20:15:00 volumio volumio[914]: ---------------------------- MPD announces state update: player Mar 02 20:15:00 volumio volumio[914]: info: sendMpdCommand status took 14 milliseconds Mar 02 20:15:00 volumio volumio[914]: info: ControllerMpd::getState Mar 02 20:15:00 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Mar 02 20:15:00 volumio volumio[914]: verbose: ControllerMpd::parseState Mar 02 20:15:00 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 20:15:00 volumio volumio[914]: info: sendMpdCommand status took 10 milliseconds Mar 02 20:15:00 volumio volumio[914]: info: sendMpdCommand playlistinfo took 10 milliseconds Mar 02 20:15:00 volumio volumio[914]: verbose: ControllerMpd::parseState Mar 02 20:15:00 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 20:15:00 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Mar 02 20:15:00 volumio volumio[914]: info: ControllerMpd::pushState Mar 02 20:15:00 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 02 20:15:00 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:15:00 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":330,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1614719700~NTRiNjdkZjgyNjE2Nzk0MGQ0OGVhYzI0ODQ3Mjg4ZjJkOGJlODVmMg==","artist":null,"album":null,"uri":"http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInMzNmNTY0YjdmNDhhYWNlZDk2NTBjZGQwZmI1NjRlMTlfNjEubXA0/0.flac?token=1614719700~NTRiNjdkZjgyNjE2Nzk0MGQ0OGVhYzI0ODQ3Mjg4ZjJkOGJlODVmMg==","trackType":"tidal"} Mar 02 20:15:00 volumio volumio[914]: verbose: CURRENT POSITION 0 Mar 02 20:15:00 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Mar 02 20:15:00 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus stop Mar 02 20:15:00 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:15:00 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:15:00 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:15:00 volumio volumio[914]: info: ------------------------------ 49ms Mar 02 20:15:01 volumio volumio[914]: info: sendMpdCommand playlistinfo took 45 milliseconds Mar 02 20:15:01 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Mar 02 20:15:01 volumio volumio[914]: info: ControllerMpd::pushState Mar 02 20:15:01 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 02 20:15:01 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:15:01 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":464,"duration":330,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"689 Kbps","isStreaming":false,"title":"0.flac?token=1614719700~NTRiNjdkZjgyNjE2Nzk0MGQ0OGVhYzI0ODQ3Mjg4ZjJkOGJlODVmMg==","artist":null,"album":null,"uri":"http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInMzNmNTY0YjdmNDhhYWNlZDk2NTBjZGQwZmI1NjRlMTlfNjEubXA0/0.flac?token=1614719700~NTRiNjdkZjgyNjE2Nzk0MGQ0OGVhYzI0ODQ3Mjg4ZjJkOGJlODVmMg==","trackType":"tidal"} Mar 02 20:15:01 volumio volumio[914]: verbose: CURRENT POSITION 0 Mar 02 20:15:01 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Mar 02 20:15:01 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus play Mar 02 20:15:01 volumio volumio[914]: info: Received an update from plugin. extracting info from payload Mar 02 20:15:01 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:15:01 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:15:01 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:15:01 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:15:01 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:15:01 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:15:01 volumio volumio[914]: info: ------------------------------ 82ms Mar 02 20:15:05 volumio volumio[914]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::ClearQueue Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::stop Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:15:05 volumio volumio[914]: UNSET VOLATILE Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::stPlaybackTimer Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::updateTrackBlock Mar 02 20:15:05 volumio volumio[914]: info: CorePlayQueue::getTrackBlock Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:15:05 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:15:05 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:15:05 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::serviceStop Mar 02 20:15:05 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:15:05 volumio volumio[914]: info: CoreCommandRouter::serviceStop Mar 02 20:15:05 volumio volumio[914]: info: [1614716105194] ControllerTidal::stop Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 02 20:15:05 volumio volumio[914]: info: ControllerMpd::stop Mar 02 20:15:05 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand stop Mar 02 20:15:05 volumio volumio[914]: info: CorePlayQueue::clearPlayQueue Mar 02 20:15:05 volumio volumio[914]: info: CorePlayQueue::saveQueue Mar 02 20:15:05 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:15:05 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:15:05 volumio volumio[914]: info: CoreCommandRouter::volumioPushQueue Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::addQueueItems Mar 02 20:15:05 volumio volumio[914]: info: CorePlayQueue::addQueueItems Mar 02 20:15:05 volumio volumio[914]: info: Adding Item to queue: tidal://mymusic/mixes/0020d481b423fc90735f65ef5802c3 Mar 02 20:15:05 volumio volumio[914]: info: Exploding uri tidal://mymusic/mixes/0020d481b423fc90735f65ef5802c3 in service tidal Mar 02 20:15:05 volumio volumio[914]: info: Mar 02 20:15:05 volumio volumio[914]: ---------------------------- MPD announces state update: player Mar 02 20:15:05 volumio volumio[914]: info: sendMpdCommand stop took 62 milliseconds Mar 02 20:15:05 volumio volumio[914]: info: ControllerMpd::getState Mar 02 20:15:05 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Mar 02 20:15:05 volumio volumio[914]: info: sendMpdCommand status took 1 milliseconds Mar 02 20:15:05 volumio volumio[914]: verbose: ControllerMpd::parseState Mar 02 20:15:05 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 20:15:05 volumio volumio[914]: info: sendMpdCommand playlistinfo took 5 milliseconds Mar 02 20:15:05 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Mar 02 20:15:05 volumio volumio[914]: info: ControllerMpd::pushState Mar 02 20:15:05 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:15:05 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:15:05 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:15:05 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:15:05 volumio volumio[914]: 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":"0.flac?token=1614719700~NTRiNjdkZjgyNjE2Nzk0MGQ0OGVhYzI0ODQ3Mjg4ZjJkOGJlODVmMg==","artist":null,"album":null,"uri":"http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInMzNmNTY0YjdmNDhhYWNlZDk2NTBjZGQwZmI1NjRlMTlfNjEubXA0/0.flac?token=1614719700~NTRiNjdkZjgyNjE2Nzk0MGQ0OGVhYzI0ODQ3Mjg4ZjJkOGJlODVmMg==","trackType":"tidal"} Mar 02 20:15:05 volumio volumio[914]: verbose: CURRENT POSITION 0 Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::syncState stateService stop Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus stop Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:15:05 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:15:05 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:15:05 volumio volumio[914]: info: No code Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:15:05 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:15:05 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:15:05 volumio volumio[914]: info: ------------------------------ 37ms Mar 02 20:15:05 volumio volumio[914]: info: explodeTIDALUri took 486 milliseconds Mar 02 20:15:05 volumio volumio[914]: info: CorePlayQueue::saveQueue Mar 02 20:15:05 volumio volumio[914]: info: CoreCommandRouter::volumioPushQueue Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::updateTrackBlock Mar 02 20:15:05 volumio volumio[914]: info: CorePlayQueue::getTrackBlock Mar 02 20:15:05 volumio volumio[914]: info: CoreCommandRouter::volumioPlay Mar 02 20:15:05 volumio volumio[914]: UNSET VOLATILE Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::play index 0 Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::stop Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:15:05 volumio volumio[914]: UNSET VOLATILE Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::play index undefined Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:15:05 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:15:05 volumio volumio[914]: info: CoreStateMachine::startPlaybackTimer Mar 02 20:15:05 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:15:05 volumio volumio[914]: info: [1614716105702] ControllerTidal::clearAddPlayTrack Mar 02 20:15:05 volumio volumio[914]: info: Getting stream with soundQuality HI_RES Mar 02 20:15:06 volumio volumio[914]: info: getStreamUrl took 333 milliseconds Mar 02 20:15:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand stop Mar 02 20:15:06 volumio volumio[914]: info: sendMpdCommand stop took 1 milliseconds Mar 02 20:15:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand clear Mar 02 20:15:06 volumio volumio[914]: info: Mar 02 20:15:06 volumio volumio[914]: ---------------------------- MPD announces system playlist update Mar 02 20:15:06 volumio volumio[914]: info: Ignoring MPD Status Update Mar 02 20:15:06 volumio volumio[914]: info: sendMpdCommand clear took 4 milliseconds Mar 02 20:15:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand load "http://ab-pr-fa.audio.tidal.com/d74a4ade474c28c47ede2c87d4dc104b_39.flac?token=1614719705~MjMwMjU5OTY1NGU2YzU0ZmFjNTgyN2Q2MDI2MzEwNTA2Y2JhZGZlZg==" Mar 02 20:15:06 volumio volumio[914]: error: updateQueue error: null Mar 02 20:15:06 volumio volumio[914]: info: ------------------------------ 9ms Mar 02 20:15:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand add "http://ab-pr-fa.audio.tidal.com/d74a4ade474c28c47ede2c87d4dc104b_39.flac?token=1614719705~MjMwMjU5OTY1NGU2YzU0ZmFjNTgyN2Q2MDI2MzEwNTA2Y2JhZGZlZg==" Mar 02 20:15:06 volumio volumio[914]: info: Mar 02 20:15:06 volumio volumio[914]: ---------------------------- MPD announces system playlist update Mar 02 20:15:06 volumio volumio[914]: info: Ignoring MPD Status Update Mar 02 20:15:06 volumio volumio[914]: info: sendMpdCommand add "http://ab-pr-fa.audio.tidal.com/d74a4ade474c28c47ede2c87d4dc104b_39.flac?token=1614719705~MjMwMjU5OTY1NGU2YzU0ZmFjNTgyN2Q2MDI2MzEwNTA2Y2JhZGZlZg==" took 2 milliseconds Mar 02 20:15:06 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 02 20:15:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand play Mar 02 20:15:06 volumio volumio[914]: info: ------------------------------ 3ms Mar 02 20:15:06 volumio volumio[914]: info: sendMpdCommand play took 2 milliseconds Mar 02 20:15:06 volumio volumio[914]: info: Mar 02 20:15:06 volumio volumio[914]: ---------------------------- MPD announces state update: player Mar 02 20:15:06 volumio volumio[914]: info: ControllerMpd::getState Mar 02 20:15:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Mar 02 20:15:06 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Mar 02 20:15:06 volumio volumio[914]: info: Mar 02 20:15:06 volumio volumio[914]: ---------------------------- MPD announces state update: player Mar 02 20:15:06 volumio volumio[914]: info: sendMpdCommand status took 14 milliseconds Mar 02 20:15:06 volumio volumio[914]: info: ControllerMpd::getState Mar 02 20:15:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Mar 02 20:15:06 volumio volumio[914]: verbose: ControllerMpd::parseState Mar 02 20:15:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 20:15:06 volumio volumio[914]: info: sendMpdCommand status took 7 milliseconds Mar 02 20:15:06 volumio volumio[914]: info: sendMpdCommand playlistinfo took 7 milliseconds Mar 02 20:15:06 volumio volumio[914]: verbose: ControllerMpd::parseState Mar 02 20:15:06 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 20:15:06 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Mar 02 20:15:06 volumio volumio[914]: info: ControllerMpd::pushState Mar 02 20:15:06 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 02 20:15:06 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:15:06 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":206,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"196 Kbps","isStreaming":false,"title":"d74a4ade474c28c47ede2c87d4dc104b_39.flac?token=1614719705~MjMwMjU5OTY1NGU2YzU0ZmFjNTgyN2Q2MDI2MzEwNTA2Y2JhZGZlZg==","artist":null,"album":null,"uri":"http://ab-pr-fa.audio.tidal.com/d74a4ade474c28c47ede2c87d4dc104b_39.flac?token=1614719705~MjMwMjU5OTY1NGU2YzU0ZmFjNTgyN2Q2MDI2MzEwNTA2Y2JhZGZlZg==","trackType":"tidal"} Mar 02 20:15:06 volumio volumio[914]: verbose: CURRENT POSITION 0 Mar 02 20:15:06 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Mar 02 20:15:06 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus stop Mar 02 20:15:06 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:15:06 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:15:06 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:15:06 volumio volumio[914]: info: ------------------------------ 37ms Mar 02 20:15:06 volumio volumio[914]: info: sendMpdCommand playlistinfo took 17 milliseconds Mar 02 20:15:06 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Mar 02 20:15:06 volumio volumio[914]: info: ControllerMpd::pushState Mar 02 20:15:06 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 02 20:15:06 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:15:06 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":464,"duration":206,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"696 Kbps","isStreaming":false,"title":"d74a4ade474c28c47ede2c87d4dc104b_39.flac?token=1614719705~MjMwMjU5OTY1NGU2YzU0ZmFjNTgyN2Q2MDI2MzEwNTA2Y2JhZGZlZg==","artist":null,"album":null,"uri":"http://ab-pr-fa.audio.tidal.com/d74a4ade474c28c47ede2c87d4dc104b_39.flac?token=1614719705~MjMwMjU5OTY1NGU2YzU0ZmFjNTgyN2Q2MDI2MzEwNTA2Y2JhZGZlZg==","trackType":"tidal"} Mar 02 20:15:06 volumio volumio[914]: verbose: CURRENT POSITION 0 Mar 02 20:15:06 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Mar 02 20:15:06 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus play Mar 02 20:15:06 volumio volumio[914]: info: Received an update from plugin. extracting info from payload Mar 02 20:15:06 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:15:06 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:15:06 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:15:06 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:15:06 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:15:06 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:15:06 volumio volumio[914]: info: ------------------------------ 46ms Mar 02 20:15:09 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 02 20:15:09 volumio volumio[914]: info: browseTIDALUri took 240 milliseconds Mar 02 20:15:37 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 02 20:15:38 volumio volumio[914]: info: browseTIDALUri took 367 milliseconds Mar 02 20:15:44 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 02 20:15:44 volumio volumio[914]: info: browseTIDALUri took 457 milliseconds Mar 02 20:15:53 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 02 20:15:53 volumio volumio[914]: info: browseTIDALUri took 492 milliseconds Mar 02 20:18:27 volumio volumio[914]: info: CorePlayQueue::getTrack 0 Mar 02 20:18:27 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 02 20:18:27 volumio volumio[914]: info: Prefetching next song Mar 02 20:18:27 volumio volumio[914]: info: [1614716307486] ControllerTidal::prefetch Mar 02 20:18:27 volumio volumio[914]: info: Getting stream with soundQuality LOSSLESS Mar 02 20:18:27 volumio volumio[914]: info: getStreamUrl took 388 milliseconds Mar 02 20:18:27 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand load "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInMTY2NzUwMDI5ODNjNjc3YmYxZWMxYjExMjg2NDFjZWVfNjEubXA0/0.flac?token=1614719907~M2VmOGFhMmIxMjY2MmRlOWZlZjU5ODQzMThiZjBmMDNjMDdiYzQyMQ==" Mar 02 20:18:28 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand add "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInMTY2NzUwMDI5ODNjNjc3YmYxZWMxYjExMjg2NDFjZWVfNjEubXA0/0.flac?token=1614719907~M2VmOGFhMmIxMjY2MmRlOWZlZjU5ODQzMThiZjBmMDNjMDdiYzQyMQ==" Mar 02 20:18:28 volumio volumio[914]: info: Mar 02 20:18:28 volumio volumio[914]: ---------------------------- MPD announces system playlist update Mar 02 20:18:28 volumio volumio[914]: info: Ignoring MPD Status Update Mar 02 20:18:28 volumio volumio[914]: info: sendMpdCommand add "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInMTY2NzUwMDI5ODNjNjc3YmYxZWMxYjExMjg2NDFjZWVfNjEubXA0/0.flac?token=1614719907~M2VmOGFhMmIxMjY2MmRlOWZlZjU5ODQzMThiZjBmMDNjMDdiYzQyMQ==" took 6 milliseconds Mar 02 20:18:28 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 02 20:18:28 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand consume 1 Mar 02 20:18:28 volumio volumio[914]: info: Mar 02 20:18:28 volumio volumio[914]: ---------------------------- MPD announces state update: options Mar 02 20:18:28 volumio volumio[914]: info: ------------------------------ 17ms Mar 02 20:18:28 volumio volumio[914]: info: sendMpdCommand consume 1 took 8 milliseconds Mar 02 20:18:28 volumio volumio[914]: info: ControllerMpd::getState Mar 02 20:18:28 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Mar 02 20:18:28 volumio volumio[914]: info: sendMpdCommand status took 3 milliseconds Mar 02 20:18:28 volumio volumio[914]: verbose: ControllerMpd::parseState Mar 02 20:18:28 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 20:18:28 volumio volumio[914]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 02 20:18:28 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Mar 02 20:18:28 volumio volumio[914]: info: ControllerMpd::pushState Mar 02 20:18:28 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 02 20:18:28 volumio volumio[914]: info: CoreStateMachine::startPlaybackTimer Mar 02 20:18:28 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 02 20:18:28 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 02 20:18:28 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":202060,"duration":206,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"556 Kbps","isStreaming":false,"title":"d74a4ade474c28c47ede2c87d4dc104b_39.flac?token=1614719705~MjMwMjU5OTY1NGU2YzU0ZmFjNTgyN2Q2MDI2MzEwNTA2Y2JhZGZlZg==","artist":null,"album":null,"uri":"http://ab-pr-fa.audio.tidal.com/d74a4ade474c28c47ede2c87d4dc104b_39.flac?token=1614719705~MjMwMjU5OTY1NGU2YzU0ZmFjNTgyN2Q2MDI2MzEwNTA2Y2JhZGZlZg==","trackType":"tidal"} Mar 02 20:18:28 volumio volumio[914]: verbose: CURRENT POSITION 1 Mar 02 20:18:28 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Mar 02 20:18:28 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus play Mar 02 20:18:28 volumio volumio[914]: info: Received an update from plugin. extracting info from payload Mar 02 20:18:28 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:18:28 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:18:28 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:18:28 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:18:28 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:18:28 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:18:28 volumio volumio[914]: info: ------------------------------ 31ms Mar 02 20:18:32 volumio volumio[914]: info: Mar 02 20:18:32 volumio volumio[914]: ---------------------------- MPD announces system playlist update Mar 02 20:18:32 volumio volumio[914]: info: Ignoring MPD Status Update Mar 02 20:18:32 volumio volumio[914]: info: Mar 02 20:18:32 volumio volumio[914]: ---------------------------- MPD announces state update: player Mar 02 20:18:32 volumio volumio[914]: info: ControllerMpd::getState Mar 02 20:18:32 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand status Mar 02 20:18:32 volumio volumio[914]: info: ------------------------------ 8ms Mar 02 20:18:32 volumio volumio[914]: info: sendMpdCommand status took 8 milliseconds Mar 02 20:18:32 volumio volumio[914]: verbose: ControllerMpd::parseState Mar 02 20:18:32 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 20:18:32 volumio volumio[914]: info: sendMpdCommand playlistinfo took 10 milliseconds Mar 02 20:18:32 volumio volumio[914]: verbose: ControllerMpd::parseTrackInfo Mar 02 20:18:32 volumio volumio[914]: info: ControllerMpd::pushState Mar 02 20:18:32 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 02 20:18:32 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 02 20:18:32 volumio volumio[914]: verbose: STATE SERVICE {"status":"play","position":0,"seek":46,"duration":293,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"450 Kbps","isStreaming":false,"title":"0.flac?token=1614719907~M2VmOGFhMmIxMjY2MmRlOWZlZjU5ODQzMThiZjBmMDNjMDdiYzQyMQ==","artist":null,"album":null,"uri":"http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInMTY2NzUwMDI5ODNjNjc3YmYxZWMxYjExMjg2NDFjZWVfNjEubXA0/0.flac?token=1614719907~M2VmOGFhMmIxMjY2MmRlOWZlZjU5ODQzMThiZjBmMDNjMDdiYzQyMQ==","trackType":"tidal"} Mar 02 20:18:32 volumio volumio[914]: verbose: CURRENT POSITION 1 Mar 02 20:18:32 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Mar 02 20:18:32 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus play Mar 02 20:18:32 volumio volumio[914]: info: Received an update from plugin. extracting info from payload Mar 02 20:18:32 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:18:32 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:18:32 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:18:32 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:18:32 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:18:32 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:18:32 volumio volumio[914]: info: ------------------------------ 43ms Mar 02 20:23:15 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 02 20:23:15 volumio volumio[914]: info: CorePlayQueue::getTrack 2 Mar 02 20:23:15 volumio volumio[914]: info: Prefetching next song Mar 02 20:23:15 volumio volumio[914]: info: [1614716595286] ControllerTidal::prefetch Mar 02 20:23:15 volumio volumio[914]: info: Getting stream with soundQuality HI_RES Mar 02 20:23:15 volumio volumio[914]: info: getStreamUrl took 404 milliseconds Mar 02 20:23:15 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand load "http://ab-pr-fa.audio.tidal.com/b8dbd3aa6d9bc92d3b66b9c051e89ea4_39.flac?token=1614720195~ZDEzOTcxM2NjNmViZjM1ODY0MDI5NmE5Zjc3ZjdlMTNiZjdhNGIxNg==" Mar 02 20:23:19 volumio volumio[914]: info: CoreStateMachine::startPlaybackTimer Mar 02 20:23:19 volumio volumio[914]: info: CorePlayQueue::getTrack 2 Mar 02 20:23:24 volumio volumio[914]: info: CoreCommandRouter::volumioNext Mar 02 20:23:24 volumio volumio[914]: info: CoreStateMachine::next Mar 02 20:23:24 volumio volumio[914]: info: [1614716604506] ControllerTidal::next Mar 02 20:23:24 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:23:24 volumio volumio[914]: info: CoreStateMachine::next Mar 02 20:23:24 volumio volumio[914]: info: CoreStateMachine::stop Mar 02 20:23:24 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:23:24 volumio volumio[914]: UNSET VOLATILE Mar 02 20:23:24 volumio volumio[914]: info: CoreStateMachine::stPlaybackTimer Mar 02 20:23:24 volumio volumio[914]: info: CoreStateMachine::updateTrackBlock Mar 02 20:23:24 volumio volumio[914]: info: CorePlayQueue::getTrackBlock Mar 02 20:23:24 volumio volumio[914]: info: CoreStateMachine::pushState Mar 02 20:23:24 volumio volumio[914]: info: CorePlayQueue::getTrack 2 Mar 02 20:23:24 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 02 20:23:24 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 20:23:24 volumio volumio[914]: info: CoreStateMachine::serviceStop Mar 02 20:23:24 volumio volumio[914]: info: CorePlayQueue::getTrack 2 Mar 02 20:23:24 volumio volumio[914]: info: CoreCommandRouter::serviceStop Mar 02 20:23:24 volumio volumio[914]: info: [1614716604520] ControllerTidal::stop Mar 02 20:23:24 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 02 20:23:24 volumio volumio[914]: info: ControllerMpd::stop Mar 02 20:23:24 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand stop Mar 02 20:23:38 volumio volumio[914]: info: CoreCommandRouter::volumioPlay Mar 02 20:23:38 volumio volumio[914]: UNSET VOLATILE Mar 02 20:23:38 volumio volumio[914]: info: CoreStateMachine::play index undefined Mar 02 20:23:38 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:23:38 volumio volumio[914]: info: CorePlayQueue::getTrack 2 Mar 02 20:23:38 volumio volumio[914]: info: CoreStateMachine::startPlaybackTimer Mar 02 20:23:38 volumio volumio[914]: info: CorePlayQueue::getTrack 2 Mar 02 20:23:38 volumio volumio[914]: info: [1614716618337] ControllerTidal::clearAddPlayTrack Mar 02 20:23:38 volumio volumio[914]: info: Getting stream with soundQuality HI_RES Mar 02 20:23:38 volumio volumio[914]: info: getStreamUrl took 354 milliseconds Mar 02 20:23:38 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand stop Mar 02 20:23:55 volumio volumio[914]: info: CoreCommandRouter::volumioPlay Mar 02 20:23:55 volumio volumio[914]: UNSET VOLATILE Mar 02 20:23:55 volumio volumio[914]: info: CoreStateMachine::play index 2 Mar 02 20:23:55 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:23:55 volumio volumio[914]: info: CoreStateMachine::stop Mar 02 20:23:55 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:23:55 volumio volumio[914]: UNSET VOLATILE Mar 02 20:23:55 volumio volumio[914]: info: CoreStateMachine::play index undefined Mar 02 20:23:55 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:23:55 volumio volumio[914]: info: CorePlayQueue::getTrack 2 Mar 02 20:23:55 volumio volumio[914]: info: CoreStateMachine::startPlaybackTimer Mar 02 20:23:55 volumio volumio[914]: info: CorePlayQueue::getTrack 2 Mar 02 20:23:55 volumio volumio[914]: info: [1614716635597] ControllerTidal::clearAddPlayTrack Mar 02 20:23:55 volumio volumio[914]: info: Getting stream with soundQuality HI_RES Mar 02 20:23:55 volumio volumio[914]: info: getStreamUrl took 284 milliseconds Mar 02 20:23:55 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand stop Mar 02 20:24:14 volumio volumio[914]: info: CoreCommandRouter::volumioPlay Mar 02 20:24:14 volumio volumio[914]: UNSET VOLATILE Mar 02 20:24:14 volumio volumio[914]: info: CoreStateMachine::play index 1 Mar 02 20:24:14 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:24:14 volumio volumio[914]: info: CoreStateMachine::stop Mar 02 20:24:14 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:24:14 volumio volumio[914]: UNSET VOLATILE Mar 02 20:24:14 volumio volumio[914]: info: CoreStateMachine::play index undefined Mar 02 20:24:14 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 20:24:14 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 02 20:24:14 volumio volumio[914]: info: CoreStateMachine::startPlaybackTimer Mar 02 20:24:14 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 02 20:24:14 volumio volumio[914]: info: [1614716654800] ControllerTidal::clearAddPlayTrack Mar 02 20:24:14 volumio volumio[914]: info: Getting stream with soundQuality LOSSLESS Mar 02 20:24:15 volumio volumio[914]: info: getStreamUrl took 332 milliseconds Mar 02 20:24:15 volumio volumio[914]: verbose: ControllerMpd::sendMpdCommand stop Mar 02 20:24:28 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 02 20:24:28 volumio volumio[914]: info: CURURI: music-library Mar 02 20:24:32 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 02 20:24:32 volumio volumio[914]: info: CURURI: music-library Mar 02 20:25:12 volumio systemd[1]: Starting Cleanup of Temporary Directories... Mar 02 20:25:12 volumio volumio[914]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 02 20:25:12 volumio volumio[914]: BT PLUGIN MESSAGE: Playing: false Mar 02 20:25:12 volumio volumio[914]: BT PLUGIN MESSAGE: VOLATILE: undefined Mar 02 20:25:12 volumio volumio[914]: BT PLUGIN MESSAGE: STATE:undefined Mar 02 20:25:12 volumio systemd[1]: Started Cleanup of Temporary Directories. Mar 02 20:25:14 volumio volumio[914]: info: CALLMETHOD: system_controller system sendBugReport [object Object] Mar 02 20:25:14 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , sendBugReport Mar 02 20:25:14 volumio sudo[3083]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig Mar 02 20:25:14 volumio sudo[3083]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 20:25:14 volumio sudo[3083]: pam_unix(sudo:session): session closed for user root Mar 02 20:25:16 volumio sudo[3121]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl -p 7 Mar 02 20:25:16 volumio sudo[3121]: pam_unix(sudo:session): session opened for user root by (uid=0)